kern/162944: Coda file system module looks broken in 9.0

Tue Nov 29 09:20:18 UTC 2011

>Number:         162944
>Category:       kern
>Synopsis:       Coda file system module looks broken in 9.0
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Tue Nov 29 09:20:13 UTC 2011
>Closed-Date:
>Last-Modified:
>Originator:     Rune
>Release:        9.0-BETA2
>Organization:
>Environment:
FreeBSD <hostname> 9.0-BETA2 FreeBSD 9.0-BETA2 #0: Wed Aug 31 18:07:44 UTC 2011     root_at_farrell.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC  amd64
>Description:
Coda file system is unusable as the data presented by the file system is bogus/messed up.

(The kernel module seems to pass a wrong file descriptor to the open()-ing process? also seems to damage or lose pioctl() data)

The Coda userspace component, cache manager Venus seems (?) to work as supposed.

Copying the description from
 http://www.coda.cs.cmu.edu/maillists/codalist/codalist-2011/9167.html
with some additional comments in []

(functional "clog" and broken "ctokens" suggest that data passing from user processes via the kernel to the venus process may be working, while passing the data back is not working properly)
---------------------------------------------------------------------------
When I try the 6.9.4 from ports on 9-BETA2 it says "not tested"
but goes through the installation and does not crash the system
(at least not immediately :)

It does not unfortunately provide any useful file data, even though
it seems to distinguish between existing and non-existing realms
and seems to be able to clog (ctokens does not show anything though).
It properly fetches attributes for directories, files and symlinks.

The contents of directories seems nevertheless to always be empty and
the file contents is bogus (apparently the [contents of] venus console log)

# uname -a
FreeBSD <hostname> 9.0-BETA2 FreeBSD 9.0-BETA2 #0: Wed Aug 31 18:07:44 UTC 2011     root_at_farrell.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC  amd64
#

# ls -al /coda/coda.cs.cmu.edu
total 0

[testing a non-existing directory name]
# ls -al /coda/coda.cs.cmu.edu/playgr
ls: /coda/coda.cs.cmu.edu/playgr: No such file or directory

# ls -al /coda/coda.cs.cmu.edu/playground
total 0

# ls -ald /coda/coda.cs.cmu.edu/playground
drwxr-xr-x  1 root  nobody  6144 Jun 28 10:17 /coda/coda.cs.cmu.edu/playground

[testing a non-existing realm]
# ls -al /coda/norealm
lrw-r--r--  1 root  nobody  10 Sep  8 09:11 /coda/norealm -> #@norealm

# ls -al /coda/coda.cs.cmu.edu/WELCOME
-rw-r--r--  1 7768  nobody  879 May 13  2007 /coda/coda.cs.cmu.edu/WELCOME

[this file should show a welcome message but you see a console log record
of the Venus daemon, i.e. the contents of another file "provided" by Venus, where we should instead get a file descriptor of the WELCOME file fetched by Venus over the net]
# cat /coda/coda.cs.cmu.edu/WELCOME

Date: Thu 09/08/2011

08:51:19 Coda Venus, version 6.9.4
08:51:19 /usr/coda/LOG size is 36084466 bytes
08:51:19 /usr/coda/DATA size is 144337864 bytes
08:51:19 Initializing RVM data...
08:51:19 ...done
08:51:19 Loading RVM data
08:51:19 Starting RealmDB scan
08:51:19        Found 1 realms
08:51:19 starting VDB scan
08:51:19        0 volume replicas
08:51:19        0 replicated volumes
08:51:19        0 CML entries allocated
08:51:19        0 CML entries on free-list
08:51:20 starting FSDB scan (50000, 1200000) (25, 75, 4)
08:51:20        0 cache files in table (0 blocks)
08:51:21        50000 cache files on free-list
08:51:23 starting HDB scan
08:51:23        0 hdb entries in table
08:51:23        0 hdb entries on free-list
08:51:23 Mounting root volume...
08:51:23 /coda now mounted.
08:51:23 Venus starting...
08:51:58 Resolved realm '<some-existing-realm>'
08:53:19 Resolved realm 'coda.cs.cmu.edu'
08:56:33 Coda token for user 1001 has been discarded
09:06:01 RecovTerminate: clean shutdown

Date: Thu 09/08/2011

09:06:25 Coda Venus, version 6.9.4
09:06:25 /usr/coda/LOG size is 36086784 bytes
09:06:25 /usr/coda/DATA size is 144337864 bytes
09:06:25 Loading RVM data
09:06:25 Last init was Thu Sep  8 08:51:19 2011
09:06:25 Last shutdown was clean
09:06:26 Starting RealmDB scan
09:06:26        Found 6 realms
09:06:26 starting VDB scan
09:06:26        6 volume replicas
09:06:26        3 replicated volumes
09:06:26        0 CML entries allocated
09:06:26        0 CML entries on free-list
09:06:26 starting FSDB scan (50000, 1200000) (25, 75, 4)
09:06:26        10 cache files in table (0 blocks)
09:06:26        49990 cache files on free-list
09:06:26 starting HDB scan
09:06:26        0 hdb entries in table
09:06:26        0 hdb entries on free-list
09:06:26 Mounting root volume...
09:06:26 /coda now mounted.
09:06:26 Venus starting...
09:08:10 Resolved realm 'coda.cs.cmu.edu'
09:12:14 Resolved realm '<some-existing-realm>'
#

On the other side the contents of /usr/coda/venus.cache/00/00/00/*
is "right", there are apparently directories like "playground"
with what looks like proper directory entries and also the files
containing among others the contents of "WELCOME" and so on.

So the problem looks like the kernel module passing a wrong file
descriptor to the open()-ing process.
The kernel complains also about ioctl sign-extension in clog
and some lock-reversal (only once?) :
-------------
 ...
WARNING pid 75641 (clog): ioctl sign-extension ioctl ffffffff80245603
lock order reversal:
 1st 0xfffffe0015e4b818 coda (coda) @ /usr/src/sys/modules/coda/../../fs/coda/coda_vfsops.c:303
 2nd 0xfffffe0031313bd8 ufs (ufs) @ /usr/src/sys/modules/coda/../../fs/coda/coda_vnops.c:240
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
kdb_backtrace() at kdb_backtrace+0x37
_witness_debugger() at _witness_debugger+0x2e
witness_checkorder() at witness_checkorder+0x807
__lockmgr_args() at __lockmgr_args+0xdc6
ffs_lock() at ffs_lock+0x8c
VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b
_vn_lock() at _vn_lock+0x47
coda_open() at coda_open+0xf6
vn_open_cred() at vn_open_cred+0x323
kern_openat() at kern_openat+0x1f9
syscallenter() at syscallenter+0x1aa
syscall() at syscall+0x4c
Xfast_syscall() at Xfast_syscall+0xdd
--- syscall (5, FreeBSD ELF64, open), rip = 0x801185f2c, rsp = 0x7fffffffdb58, rbp = 0x3 ---
WARNING pid 75676 (clog): ioctl sign-extension ioctl ffffffff80245603
WARNING pid 75687 (cunlog): ioctl sign-extension ioctl ffffffff80245609
WARNING pid 75759 (clog): ioctl sign-extension ioctl ffffffff80245603
WARNING pid 75767 (clog): ioctl sign-extension ioctl ffffffff80245603
Warning: memory type coda leaked memory on destroy (4 allocations, 1024 bytes leaked).
 ...
-------------
>How-To-Repeat:
try to use Coda file system via ports
>Fix:

>Release-Note:
>Audit-Trail:
>Unformatted: