Remember the problem where a mounted (cfs mkmount) volume was displayed
like this :
lrw-r--r--   1 1000     65534           8 Oct  3 16:02 testvol ->
#testvol


I've turned on debugging on the Venus-side (with kdebug and ktrace).

I've attached the result as a text file... it's quite big, but it might
give a clue to what the problem is...

When typing "venus -init &" :

Oct  3 16:14:19 gnet kernel: Process 1171 entered coda_psdev_open 
Oct  3 16:14:19 gnet kernel: (coda_psdev_open,l. 320): device 0 - inuse: 1 
Oct  3 16:14:19 gnet kernel: Process 1171 leaving coda_psdev_open 
Oct  3 16:14:19 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,25,0), nbytes 12 
Oct  3 16:14:19 gnet kernel: (coda_psdev_write,l. 128): coda_psdev_write: downcall, no SB! 
Oct  3 16:14:19 gnet kernel: Process 1171 entered coda_psdev_release 
Oct  3 16:14:19 gnet kernel: (coda_psdev_release,l. 342): psdev_release: inuse 1 
Oct  3 16:14:19 gnet kernel: (coda_psdev_release,l. 349): wake up pending clients 
Oct  3 16:14:19 gnet kernel: (coda_psdev_release,l. 366): wake up processing clients 
Oct  3 16:14:19 gnet kernel: (coda_psdev_release,l. 372): Done. 
Oct  3 16:14:19 gnet kernel: Process 1171 leaving coda_psdev_release 
Oct  3 16:14:22 gnet kernel: Process 1171 entered coda_psdev_open 
Oct  3 16:14:22 gnet kernel: (coda_psdev_open,l. 320): device 0 - inuse: 1 
Oct  3 16:14:22 gnet kernel: Process 1171 leaving coda_psdev_open 
Oct  3 16:14:37 gnet kernel: Process 1172 entered coda_read_super 
Oct  3 16:14:37 gnet kernel: coda_read_super: device index: 0 
Oct  3 16:14:37 gnet kernel: Process 1172 entered venus_rootfid 
Oct  3 16:14:37 gnet kernel: (alloc_upcall,l. 52): kmalloced: 30 at c2de69a0. 
Oct  3 16:14:37 gnet kernel: Process 1172 entered coda_upcall 
Oct  3 16:14:37 gnet kernel: (coda_upcall,l. 762): Proc 1172 wake Venus for(opc,uniq) =(2,1) msg at c2de6be0.zzz. 
Oct  3 16:14:37 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,2,1), nbytes 24 
Oct  3 16:14:37 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 1 on queue! 
Oct  3 16:14:37 gnet kernel: (coda_psdev_write,l. 215): Found! Count 24 for (opc,uniq)=(2,1), upc_req at c22a7f6c 
Oct  3 16:14:37 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:14:37 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:37 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:37 gnet kernel: (coda_upcall,l. 780): opc: 2 time: 2 uniq: 1 size: 24 
Oct  3 16:14:37 gnet kernel: (coda_upcall,l. 783): ..process 1172 woken up by Venus for req at c2de6be0, data at c2de69a0 
Oct  3 16:14:37 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (1, 2, 0) out at c2de69a0 
Oct  3 16:14:37 gnet kernel: (venus_rootfid,l. 103): VolumeId: 7f000000, VnodeId: 1. 
Oct  3 16:14:37 gnet kernel: (venus_rootfid,l. 106): kfreed: 30 at c2de69a0. 
Oct  3 16:14:37 gnet kernel: Process 1172 leaving venus_rootfid 
Oct  3 16:14:38 gnet kernel: coda_read_super: rootfid is (0x7f000000,0x1,0x1) 
Oct  3 16:14:38 gnet kernel: Process 1172 entered coda_cnode_make 
Oct  3 16:14:38 gnet kernel: Process 1172 entered venus_getattr 
Oct  3 16:14:38 gnet kernel: (alloc_upcall,l. 52): kmalloced: 64 at c3c1d4e0. 
Oct  3 16:14:38 gnet kernel: Process 1172 entered coda_upcall 
Oct  3 16:14:38 gnet kernel: (coda_upcall,l. 762): Proc 1172 wake Venus for(opc,uniq) =(7,2) msg at c2de69a0.zzz. 
Oct  3 16:14:38 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,7,2), nbytes 100 
Oct  3 16:14:38 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 2 on queue! 
Oct  3 16:14:38 gnet kernel: (coda_psdev_write,l. 215): Found! Count 100 for (opc,uniq)=(7,2), upc_req at c22a7f6c 
Oct  3 16:14:38 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:14:38 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:38 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:38 gnet kernel: (coda_upcall,l. 780): opc: 7 time: 12 uniq: 2 size: 100 
Oct  3 16:14:38 gnet kernel: (coda_upcall,l. 783): ..process 1172 woken up by Venus for req at c2de69a0, data at c3c1d4e0 
Oct  3 16:14:38 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (2, 7, 0) out at c3c1d4e0 
Oct  3 16:14:38 gnet kernel: (venus_getattr,l. 127): kfreed: 64 at c3c1d4e0. 
Oct  3 16:14:38 gnet kernel: Process 1172 leaving venus_getattr 
Oct  3 16:14:38 gnet kernel: Process 1172 entered coda_read_inode 
Oct  3 16:14:39 gnet kernel: (coda_fill_inode,l. 45): ino: 1025 
Oct  3 16:14:39 gnet kernel: attr: type C_VDIR (2)  mode 777 uid 0 gid 65534 rdev 1 
Oct  3 16:14:39 gnet kernel:       fileid 1025 nlink 2 size 2048 blocksize 8192 bytes 2048 
Oct  3 16:14:39 gnet kernel:       gen 0 flags 0 
Oct  3 16:14:39 gnet kernel:       atime sec 1002117747 nsec 0 
Oct  3 16:14:39 gnet kernel:       mtime sec 1002117747 nsec 0 
Oct  3 16:14:39 gnet kernel:       ctime sec 0 nsec 0 
Oct  3 16:14:39 gnet kernel: (coda_cnode_make,l. 127): Done making inode: ino 1025, count 1 with (0x7f000000,0x1,0x1) 
Oct  3 16:14:39 gnet kernel: Process 1172 leaving coda_cnode_make 
Oct  3 16:14:39 gnet kernel: coda_read_super: rootinode is 1025 dev 7 
Oct  3 16:14:39 gnet kernel: Process 1172 leaving coda_read_super 




