(Illustration by Gaich Muramatsu)
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hi, once again, my venus won't start. But this time it seems to be another problem than the one on Sep 14, 2003. Fortunately, I've got a venus binary with debug information now. Perhaps someone can tell me, what's gone wrong. FYI: The client is connected directly via 100Mbit to the server and only one client accesses coda at a time. Therefore I don't understand how a conflict could occur in the first place. (There's one file mentioned in floyd.netego.de_florian.tar) OK, below is the information I gathered - I hope it's not too long. I haven't initialised venus till now, therefore I can try "some things" with the system if that would be useful. Ciao Florian - -----------------[ console ]----------------- 13:09:51 Reintegrate florian pending tokens for uid = 500 13:10:02 worker::main Got a bogus opcode 36 13:10:02 Resolved realm 'floyd.netego.de' 13:10:08 Checkpointing florian 13:10:08 to /usr/coda/spool/500/floyd.netego.de_florian.tar 13:10:08 and /usr/coda/spool/500/floyd.netego.de_florian.cml 13:10:08 Local inconsistent object at ???/anderes/config, please check! 13:10:08 Reintegrate: florian, 4/4 records, result = Unknown error 198 13:10:15 fatal error -- cmlent::thread: can't find (50294108.7f000001.151.caa) 13:10:15 RecovTerminate: clean shutdown Assertion failed: 0, file "vol_cml.cc", line 2469 Sleeping forever. You may use gdb to attach to process 620. - -----------------[ backtrace ]----------------- (gdb) bt #0 0x40214495 in nanosleep () from /lib/libc.so.6 #1 0x40214318 in sleep () from /lib/libc.so.6 #2 0x080db918 in coda_assert (pred=0x80e44f8 "0", file=0x80f1130 "vol_cml.cc", line=2469) at coda_assert.c:46 #3 0x08090501 in choke(char*, int, char*, ...) (file=0x80f1130 "vol_cml.cc", line=2469, fmt=0x80f2380 "cmlent::thread: can't find (%s)") at venusutil.cc:210 #4 0x080a049c in cmlent::thread() (this=0x502876c8) at venusfid.h:78 #5 0x0809e825 in ClientModifyLog::IncThread(int) (this=0x50293ba8, tid=-102) at vol_cml.cc:1946 #6 0x080a5d2f in repvol::IncReintegrate(int) (this=0x50293b08, tid=-102) at vol_reintegrate.cc:278 #7 0x080a5978 in repvol::Reintegrate() (this=0x50293b08) at vol_reintegrate.cc:165 #8 0x080a6aa7 in reintegrator::main() (this=0x8136570) at vol_reintegrate.cc:753 #9 0x080acf29 in VprocPreamble(Lock*) (init_lock=0x81365b0) at vproc.cc:146 #10 0x4007ce9a in Create_Process_Part2 () at lwp.c:796 - -----------------[ venus.log ]----------------- [ X(00) : 0000 : 13:09:44 ] Coda Venus, version 6.0.2 [ X(00) : 0000 : 13:09:44 ] Logfile initialized with LogLevel = 0 at Fri Oct 3 13:09:44 2003 [ X(00) : 0000 : 13:09:44 ] E StatsInit() [ X(00) : 0000 : 13:09:44 ] L StatsInit() [ X(00) : 0000 : 13:09:45 ] BeginRvmFlush (1, 60, F) [ X(00) : 0000 : 13:09:45 ] EndRvmFlush [ X(00) : 0000 : 13:09:45 ] BeginRvmTruncate (1, 220, F) [ X(00) : 0000 : 13:09:45 ] EndRvmTruncate [ X(00) : 0000 : 13:09:46 ] BeginRvmFlush (1, 508, F) [ X(00) : 0000 : 13:09:46 ] EndRvmFlush [ X(00) : 0000 : 13:09:46 ] BeginRvmTruncate (3, 668, F) [ X(00) : 0000 : 13:09:46 ] EndRvmTruncate [ X(00) : 0000 : 13:09:46 ] E adv_daemon::adv_daemon: AdviceServer [ A(18) : 0000 : 13:09:46 ] adv_daemon::main() [ H(07) : 0000 : 13:09:46 ] HDBDaemon about to sleep on hdbdaemon_sync [ W(20) : 0000 : 13:09:46 ] FidToNodeid: called for volume root (50328f88.ff000001)!!! [ D(21) : 0000 : 13:09:51 ] WAITING(SRVRQ): [ V(05) : 0000 : 13:09:51 ] userent::Connect: ViceGetAttrPlusSHA(floyd.netego.de) [ V(05) : 0000 : 13:09:51 ] userent::Connect: ViceGetAttrPlusSHA() -> 22 [ V(05) : 0000 : 13:09:51 ] userent::Connect: VGAPlusSHA_Supported -> 1 [ D(21) : 0000 : 13:09:51 ] WAIT OVER, elapsed = 19.5 [ D(21) : 0000 : 13:09:51 ] userent::Connect: ViceGetAttrPlusSHA(floyd.netego.de) [ D(21) : 0000 : 13:09:51 ] userent::Connect: ViceGetAttrPlusSHA() -> 22 [ D(21) : 0000 : 13:09:51 ] userent::Connect: VGAPlusSHA_Supported -> 1 [ T(01) : 0001 : 13:10:01 ] BeginRvmFlush (1, 5156, T) [ T(01) : 0001 : 13:10:02 ] EndRvmFlush [ W(20) : 0000 : 13:10:02 ] Cachefile::SetLength 512 [ W(20) : 0000 : 13:10:02 ] worker::main Got a bogus opcode 36 [ V(05) : 0002 : 13:10:07 ] Reintegrate [ I(22) : 0000 : 13:10:08 ] repvol::Reintegrate [ I(22) : 0000 : 13:10:08 ] userent::Connect: ViceGetAttrPlusSHA(floyd.netego.de) [ I(22) : 0000 : 13:10:08 ] userent::Connect: ViceGetAttrPlusSHA() -> 22 [ I(22) : 0000 : 13:10:08 ] userent::Connect: VGAPlusSHA_Supported -> 1 [ I(22) : 0000 : 13:10:08 ] mysha(20, 20) = 8f.be.f9.c3.09.b4.d0.79.2d.57.cf.44.47.f0.d4.f9.9b.df.73.e2 .[ I(22) : 0000 : 13:10:08 ] mysha(20, 20) = fb.ed.ab.f0.0f.a1.13.9b.68.a9.32.53.31.a2.96.29.73.24.91.8d .[ I(22) : 0000 : 13:10:08 ] mysha(20, 20) = f5.f8.53.ff.82.19.85.6d.fa.7b.bd.25.ce.50.41.03.3a.a0.2d.72 .[ I(22) : 0000 : 13:10:08 ] mysha(20, 20) = e7.a6.09.64.5b.1d.f6.fa.9d.ed.bc.a3.4d.3d.54.30.2a.38.5f.14 .[ I(22) : 0000 : 13:10:08 ] volent::DisableASR: disabling asr for 7f000001 [ I(22) : 0000 : 13:10:08 ] ClientModifyLog::GetReintegrateable: (florian, -101) 4 records, 46 msec [ I(22) : 0000 : 13:10:08 ] volent::IncReintegrate: (florian, -101) uid = 500 [ I(22) : 0000 : 13:10:08 ] ClientModifyLog::IncReallocFids: (florian) [ I(22) : 0000 : 13:10:08 ] ClientModifyLog::IncThread: (florian) [ I(22) : 0000 : 13:10:08 ] ClientModifyLog::IncPack: (florian) [ I(22) : 0000 : 13:10:08 ] userent::Connect: ViceGetAttrPlusSHA(floyd.netego.de) [ I(22) : 0000 : 13:10:08 ] userent::Connect: ViceGetAttrPlusSHA() -> 22 [ I(22) : 0000 : 13:10:08 ] userent::Connect: VGAPlusSHA_Supported -> 1 [ I(22) : 0000 : 13:10:08 ] ClientModifyLog::COP1: (florian), 532 bytes, returns 198, index = 2 [ I(22) : 0000 : 13:10:08 ] volent::IncReintegrate: fail code = 198 ClientModifyLog: owner = 500, count = 4 current stats: 1 0.2 21.5 3 0.8 cancelled stats: 0 0.0 0.0 0 0.0 [...] 0x50311748 : fid = (50294108.7f000001.6f4.3bb), comp = posted, vol = 50293b08 state = Normal, stat = { 8636, 54, 1062480290, 500, 0644, 1, File }, rc rights = 3 VV = {[ 56 0 0 0 0 0 0 0 ] [ 0xc03 1920 ] [ 0 ]} voltype = [0 1 0], fake = 0, fetching = 0 local = 0 rep = 1, data = 0, owrite = 0, dirty = 0, shadow = 0 mvstat = Normal parent = (50294108.7f000001.5f.290, 50312548), children = 0 priority = 19825 (32479), hoard = [0, -2, 0], lastref = 15407 mle_bindings = (0, 0), cleanstat = [-1, -1] cachefile = [ 00/00/00/91, -1, 0/0 ] refs = [0 0 0], openers = [0 0 0] lastresolved = 0 VFS Operations Operation Counts Times Root : 0 [ 0 0 0] : 0.0 ( 0.0) OpenByFD : 0 [ 0 0 0] : 0.0 ( 0.0) Open : 1 [ 0 0 0] : 1.1 ( 0.0) Close : 1 [ 0 0 0] : 0.0 ( 0.0) Ioctl : 0 [ 0 0 0] : 0.0 ( 0.0) Getattr : 1 [ 0 0 0] : 0.4 ( 0.0) Setattr : 0 [ 0 0 0] : 0.0 ( 0.0) Access : 3 [ 0 0 0] : 1.2 ( 2.0) Lookup : 0 [ 0 0 0] : 0.0 ( 0.0) Create : 0 [ 0 0 0] : 0.0 ( 0.0) Remove : 0 [ 0 0 0] : 0.0 ( 0.0) Link : 0 [ 0 0 0] : 0.0 ( 0.0) Rename : 0 [ 0 0 0] : 0.0 ( 0.0) Mkdir : 0 [ 0 0 0] : 0.0 ( 0.0) Rmdir : 0 [ 0 0 0] : 0.0 ( 0.0) Symlink : 0 [ 0 0 0] : 0.0 ( 0.0) Readlink : 0 [ 0 0 0] : 0.0 ( 0.0) Fsync : 0 [ 0 0 0] : 0.0 ( 0.0) Vget : 0 [ 0 0 0] : 0.0 ( 0.0) Signal : 0 [ 0 0 0] : 0.0 ( 0.0) Replace : 6 [ 0 0 0] : 0.0 ( 0.0) Flush : 4 [ 0 0 0] : 0.0 ( 0.0) PurgeUser : 1 [ 0 0 0] : 0.0 ( 0.0) ZapFile : 17 [ 0 0 0] : 0.0 ( 0.0) ZapDir : 47 [ 0 0 0] : 0.0 ( 0.0) PurgeFid : 249 [ 0 0 0] : 0.0 ( 0.0) OpenByPath : 0 [ 0 0 0] : 0.0 ( 0.0) Resolve : 0 [ 0 0 0] : 0.0 ( 0.0) Reintegrate : 0 [ 0 0 1] : 0.0 ( 0.0) Statfs : 0 [ 0 0 0] : 0.0 ( 0.0) RPC Operations: Operation Good Bad Time MGood MBad MTime RPCR MRPCR GetAttr 0 0 0.0 0 0 0.0 0 0 GetACL 0 0 0.0 0 0 0.0 0 0 Fetch 0 0 0.0 0 0 0.0 0 0 SetAttr 0 0 0.0 0 0 0.0 0 0 SetACL 0 0 0.0 0 0 0.0 0 0 Store 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 GetRootVolume 0 0 0.0 0 0 0.0 0 0 SetRootVolume 0 0 0.0 0 0 0.0 0 0 GetVolumeStatus 0 0 0.0 0 0 0.0 0 0 SetVolumeStatus 0 0 0.0 0 0 0.0 0 0 DisconnectFS 0 0 0.0 0 0 0.0 0 0 GetTime 0 0 0.0 1 0 1.1 0 0 nExpired 0 0 0.0 0 0 0.0 0 0 GetOldStatistics 0 0 0.0 0 0 0.0 0 0 GetStatistics 0 0 0.0 0 0 0.0 0 0 GetVolumeInfo 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 COP2 0 0 0.0 0 0 0.0 0 0 Resolve 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 Repair 0 0 0.0 0 0 0.0 0 0 SetVV 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 AllocFids 0 0 0.0 0 0 0.0 0 0 ValidateAttrs 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 NewConnectFS 4 0 5.7 0 0 0.0 0 0 GetVolVS 0 0 0.0 1 0 0.6 0 0 ValidateVols 0 0 0.0 2 0 11.2 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 VRemove 0 0 0.0 0 0 0.0 0 0 VCreate 0 0 0.0 0 0 0.0 0 0 VRename 0 0 0.0 0 0 0.0 0 0 VSymLink 0 0 0.0 0 0 0.0 0 0 VLink 0 0 0.0 0 0 0.0 0 0 VMakeDir 0 0 0.0 0 0 0.0 0 0 VRemoveDir 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 y 0 0 0.0 0 0 0.0 0 0 OpenReintHandle 0 0 0.0 0 0 0.0 0 0 QueryReintHandle 0 0 0.0 0 0 0.0 0 0 SendReintFragment 0 0 0.0 0 0 0.0 0 0 CloseReintHandle 0 0 0.0 0 0 0.0 0 0 Reintegrate 0 0 0.0 0 1 0.0 0 0 GetWBPermit 0 0 0.0 0 0 0.0 0 0 TossWBPermit 0 0 0.0 0 0 0.0 0 0 RejectWBPermit 0 0 0.0 0 0 0.0 0 0 GetAttrPlusSHA 4 0 0.6 0 0 0.0 0 0 ValidateAttrsPlusSHA 0 0 0.0 6 0 16.1 0 0 RPC Packets: RPC2: Sent: Total Retrys Busies Naks Uni: 38 : 21319 0 0 0 Multi: 0 : 0 0 0 0 Received: Total Replys Reqs Busies Bogus Naks Uni: 38 : 4480 22 : 0 9 : 7 0 : 0 0 0 Multi: 0 : 0 0 : 0 0 : 0 0 : 0 0 0 SFTP: Sent: Total Starts Datas Acks Naks Busies Uni: 0 : 0 0 0 : 0 0 0 0 Multi: 0 : 0 0 0 : 0 0 0 0 Received: Total Starts Datas Acks Naks Busies Uni: 0 : 0 0 0 : 0 0 0 0 Multi: 0 : 0 0 0 : 0 0 0 0 HDB: counts = [625, 0, 0], namectxts = [0, 0, 0, 0] [0, 0] connent: 1, 0, 24 srvent: 1, 0, 56 mgrpent: 3, 0, 564 vsgent: 1, 0, 64 volrep: 0, 0, 0 repvol: 0, 0, 0 binding: 7, 0, 252 namectxt: 0, 0, 0 resent: 0, 0, 0 cop2ent: 0, 0, 0 msgent: 1, 0, 8452 repair_session_tid = -1000000 repair_tid_gen = 1000000 subtree_view = SUBTREE_MIXED_VIEW repair_root_fid = NULL current_search_cml = NULL repair_session_mode = REP_SCRATCH_MODE there are 0 entries in repair_obj_list ======================================================================= ======================================================================= there are 0 entries in repair_vol_list ======================================================================= ======================================================================= there are 0 entries in repair_cml_list ======================================================================= ======================================================================= there are 6 entries in the global-local-fid map (local = 50328f88.ffffffff.ffffffff.2 global = 50294108.7f000001.151.caa) (local = 50328f88.ffffffff.fffffffe.3 global = 50294108.7f000001.6b52.34b1) (local = 50328f88.ffffffff.fffffffe.4 global = 50294108.7f000001.c58.52b0) (local = 50328f88.ffffffff.fffffffe.5 global = 50294108.7f000001.24cc.84e0) (local = 50328f88.ffffffff.fffffffe.6 global = 50294108.7f000001.24ce.84e1) (local = 50328f88.ffffffff.fffffffe.7 global = 50294108.7f000001.25d2.84c1) there are 1 entries in the root-fid map ==================================== fake_root_fid = 50294108.7f000001.3cb.839b global_root_fid = 50294108.7f000001.151.caa local_root_fid = 50328f88.ffffffff.ffffffff.2 root_parent_fid = 50294108.7f000001.43.282 global_child_fid = 50294108.7f000001.fffffffc.80000 LocalChildFid = 50294108.7f000001.fffffffc.80001 name = config root_mtpt = 0 root is not covered view = Mixed-View ==================================== ************************ [ I(22) : 0001 : 13:10:15 ] BeginRvmFlush (1, 17316, F) [ I(22) : 0001 : 13:10:15 ] EndRvmFlush - -----------------[ rvmutl ]----------------- root_at_zini:~ # rvmutl * o /usr/coda/LOG * status Status of log: /usr/coda/LOG log created on: Sun Sep 14 2003 14:41:04.277677 log created with: RVM Interface Version 1.3 7 Mar 1994 RVM Log Version 1.4 Oct 17, 1997 RVM Statistics Version 1.1 8 Dec 1992 status last written: Fri Oct 3 2003 13:10:15.728607 last truncation: Fri Oct 3 2003 13:09:46.398496 log head offset: 285552 log tail offset: 308396 log empty: false space used by records: 22844 space available: 807620 status area size: 1536 total log size: 832000 first record number: 1132 last record number: 1135 first timestamp: null last timestamp: null first trans. uname: null last trans. uname: null -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.2.0 (GNU/Linux) Comment: Get my DSA key from: www.netego.de/hpc?p=download&l=en iD8DBQE/fWFq+2lxodi1OoURAmPXAJ984jOLNMwcsG6McfRN68PsvMnsXwCeNFRX EXU5LV0/cwdkDLDCYmBNlfk= =FYYE -----END PGP SIGNATURE-----Received on 2003-10-03 07:53:27