When doing "cd /coda" :

Oct  3 16:14:54 gnet kernel: Process 1096 entered coda_permission 
Oct  3 16:14:54 gnet kernel: (coda_cache_check,l. 78): MISS for ino 1025 
Oct  3 16:14:54 gnet kernel: (coda_permission,l. 181): mask is 1 
Oct  3 16:14:54 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:14:54 gnet kernel: Process 1096 entered coda_upcall 
Oct  3 16:14:54 gnet kernel: (coda_upcall,l. 762): Proc 1096 wake Venus for(opc,uniq) =(9,3) msg at c2de69a0.zzz. 
Oct  3 16:14:54 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,9,3), nbytes 12 
Oct  3 16:14:54 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 3 on queue! 
Oct  3 16:14:54 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(9,3), upc_req at c22a7f6c 
Oct  3 16:14:54 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:14:54 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:54 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:14:54 gnet kernel: (coda_upcall,l. 780): opc: 9 time: 0 uniq: 3 size: 12 
Oct  3 16:14:54 gnet kernel: (coda_upcall,l. 783): ..process 1096 woken up by Venus for req at c2de69a0, data at c2de6be0 
Oct  3 16:14:54 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (3, 9, 0) out at c2de6be0 
Oct  3 16:14:54 gnet kernel: (venus_access,l. 545): kfreed: 40 at c2de6be0. 
Oct  3 16:14:54 gnet kernel: Process 1096 leaving venus_access 
Oct  3 16:14:54 gnet kernel: (coda_permission,l. 185): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 1) error: 0 
Oct  3 16:14:54 gnet kernel: Process 1096 entered coda_cache_enter 


When doing "ls" in /coda :
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:02 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_lookup 
Oct  3 16:15:02 gnet kernel: (coda_lookup,l. 115): name i586, len 4 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:15:02 gnet kernel: (alloc_upcall,l. 52): kmalloced: 49 at c3c1d760. 
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:02 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(10,4) msg at c2de6be0.zzz. 
Oct  3 16:15:02 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,4), nbytes 12 
Oct  3 16:15:02 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 4 on queue! 
Oct  3 16:15:02 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,4), upc_req at c22a7f6c 
Oct  3 16:15:02 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:02 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:02 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:02 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 1 uniq: 4 size: 12 
Oct  3 16:15:02 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d760 
Oct  3 16:15:02 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (4, 10, 2) out at c3c1d760 
Oct  3 16:15:02 gnet kernel: (venus_lookup,l. 177): kfreed: 49 at c3c1d760. 
Oct  3 16:15:02 gnet kernel: (coda_lookup,l. 147): lookup: i586 is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:15:02 gnet kernel: Process 1179 leaving coda_lookup 
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:02 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_lookup 
Oct  3 16:15:02 gnet kernel: (coda_lookup,l. 115): name libc.so.6, len 9 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:15:02 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4e at c3c1d4e0. 
Oct  3 16:15:02 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:02 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(10,5) msg at c2de6be0.zzz. 
Oct  3 16:15:02 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,5), nbytes 12 
Oct  3 16:15:02 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 5 on queue! 
Oct  3 16:15:03 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,5), upc_req at c22a7f6c 
Oct  3 16:15:03 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:03 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:03 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:03 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 5 size: 12 
Oct  3 16:15:03 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:03 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (5, 10, 2) out at c3c1d4e0 
Oct  3 16:15:03 gnet kernel: (venus_lookup,l. 177): kfreed: 4e at c3c1d4e0. 
Oct  3 16:15:03 gnet kernel: (coda_lookup,l. 147): lookup: libc.so.6 is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:15:03 gnet kernel: Process 1179 leaving coda_lookup 
Oct  3 16:15:03 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:03 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:03 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:03 gnet kernel: (coda_cache_check,l. 78): MISS for ino 1025 
Oct  3 16:15:03 gnet kernel: (coda_permission,l. 181): mask is 4 
Oct  3 16:15:03 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:15:03 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:03 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(9,6) msg at c2de69a0.zzz. 
Oct  3 16:15:03 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,9,6), nbytes 12 
Oct  3 16:15:04 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 6 on queue! 
Oct  3 16:15:04 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(9,6), upc_req at c22a7f6c 
Oct  3 16:15:04 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:04 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:04 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:04 gnet kernel: (coda_upcall,l. 780): opc: 9 time: 0 uniq: 6 size: 12 
Oct  3 16:15:04 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de69a0, data at c2de6be0 
Oct  3 16:15:04 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (6, 9, 0) out at c2de6be0 
Oct  3 16:15:04 gnet kernel: (venus_access,l. 545): kfreed: 40 at c2de6be0. 
Oct  3 16:15:04 gnet kernel: Process 1179 leaving venus_access 
Oct  3 16:15:04 gnet kernel: (coda_permission,l. 185): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 4) error: 0 
Oct  3 16:15:04 gnet kernel: Process 1179 entered coda_cache_enter 
Oct  3 16:15:04 gnet kernel: (coda_flags_to_cflags,l. 97): --> C_O_READ added 
Oct  3 16:15:04 gnet kernel: Process 1179 entered coda_open 
Oct  3 16:15:04 gnet kernel: (coda_open,l. 72): OPEN inode number: 1025, count 7, flags 4000. 
Oct  3 16:15:04 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:15:04 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:04 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(3,7) msg at c2de69a0.zzz. 
Oct  3 16:15:04 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,3,7), nbytes 20 
Oct  3 16:15:05 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 7 on queue! 
Oct  3 16:15:05 gnet kernel: (coda_psdev_write,l. 215): Found! Count 20 for (opc,uniq)=(3,7), upc_req at c22a7f6c 
Oct  3 16:15:05 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:05 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:05 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:05 gnet kernel: (coda_upcall,l. 780): opc: 3 time: 0 uniq: 7 size: 20 
Oct  3 16:15:05 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de69a0, data at c2de6be0 
Oct  3 16:15:05 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (7, 3, 0) out at c2de6be0 
Oct  3 16:15:05 gnet kernel: (venus_open,l. 264): kfreed: 40 at c2de6be0. 
Oct  3 16:15:05 gnet kernel: (coda_open,l. 101): result 0, coda i->i_count is 1, cii->contcount is 1 for ino 1025 
Oct  3 16:15:05 gnet kernel: (coda_open,l. 105): cache ino: 5476, count 1, ops c0279a80 
Oct  3 16:15:05 gnet kernel: Process 1179 leaving coda_open 
Oct  3 16:15:05 gnet kernel: Process 1179 entered coda_revalidate_inode 
Oct  3 16:15:05 gnet kernel: (coda_revalidate_inode,l. 746): revalidating: /// 
Oct  3 16:15:05 gnet kernel: Process 1179 entered coda_readdir 
Oct  3 16:15:05 gnet kernel: Process 1179 entered coda_venus_readdir 
Oct  3 16:15:05 gnet kernel: (coda_venus_readdir,l. 582): kmalloced: 800 at c09cf000. 
Oct  3 16:15:05 gnet kernel: (coda_venus_readdir,l. 603): buffsize: 512 offset 0, count 0. 
Oct  3 16:15:06 gnet kernel: (coda_venus_readdir,l. 628): entry 0: ino 1025, namlen 1, reclen 12, type 0, pos 0, string_offs 8, name ., offset 0, result: 0, errfill: 0. 
Oct  3 16:15:06 gnet kernel: (coda_venus_readdir,l. 628): entry 1: ino 1025, namlen 2, reclen 12, type 0, pos 12, string_offs 8, name .., offset 12, result: 1, errfill: 0. 
Oct  3 16:15:06 gnet kernel: (coda_venus_readdir,l. 628): entry 2: ino 67618, namlen 7, reclen 16, type 0, pos 24, string_offs 8, name testvol, offset 24, result: 2, errfill: 0. 
Oct  3 16:15:06 gnet kernel: (coda_venus_readdir,l. 658): kfreed: 800 at c09cf000. 
Oct  3 16:15:06 gnet kernel: Process 1179 leaving coda_readdir 
Oct  3 16:15:06 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:06 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:06 gnet kernel: Process 1179 entered coda_lookup 
Oct  3 16:15:06 gnet kernel: (coda_lookup,l. 115): name testvol, len 7 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:15:06 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4c at c3c1d4e0. 
Oct  3 16:15:06 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:06 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(10,8) msg at c2de6be0.zzz. 
Oct  3 16:15:06 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,8), nbytes 28 
Oct  3 16:15:06 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 8 on queue! 
Oct  3 16:15:06 gnet kernel: (coda_psdev_write,l. 215): Found! Count 28 for (opc,uniq)=(10,8), upc_req at c22a7f6c 
Oct  3 16:15:06 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:06 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:06 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:06 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 1 uniq: 8 size: 28 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (8, 10, 0) out at c3c1d4e0 
Oct  3 16:15:07 gnet kernel: (venus_lookup,l. 177): kfreed: 4c at c3c1d4e0. 
Oct  3 16:15:07 gnet kernel: (coda_lookup,l. 135): dropme set for (0x7f000000,0x42,0x22) 
Oct  3 16:15:07 gnet kernel: Process 1179 entered coda_cnode_make 
Oct  3 16:15:07 gnet kernel: Process 1179 entered venus_getattr 
Oct  3 16:15:07 gnet kernel: (alloc_upcall,l. 52): kmalloced: 64 at c3c1d4e0. 
Oct  3 16:15:07 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(7,9) msg at c2de6be0.zzz. 
Oct  3 16:15:07 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,7,9), nbytes 100 
Oct  3 16:15:07 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 9 on queue! 
Oct  3 16:15:07 gnet kernel: (coda_psdev_write,l. 215): Found! Count 100 for (opc,uniq)=(7,9), upc_req at c22a7f6c 
Oct  3 16:15:07 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:07 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:07 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 780): opc: 7 time: 0 uniq: 9 size: 100 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:07 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (9, 7, 0) out at c3c1d4e0 
Oct  3 16:15:07 gnet kernel: (venus_getattr,l. 127): kfreed: 64 at c3c1d4e0. 
Oct  3 16:15:08 gnet kernel: Process 1179 leaving venus_getattr 
Oct  3 16:15:08 gnet kernel: Process 1179 entered coda_read_inode 
Oct  3 16:15:08 gnet kernel: (coda_fill_inode,l. 45): ino: 67618 
Oct  3 16:15:08 gnet kernel: attr: type C_VLNK (5)  mode 644 uid 1000 gid 65534 rdev 1 
Oct  3 16:15:08 gnet kernel:       fileid 67618 nlink 1 size 8 blocksize 8192 bytes 8 
Oct  3 16:15:08 gnet kernel:       gen 0 flags 0 
Oct  3 16:15:08 gnet kernel:       atime sec 1002117747 nsec 0 
Oct  3 16:15:08 gnet kernel:       mtime sec 1002117747 nsec 0 
Oct  3 16:15:08 gnet kernel:       ctime sec 0 nsec 0 
Oct  3 16:15:08 gnet kernel: (coda_cnode_make,l. 127): Done making inode: ino 67618, count 1 with (0x7f000000,0x42,0x22) 
Oct  3 16:15:08 gnet kernel: Process 1179 leaving coda_cnode_make 
Oct  3 16:15:08 gnet kernel: (coda_lookup,l. 147): lookup: testvol is ((0x7f000000,0x42,0x22)), type 5 result 0, dropme 1 
Oct  3 16:15:08 gnet kernel: Process 1179 leaving coda_lookup 
Oct  3 16:15:08 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:08 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:08 gnet kernel: Process 1179 entered coda_lookup 
Oct  3 16:15:08 gnet kernel: (coda_lookup,l. 115): name testvol, len 7 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:15:08 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4c at c3c1d4e0. 
Oct  3 16:15:09 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:09 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(10,10) msg at c2de6be0.zzz. 
Oct  3 16:15:09 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,10), nbytes 28 
Oct  3 16:15:09 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 10 on queue! 
Oct  3 16:15:09 gnet kernel: (coda_psdev_write,l. 215): Found! Count 28 for (opc,uniq)=(10,10), upc_req at c22a7f6c 
Oct  3 16:15:09 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:09 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:09 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:09 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 1 uniq: 10 size: 28 
Oct  3 16:15:09 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:09 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (10, 10, 0) out at c3c1d4e0 
Oct  3 16:15:09 gnet kernel: (venus_lookup,l. 177): kfreed: 4c at c3c1d4e0. 
Oct  3 16:15:09 gnet kernel: (coda_lookup,l. 135): dropme set for (0x7f000000,0x42,0x22) 
Oct  3 16:15:09 gnet kernel: Process 1179 entered coda_cnode_make 
Oct  3 16:15:09 gnet kernel: Process 1179 entered venus_getattr 
Oct  3 16:15:09 gnet kernel: (alloc_upcall,l. 52): kmalloced: 64 at c3c1d4e0. 
Oct  3 16:15:09 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:09 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(7,11) msg at c2de6be0.zzz. 
Oct  3 16:15:10 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,7,11), nbytes 100 
Oct  3 16:15:10 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 11 on queue! 
Oct  3 16:15:10 gnet kernel: (coda_psdev_write,l. 215): Found! Count 100 for (opc,uniq)=(7,11), upc_req at c22a7f6c 
Oct  3 16:15:10 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:10 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:10 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:10 gnet kernel: (coda_upcall,l. 780): opc: 7 time: 0 uniq: 11 size: 100 
Oct  3 16:15:10 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:10 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (11, 7, 0) out at c3c1d4e0 
Oct  3 16:15:10 gnet kernel: (venus_getattr,l. 127): kfreed: 64 at c3c1d4e0. 
Oct  3 16:15:10 gnet kernel: Process 1179 leaving venus_getattr 
Oct  3 16:15:10 gnet kernel: (coda_fill_inode,l. 45): ino: 67618 
Oct  3 16:15:10 gnet kernel: attr: type C_VLNK (5)  mode 644 uid 1000 gid 65534 rdev 1 
Oct  3 16:15:10 gnet kernel:       fileid 67618 nlink 1 size 8 blocksize 8192 bytes 8 
Oct  3 16:15:10 gnet kernel:       gen 0 flags 0 
Oct  3 16:15:10 gnet kernel:       atime sec 1002117747 nsec 0 
Oct  3 16:15:10 gnet kernel:       mtime sec 1002117747 nsec 0 
Oct  3 16:15:10 gnet kernel:       ctime sec 0 nsec 0 
Oct  3 16:15:10 gnet kernel: (coda_cnode_make,l. 127): Done making inode: ino 67618, count 1 with (0x7f000000,0x42,0x22) 
Oct  3 16:15:11 gnet kernel: Process 1179 leaving coda_cnode_make 
Oct  3 16:15:11 gnet kernel: (coda_lookup,l. 147): lookup: testvol is ((0x7f000000,0x42,0x22)), type 5 result 0, dropme 1 
Oct  3 16:15:11 gnet kernel: Process 1179 leaving coda_lookup 
Oct  3 16:15:11 gnet kernel: (alloc_upcall,l. 52): vmalloced: 1015 at c4812000 . 
Oct  3 16:15:11 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:11 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(19,12) msg at c2de6be0.zzz. 
Oct  3 16:15:11 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,19,12), nbytes 28 
Oct  3 16:15:11 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 12 on queue! 
Oct  3 16:15:11 gnet kernel: (coda_psdev_write,l. 215): Found! Count 28 for (opc,uniq)=(19,12), upc_req at c22a7f6c 
Oct  3 16:15:11 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:11 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:11 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:11 gnet kernel: (coda_upcall,l. 780): opc: 19 time: 0 uniq: 12 size: 28 
Oct  3 16:15:11 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c4812000 
Oct  3 16:15:11 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (12, 19, 0) out at c4812000 
Oct  3 16:15:11 gnet kernel: (venus_readlink,l. 441):  result 0 
Oct  3 16:15:11 gnet kernel: Process 1179 leaving venus_readlink 
Oct  3 16:15:12 gnet kernel: (venus_readlink,l. 443): vfreed: 1015 at c4812000. 
Oct  3 16:15:12 gnet kernel: Process 1179 entered coda_permission 
Oct  3 16:15:12 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:15:12 gnet kernel: Process 1179 entered coda_lookup 
Oct  3 16:15:12 gnet kernel: (coda_lookup,l. 115): name #repvol, len 7 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:15:12 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4c at c3c1d4e0. 
Oct  3 16:15:12 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:12 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(10,13) msg at c2de6be0.zzz. 
Oct  3 16:15:12 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,13), nbytes 12 
Oct  3 16:15:12 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 13 on queue! 
Oct  3 16:15:12 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,13), upc_req at c22a7f6c 
Oct  3 16:15:12 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:12 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:12 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:12 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 1 uniq: 13 size: 12 
Oct  3 16:15:12 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de6be0, data at c3c1d4e0 
Oct  3 16:15:12 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (13, 10, 2) out at c3c1d4e0 
Oct  3 16:15:12 gnet kernel: (venus_lookup,l. 177): kfreed: 4c at c3c1d4e0. 
Oct  3 16:15:13 gnet kernel: (coda_lookup,l. 147): lookup: #repvol is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:15:13 gnet kernel: Process 1179 leaving coda_lookup 
Oct  3 16:15:13 gnet kernel: Process 1179 entered coda_readdir 
Oct  3 16:15:13 gnet kernel: Process 1179 entered coda_venus_readdir 
Oct  3 16:15:13 gnet kernel: (coda_venus_readdir,l. 582): kmalloced: 800 at c09cf000. 
Oct  3 16:15:13 gnet kernel: (coda_venus_readdir,l. 658): kfreed: 800 at c09cf000. 
Oct  3 16:15:13 gnet kernel: Process 1179 leaving coda_readdir 
Oct  3 16:15:13 gnet kernel: Process 1179 entered coda_flush 
Oct  3 16:15:13 gnet kernel: (coda_flags_to_cflags,l. 97): --> C_O_READ added 
Oct  3 16:15:13 gnet kernel: Process 1179 entered coda_release 
Oct  3 16:15:13 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:15:13 gnet kernel: Process 1179 entered coda_upcall 
Oct  3 16:15:13 gnet kernel: (coda_upcall,l. 762): Proc 1179 wake Venus for(opc,uniq) =(5,14) msg at c2de69a0.zzz. 
Oct  3 16:15:13 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,5,14), nbytes 12 
Oct  3 16:15:13 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 14 on queue! 
Oct  3 16:15:13 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(5,14), upc_req at c22a7f6c 
Oct  3 16:15:13 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:15:13 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:14 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:15:14 gnet kernel: (coda_upcall,l. 780): opc: 5 time: 0 uniq: 14 size: 12 
Oct  3 16:15:14 gnet kernel: (coda_upcall,l. 783): ..process 1179 woken up by Venus for req at c2de69a0, data at c2de6be0 
Oct  3 16:15:14 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (14, 5, 0) out at c2de6be0 
Oct  3 16:15:14 gnet kernel: (venus_close,l. 243): kfreed: 40 at c2de6be0. 


Since I wasn't logged in yet, I typed :
"clog coda"
Oct  3 16:16:26 gnet kernel: Process 1096 entered coda_permission 
Oct  3 16:16:26 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:26 gnet kernel: Process 1096 entered coda_permission 
Oct  3 16:16:26 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:26 gnet kernel: Process 1096 entered coda_lookup 
Oct  3 16:16:26 gnet kernel: (coda_lookup,l. 115): name clog, len 4 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:26 gnet kernel: (alloc_upcall,l. 52): kmalloced: 49 at c3c1d460. 
Oct  3 16:16:26 gnet kernel: Process 1096 entered coda_upcall 
Oct  3 16:16:26 gnet kernel: (coda_upcall,l. 762): Proc 1096 wake Venus for(opc,uniq) =(10,21) msg at c2de6c60.zzz. 
Oct  3 16:16:26 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,21), nbytes 12 
Oct  3 16:16:26 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 21 on queue! 
Oct  3 16:16:26 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,21), upc_req at c22a7f6c 
Oct  3 16:16:26 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:26 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:26 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:26 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 21 size: 12 
Oct  3 16:16:26 gnet kernel: (coda_upcall,l. 783): ..process 1096 woken up by Venus for req at c2de6c60, data at c3c1d460 
Oct  3 16:16:26 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (21, 10, 2) out at c3c1d460 
Oct  3 16:16:26 gnet kernel: (venus_lookup,l. 177): kfreed: 49 at c3c1d460. 
Oct  3 16:16:26 gnet kernel: (coda_lookup,l. 147): lookup: clog is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:16:26 gnet kernel: Process 1096 leaving coda_lookup 
Oct  3 16:16:26 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:26 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:26 gnet kernel: Process 1195 entered coda_dentry_revalidate 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:27 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_lookup 
Oct  3 16:16:27 gnet kernel: (coda_lookup,l. 115): name librpc2.so.3, len 12 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:27 gnet kernel: (alloc_upcall,l. 52): kmalloced: 51 at c3c1d4e0. 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_upcall 
Oct  3 16:16:27 gnet kernel: (coda_upcall,l. 762): Proc 1195 wake Venus for(opc,uniq) =(10,22) msg at c2de6c60.zzz. 
Oct  3 16:16:27 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,22), nbytes 12 
Oct  3 16:16:27 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 22 on queue! 
Oct  3 16:16:27 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,22), upc_req at c22a7f6c 
Oct  3 16:16:27 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:27 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:27 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:27 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 22 size: 12 
Oct  3 16:16:27 gnet kernel: (coda_upcall,l. 783): ..process 1195 woken up by Venus for req at c2de6c60, data at c3c1d4e0 
Oct  3 16:16:27 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (22, 10, 2) out at c3c1d4e0 
Oct  3 16:16:27 gnet kernel: (venus_lookup,l. 177): kfreed: 51 at c3c1d4e0. 
Oct  3 16:16:27 gnet kernel: (coda_lookup,l. 147): lookup: librpc2.so.3 is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:16:27 gnet kernel: Process 1195 leaving coda_lookup 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:27 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_dentry_revalidate 
Oct  3 16:16:27 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:28 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:28 gnet kernel: Process 1195 entered coda_lookup 
Oct  3 16:16:28 gnet kernel: (coda_lookup,l. 115): name liblwp.so.2, len 11 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:28 gnet kernel: (alloc_upcall,l. 52): kmalloced: 50 at c3c1d4e0. 
Oct  3 16:16:28 gnet kernel: Process 1195 entered coda_upcall 
Oct  3 16:16:28 gnet kernel: (coda_upcall,l. 762): Proc 1195 wake Venus for(opc,uniq) =(10,23) msg at c2de6c60.zzz. 
Oct  3 16:16:28 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,23), nbytes 12 
Oct  3 16:16:28 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 23 on queue! 
Oct  3 16:16:28 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,23), upc_req at c22a7f6c 
Oct  3 16:16:28 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:28 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:28 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:28 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 23 size: 12 
Oct  3 16:16:28 gnet kernel: (coda_upcall,l. 783): ..process 1195 woken up by Venus for req at c2de6c60, data at c3c1d4e0 
Oct  3 16:16:28 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (23, 10, 2) out at c3c1d4e0 
Oct  3 16:16:28 gnet kernel: (venus_lookup,l. 177): kfreed: 50 at c3c1d4e0. 
Oct  3 16:16:28 gnet kernel: (coda_lookup,l. 147): lookup: liblwp.so.2 is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:16:28 gnet kernel: Process 1195 leaving coda_lookup 
Oct  3 16:16:28 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:28 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_dentry_revalidate 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:29 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_dentry_revalidate 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:29 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_dentry_revalidate 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:29 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_lookup 
Oct  3 16:16:29 gnet kernel: (coda_lookup,l. 115): name libnss_files.so.2, len 17 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:29 gnet kernel: (alloc_upcall,l. 52): kmalloced: 56 at c3c1d860. 
Oct  3 16:16:29 gnet kernel: Process 1195 entered coda_upcall 
Oct  3 16:16:29 gnet kernel: (coda_upcall,l. 762): Proc 1195 wake Venus for(opc,uniq) =(10,24) msg at c2de6c60.zzz. 
Oct  3 16:16:29 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,24), nbytes 12 
Oct  3 16:16:29 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 24 on queue! 
Oct  3 16:16:29 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(10,24), upc_req at c22a7f6c 
Oct  3 16:16:29 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:29 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:30 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:30 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 24 size: 12 
Oct  3 16:16:30 gnet kernel: (coda_upcall,l. 783): ..process 1195 woken up by Venus for req at c2de6c60, data at c3c1d860 
Oct  3 16:16:30 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (24, 10, 2) out at c3c1d860 
Oct  3 16:16:30 gnet kernel: (venus_lookup,l. 177): kfreed: 56 at c3c1d860. 
Oct  3 16:16:30 gnet kernel: (coda_lookup,l. 147): lookup: libnss_files.so.2 is ((0x0,0x0,0x0)), type 0 result -2, dropme 0 
Oct  3 16:16:30 gnet kernel: Process 1195 leaving coda_lookup 



And entered the password :
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_permission 
Oct  3 16:16:40 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_lookup 
Oct  3 16:16:40 gnet kernel: (coda_lookup,l. 115): name .CONTROL, len 8 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_read_inode 
Oct  3 16:16:40 gnet kernel: (coda_lookup,l. 122): Lookup on CTL object; dir ino 1025, count 1 
Oct  3 16:16:40 gnet kernel: Process 1195 leaving coda_lookup 
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_ioctl_permission 
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_pioctl 
Oct  3 16:16:40 gnet kernel: (coda_pioctl,l. 73): namei, data.follow = 0 
Oct  3 16:16:40 gnet kernel: (coda_pioctl,l. 88): target ino: 0x1025, dev: 0x7 
Oct  3 16:16:40 gnet kernel: (alloc_upcall,l. 52): vmalloced: 2110 at c4812000 . 
Oct  3 16:16:40 gnet kernel: Process 1195 entered coda_upcall 
Oct  3 16:16:40 gnet kernel: (coda_upcall,l. 762): Proc 1195 wake Venus for(opc,uniq) =(6,25) msg at c2de6c60.zzz. 
Oct  3 16:16:40 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,26,0), nbytes 44 
Oct  3 16:16:40 gnet kernel: (coda_psdev_write,l. 132): handling downcall 
Oct  3 16:16:40 gnet kernel: (coda_psdev_write,l. 145): kmalloced: 2c at c2de6be0. 
Oct  3 16:16:40 gnet kernel: (coda_downcall,l. 916): CODA_PURGEUSER 
Oct  3 16:16:40 gnet kernel: Process 1171 entered coda_cache_clear_all 
Oct  3 16:16:40 gnet kernel: (coda_psdev_write,l. 157): kfreed: 2c at c2de6be0. 
Oct  3 16:16:40 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,6,25), nbytes 20 
Oct  3 16:16:41 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 25 on queue! 
Oct  3 16:16:41 gnet kernel: (coda_psdev_write,l. 215): Found! Count 20 for (opc,uniq)=(6,25), upc_req at c22a7f6c 
Oct  3 16:16:41 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:41 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:41 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:41 gnet kernel: (coda_upcall,l. 780): opc: 6 time: 3 uniq: 25 size: 20 
Oct  3 16:16:41 gnet kernel: (coda_upcall,l. 783): ..process 1195 woken up by Venus for req at c2de6c60, data at c4812000 
Oct  3 16:16:41 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (25, 6, 0) out at c4812000 
Oct  3 16:16:41 gnet kernel: (venus_pioctl,l. 617): vfreed: 2110 at c4812000. 
Oct  3 16:16:41 gnet kernel: (coda_pioctl,l. 101): ioctl on inode 1025 
Oct  3 16:16:41 gnet kernel: (coda_pioctl,l. 103): dput on ino: 1025, icount 1, dcount 13 



And then did "ls" again :
Oct  3 16:16:48 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:48 gnet kernel: (coda_cache_check,l. 78): MISS for ino 1025 
Oct  3 16:16:48 gnet kernel: (coda_permission,l. 181): mask is 1 
Oct  3 16:16:48 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:16:48 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:48 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(9,26) msg at c2de6c60.zzz. 
Oct  3 16:16:48 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,9,26), nbytes 12 
Oct  3 16:16:48 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 26 on queue! 
Oct  3 16:16:48 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(9,26), upc_req at c22a7f6c 
Oct  3 16:16:48 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:48 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:48 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:48 gnet kernel: (coda_upcall,l. 780): opc: 9 time: 2 uniq: 26 size: 12 
Oct  3 16:16:48 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6c60, data at c2de6be0 
Oct  3 16:16:48 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (26, 9, 0) out at c2de6be0 
Oct  3 16:16:48 gnet kernel: (venus_access,l. 545): kfreed: 40 at c2de6be0. 
Oct  3 16:16:48 gnet kernel: Process 1198 leaving venus_access 
Oct  3 16:16:48 gnet kernel: (coda_permission,l. 185): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 1) error: 0 
Oct  3 16:16:48 gnet kernel: Process 1198 entered coda_cache_enter 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_dentry_revalidate 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:49 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_dentry_revalidate 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:49 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:49 gnet kernel: (coda_cache_check,l. 78): MISS for ino 1025 
Oct  3 16:16:49 gnet kernel: (coda_permission,l. 181): mask is 4 
Oct  3 16:16:49 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:16:49 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:49 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(9,27) msg at c2de6c60.zzz. 
Oct  3 16:16:49 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,9,27), nbytes 12 
Oct  3 16:16:49 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 27 on queue! 
Oct  3 16:16:49 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(9,27), upc_req at c22a7f6c 
Oct  3 16:16:49 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:49 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:49 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:49 gnet kernel: (coda_upcall,l. 780): opc: 9 time: 0 uniq: 27 size: 12 
Oct  3 16:16:50 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6c60, data at c2de6be0 
Oct  3 16:16:50 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (27, 9, 0) out at c2de6be0 
Oct  3 16:16:50 gnet kernel: (venus_access,l. 545): kfreed: 40 at c2de6be0. 
Oct  3 16:16:50 gnet kernel: Process 1198 leaving venus_access 
Oct  3 16:16:50 gnet kernel: (coda_permission,l. 185): fid: (0x7f000000,0x1,0x1), ino: 1025 (mask: 4) error: 0 
Oct  3 16:16:50 gnet kernel: Process 1198 entered coda_cache_enter 
Oct  3 16:16:50 gnet kernel: (coda_flags_to_cflags,l. 97): --> C_O_READ added 
Oct  3 16:16:50 gnet kernel: Process 1198 entered coda_open 
Oct  3 16:16:50 gnet kernel: (coda_open,l. 72): OPEN inode number: 1025, count 12, flags 4000. 
Oct  3 16:16:50 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:16:50 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:50 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(3,28) msg at c2de6c60.zzz. 
Oct  3 16:16:50 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,3,28), nbytes 20 
Oct  3 16:16:50 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 28 on queue! 
Oct  3 16:16:50 gnet kernel: (coda_psdev_write,l. 215): Found! Count 20 for (opc,uniq)=(3,28), upc_req at c22a7f6c 
Oct  3 16:16:50 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:50 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:50 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:51 gnet kernel: (coda_upcall,l. 780): opc: 3 time: 0 uniq: 28 size: 20 
Oct  3 16:16:51 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6c60, data at c2de6be0 
Oct  3 16:16:51 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (28, 3, 0) out at c2de6be0 
Oct  3 16:16:51 gnet kernel: (venus_open,l. 264): kfreed: 40 at c2de6be0. 
Oct  3 16:16:51 gnet kernel: (coda_open,l. 101): result 0, coda i->i_count is 1, cii->contcount is 1 for ino 1025 
Oct  3 16:16:51 gnet kernel: (coda_open,l. 105): cache ino: 5476, count 1, ops c0279a80 
Oct  3 16:16:51 gnet kernel: Process 1198 leaving coda_open 
Oct  3 16:16:51 gnet kernel: Process 1198 entered coda_revalidate_inode 
Oct  3 16:16:51 gnet kernel: (coda_revalidate_inode,l. 746): revalidating: /// 
Oct  3 16:16:51 gnet kernel: Process 1198 entered coda_readdir 
Oct  3 16:16:51 gnet kernel: Process 1198 entered coda_venus_readdir 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 582): kmalloced: 800 at c1e8b800. 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 603): buffsize: 512 offset 0, count 0. 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 628): entry 0: ino 1025, namlen 1, reclen 12, type 0, pos 0, string_offs 8, name ., offset 0, result: 0, errfill: 0. 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 628): entry 1: ino 1025, namlen 2, reclen 12, type 0, pos 12, string_offs 8, name .., offset 12, result: 1, errfill: 0. 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 628): entry 2: ino 67618, namlen 7, reclen 16, type 0, pos 24, string_offs 8, name testvol, offset 24, result: 2, errfill: 0. 
Oct  3 16:16:51 gnet kernel: (coda_venus_readdir,l. 658): kfreed: 800 at c1e8b800. 
Oct  3 16:16:51 gnet kernel: Process 1198 leaving coda_readdir 
Oct  3 16:16:51 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:52 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:52 gnet kernel: Process 1198 entered coda_lookup 
Oct  3 16:16:52 gnet kernel: (coda_lookup,l. 115): name testvol, len 7 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:52 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4c at c3c1d6e0. 
Oct  3 16:16:52 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:52 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(10,29) msg at c2de6be0.zzz. 
Oct  3 16:16:52 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,29), nbytes 28 
Oct  3 16:16:52 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 29 on queue! 
Oct  3 16:16:52 gnet kernel: (coda_psdev_write,l. 215): Found! Count 28 for (opc,uniq)=(10,29), upc_req at c22a7f6c 
Oct  3 16:16:52 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:52 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:52 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:52 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 2 uniq: 29 size: 28 
Oct  3 16:16:52 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6be0, data at c3c1d6e0 
Oct  3 16:16:52 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (29, 10, 0) out at c3c1d6e0 
Oct  3 16:16:52 gnet kernel: (venus_lookup,l. 177): kfreed: 4c at c3c1d6e0. 
Oct  3 16:16:52 gnet kernel: (coda_lookup,l. 135): dropme set for (0x7f000000,0x42,0x22) 
Oct  3 16:16:52 gnet kernel: Process 1198 entered coda_cnode_make 
Oct  3 16:16:52 gnet kernel: Process 1198 entered venus_getattr 
Oct  3 16:16:53 gnet kernel: (alloc_upcall,l. 52): kmalloced: 64 at c3c1d6e0. 
Oct  3 16:16:53 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:53 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(7,30) msg at c2de6be0.zzz. 
Oct  3 16:16:53 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,7,30), nbytes 100 
Oct  3 16:16:53 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 30 on queue! 
Oct  3 16:16:53 gnet kernel: (coda_psdev_write,l. 215): Found! Count 100 for (opc,uniq)=(7,30), upc_req at c22a7f6c 
Oct  3 16:16:53 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:53 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:53 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:53 gnet kernel: (coda_upcall,l. 780): opc: 7 time: 0 uniq: 30 size: 100 
Oct  3 16:16:53 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6be0, data at c3c1d6e0 
Oct  3 16:16:53 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (30, 7, 0) out at c3c1d6e0 
Oct  3 16:16:53 gnet kernel: (venus_getattr,l. 127): kfreed: 64 at c3c1d6e0. 
Oct  3 16:16:53 gnet kernel: Process 1198 leaving venus_getattr 
Oct  3 16:16:53 gnet kernel: (coda_fill_inode,l. 45): ino: 67618 
Oct  3 16:16:53 gnet kernel: attr: type C_VLNK (5)  mode 644 uid 1000 gid 65534 rdev 1 
Oct  3 16:16:53 gnet kernel:       fileid 67618 nlink 1 size 8 blocksize 8192 bytes 8 
Oct  3 16:16:53 gnet kernel:       gen 0 flags 0 
Oct  3 16:16:53 gnet kernel:       atime sec 1002117747 nsec 0 
Oct  3 16:16:54 gnet kernel:       mtime sec 1002117747 nsec 0 
Oct  3 16:16:54 gnet kernel:       ctime sec 0 nsec 0 
Oct  3 16:16:54 gnet kernel: (coda_cnode_make,l. 127): Done making inode: ino 67618, count 1 with (0x7f000000,0x42,0x22) 
Oct  3 16:16:54 gnet kernel: Process 1198 leaving coda_cnode_make 
Oct  3 16:16:54 gnet kernel: (coda_lookup,l. 147): lookup: testvol is ((0x7f000000,0x42,0x22)), type 5 result 0, dropme 1 
Oct  3 16:16:54 gnet kernel: Process 1198 leaving coda_lookup 
Oct  3 16:16:54 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:54 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:54 gnet kernel: Process 1198 entered coda_lookup 
Oct  3 16:16:54 gnet kernel: (coda_lookup,l. 115): name testvol, len 7 in ino 1025, fid (0x7f000000,0x1,0x1) 
Oct  3 16:16:54 gnet kernel: (alloc_upcall,l. 52): kmalloced: 4c at c3c1d6e0. 
Oct  3 16:16:54 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:54 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(10,31) msg at c2de6be0.zzz. 
Oct  3 16:16:54 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,10,31), nbytes 28 
Oct  3 16:16:54 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 31 on queue! 
Oct  3 16:16:54 gnet kernel: (coda_psdev_write,l. 215): Found! Count 28 for (opc,uniq)=(10,31), upc_req at c22a7f6c 
Oct  3 16:16:54 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:54 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:55 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 780): opc: 10 time: 0 uniq: 31 size: 28 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6be0, data at c3c1d6e0 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (31, 10, 0) out at c3c1d6e0 
Oct  3 16:16:55 gnet kernel: (venus_lookup,l. 177): kfreed: 4c at c3c1d6e0. 
Oct  3 16:16:55 gnet kernel: (coda_lookup,l. 135): dropme set for (0x7f000000,0x42,0x22) 
Oct  3 16:16:55 gnet kernel: Process 1198 entered coda_cnode_make 
Oct  3 16:16:55 gnet kernel: Process 1198 entered venus_getattr 
Oct  3 16:16:55 gnet kernel: (alloc_upcall,l. 52): kmalloced: 64 at c3c1d6e0. 
Oct  3 16:16:55 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(7,32) msg at c2de6be0.zzz. 
Oct  3 16:16:55 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,7,32), nbytes 100 
Oct  3 16:16:55 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 32 on queue! 
Oct  3 16:16:55 gnet kernel: (coda_psdev_write,l. 215): Found! Count 100 for (opc,uniq)=(7,32), upc_req at c22a7f6c 
Oct  3 16:16:55 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:55 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:55 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 780): opc: 7 time: 1 uniq: 32 size: 100 
Oct  3 16:16:55 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6be0, data at c3c1d6e0 
Oct  3 16:16:56 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (32, 7, 0) out at c3c1d6e0 
Oct  3 16:16:56 gnet kernel: (venus_getattr,l. 127): kfreed: 64 at c3c1d6e0. 
Oct  3 16:16:56 gnet kernel: Process 1198 leaving venus_getattr 
Oct  3 16:16:56 gnet kernel: (coda_fill_inode,l. 45): ino: 67618 
Oct  3 16:16:56 gnet kernel: attr: type C_VLNK (5)  mode 644 uid 1000 gid 65534 rdev 1 
Oct  3 16:16:56 gnet kernel:       fileid 67618 nlink 1 size 8 blocksize 8192 bytes 8 
Oct  3 16:16:56 gnet kernel:       gen 0 flags 0 
Oct  3 16:16:56 gnet kernel:       atime sec 1002117747 nsec 0 
Oct  3 16:16:56 gnet kernel:       mtime sec 1002117747 nsec 0 
Oct  3 16:16:56 gnet kernel:       ctime sec 0 nsec 0 
Oct  3 16:16:56 gnet kernel: (coda_cnode_make,l. 127): Done making inode: ino 67618, count 1 with (0x7f000000,0x42,0x22) 
Oct  3 16:16:56 gnet kernel: Process 1198 leaving coda_cnode_make 
Oct  3 16:16:56 gnet kernel: (coda_lookup,l. 147): lookup: testvol is ((0x7f000000,0x42,0x22)), type 5 result 0, dropme 1 
Oct  3 16:16:56 gnet kernel: Process 1198 leaving coda_lookup 
Oct  3 16:16:56 gnet kernel: Process 1198 entered coda_permission 
Oct  3 16:16:56 gnet kernel: (coda_cache_check,l. 78): HIT for ino 1025 
Oct  3 16:16:56 gnet kernel: Process 1198 entered coda_dentry_revalidate 
Oct  3 16:16:56 gnet kernel: Process 1198 entered coda_readdir 
Oct  3 16:16:56 gnet kernel: Process 1198 entered coda_venus_readdir 
Oct  3 16:16:57 gnet kernel: (coda_venus_readdir,l. 582): kmalloced: 800 at c1e8b800. 
Oct  3 16:16:57 gnet kernel: (coda_venus_readdir,l. 658): kfreed: 800 at c1e8b800. 
Oct  3 16:16:57 gnet kernel: Process 1198 leaving coda_readdir 
Oct  3 16:16:57 gnet kernel: Process 1198 entered coda_flush 
Oct  3 16:16:57 gnet kernel: (coda_flags_to_cflags,l. 97): --> C_O_READ added 
Oct  3 16:16:57 gnet kernel: Process 1198 entered coda_release 
Oct  3 16:16:57 gnet kernel: (alloc_upcall,l. 52): kmalloced: 40 at c2de6be0. 
Oct  3 16:16:57 gnet kernel: Process 1198 entered coda_upcall 
Oct  3 16:16:57 gnet kernel: (coda_upcall,l. 762): Proc 1198 wake Venus for(opc,uniq) =(5,33) msg at c2de6c60.zzz. 
Oct  3 16:16:57 gnet kernel: (coda_psdev_write,l. 119): (process,opc,uniq)=(1171,5,33), nbytes 12 
Oct  3 16:16:57 gnet kernel: (coda_psdev_write,l. 186): Eureka: uniq 33 on queue! 
Oct  3 16:16:57 gnet kernel: (coda_psdev_write,l. 215): Found! Count 12 for (opc,uniq)=(5,33), upc_req at c22a7f6c 
Oct  3 16:16:57 gnet kernel: (coda_waitfor_upcall,l. 706): begin: 0.000000, elapsed: 0.000000 
Oct  3 16:16:57 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:57 gnet kernel: (do_time_stats,l. 145): time: 0 
Oct  3 16:16:57 gnet kernel: (coda_upcall,l. 780): opc: 5 time: 0 uniq: 33 size: 12 
Oct  3 16:16:57 gnet kernel: (coda_upcall,l. 783): ..process 1198 woken up by Venus for req at c2de6c60, data at c2de6be0 
Oct  3 16:16:57 gnet kernel: (coda_upcall,l. 792): upcall: (u,o,r) (33, 5, 0) out at c2de6be0 
Oct  3 16:16:57 gnet kernel: (venus_close,l. 243): kfreed: 40 at c2de6be0. 


That's it... I hope this gives some clues...