Coda File System

MaxRetries, EWOULDBLOCK,

From: Steffen Neumann <sneumann_at_TechFak.Uni-Bielefeld.DE>
Date: 28 May 2003 10:09:56 +0200
Hi Jan et al,

A User complains about slowness of her operations.
A different coda client seems to work better,
but I'd like to know what went wrong on this one,
it had been -init'ed yesterday. As you can see from
some of the filenames, it's this time quite important 
that we don't loose data, any help appreciated.

Yours,
Steffen

Checking the console I have plenty of  

	[...]
	09:45:44 MaxRetries exceeded...returning EWOULDBLOCK
	09:47:17 MaxRetries exceeded...returning EWOULDBLOCK
	09:47:25 MaxRetries exceeded...returning EWOULDBLOCK

The volume she's using looks fine:

          Status of volume 0x7f00002a (2130706474) named "coda.homes.kerstin"
          Volume type is ReadWrite
          Connection State is Connected
          Minimum quota is 0, maximum quota is unlimited
          Current blocks used are 198059
          The partition has 279668 blocks available out of 4787924
          Write-back is disabled
        
and checking venus log with loglevel 100 I get 
        
       	[ W(21) : 0000 : 09:47:25 ] vproc::Begin_VFS(Remove): vid = 7f00002a, u.u_vol = 0, mode = -1
       	[ W(21) : 0000 : 09:47:25 ] vproc::End_VFS(Remove): code = 157
       	[ W(21) : 0000 : 09:47:25 ] Remove : returns Resource temporarily unavailable, elapsed = 23.9 msec
       	[ W(21) : 0000 : 09:47:25 ] vproc::lookup: fid = (0x7f00002a.0xd1.0xd54), name = flexibility.tex, nc = 0
       	[ W(21) : 0000 : 09:47:25 ] vproc::Begin_VFS(Lookup): vid = 7f00002a, u.u_vol = 0, mode = -1
	[ W(21) : 0000 : 09:47:25 ] vproc::End_VFS(Lookup): code = 0
	[ W(21) : 0000 : 09:47:25 ] Lookup : returns SUCCESS, elapsed = 0.9 msec
	[ W(21) : 0000 : 09:47:25 ] vproc::getattr: fid = (0x7f00002a.0xc70.0x3950)
	[ W(21) : 0000 : 09:47:25 ] vproc::Begin_VFS(Getattr): vid = 7f00002a, u.u_vol = 0, mode = -1
	[ W(21) : 0000 : 09:47:25 ] vproc::End_VFS(Getattr): code = 0
	[ W(21) : 0000 : 09:47:25 ] Getattr : returns SUCCESS, elapsed = 0.0 msec
	[ W(21) : 0000 : 09:47:25 ] vproc::getattr: fid = (0x7f00002a.0xc70.0x3950)
	[ W(21) : 0000 : 09:47:25 ] vproc::Begin_VFS(Getattr): vid = 7f00002a, u.u_vol = 0, mode = -1
	[ W(21) : 0000 : 09:47:25 ] vproc::End_VFS(Getattr): code = 0
	[ W(21) : 0000 : 09:47:25 ] Getattr : returns SUCCESS, elapsed = 0.0 msec

Another thing I see is that venus.log claims 
the volume 0x7f00002a would be under repair,
which it isn't:

        [ W(21) : 0000 : 09:45:44 ] (Multi)ValidateAttrs: start
        [ W(21) : 0000 : 09:45:44 ] CommQueue: remove pri 3 count = 0
        [ W(21) : 0000 : 09:45:44 ] (Multi)ValidateAttrs: code = -2001, elapsed = 1.0
        [ W(21) : 0000 : 09:45:44 ] mgrpent::CheckNonMutating: acode = -2001
                        hosts = [0x628b4681 0 0 0 0 0 0 0],
                        retcodes = [0 -2002 -2002 -2002 -2002 -2002 -2002 -2002]
        [ W(21) : 0000 : 09:45:44 ] fsobj::GetAttr: ValidateAttrs (Diss), 0 fids sent, 0 checked
                        0: {[ 15459 0 0 0 0 0 0 0 ] [ 3086 1906 ] [ 0 ]}
        [ W(21) : 0000 : 09:45:44 ] fsobj::SetRcRights: ((0x7f00002a.0xd1.0xd54)), rights = 15
        [ W(21) : 0000 : 09:45:44 ] fsobj::UpdateStatus: ((0x7f00002a.0xd1.0xd54)), uid = 17154
        [ W(21) : 0000 : 09:45:44 ] fsobj::SetAcRights: ((0x7f00002a.0xd1.0xd54)), vuid = 17154, my_rights = 127, any_rights = 9
        [ W(21) : 0000 : 09:45:44 ] GetUser: uid = 17154
        [ W(21) : 0000 : 09:45:44 ] PutUser: 
        [ W(21) : 0000 : 09:45:44 ] mgrpent::Put 0x8145500, uid = 17154, mid = 33, auth = 1, refcount = 2, detached = 0
        [ W(21) : 0000 : 09:45:44 ] mgrpent::PutHostSet: 0x8145500
        [ W(21) : 0000 : 09:45:44 ] fsdb::Get-mre: key = (7f00002a.23b6.47b3), uid = 17154, rights = 3, comp = .#flexibility.tex
        [ W(21) : 0000 : 09:45:44 ] repvol::IsUnderRepair: vol = 7f00002a, vuid = -1
        [ W(21) : 0000 : 09:45:44 ] fsobj::Reference: ((0x7f00002a.0x23b6.0x47b3)), old = 91766, new = 91768
        [ W(21) : 0000 : 09:45:44 ] fsobj::Access : (Diss, 16, 0), uid = 17154
        [ W(21) : 0000 : 09:45:44 ] GetUser: uid = 17154
        [ W(21) : 0000 : 09:45:44 ] PutUser: 
        [ W(21) : 0000 : 09:45:44 ] fsobj::Remove: (Diss, .#flexibility.tex), uid = 17154
        [ W(21) : 0000 : 09:45:44 ] vsgent::GetMgrp 0x8114d08 17154 1
        [ W(21) : 0000 : 09:45:44 ] mgrpent::GetHostSet: 0x8145500, uid = 17154, mid = 33
        [ W(21) : 0000 : 09:45:44 ] volent::FlushCOP2(Piggy): vol = 7f00002a
        [ W(21) : 0000 : 09:45:44 ] CommQueue: insert pri 3 count = 1
        [ W(21) : 0000 : 09:45:44 ] (Multi)VRemove: start
        [ W(21) : 0000 : 09:45:44 ] CommQueue: remove pri 3 count = 0
        [ W(21) : 0000 : 09:45:44 ] (Multi)VRemove: code = -2001, elapsed = 20.6

The server has quite a few entries about this volume as well:

        09:46:12 ViceValidateAttrs: (1000017.700.1bc9) failed ()!
        09:46:12 ViceValidateAttrs: (1000017.8e8.2712) failed ()!
[...]
        09:46:12 VGetVnode: vnode 1000017.2288 is not allocated
        09:46:12 ViceValidateAttrs: (1000017.2288.467c) failed (GetFsObj 1)!
        09:46:13 VGetVnode: vnode 1000004.12142 is not allocated
        09:47:10 CheckRemoveSemantics: (0x1000017.0x239c.0x4786), VCP error (198)
        09:47:10 Entering VFlushVnode for vnode 0xd1
        09:47:10 Entering VFlushVnode for vnode 0x239c
        09:47:10 CheckRemoveSemantics: (0x1000017.0x239c.0x4786), VCP error (198)
        09:47:10 Entering VFlushVnode for vnode 0xd1
        09:47:10 Entering VFlushVnode for vnode 0x239c
[...]
        09:47:18 CheckRemoveSemantics: (0x1000017.0x239c.0x4786), VCP error (198)
        09:47:18 Entering VFlushVnode for vnode 0xd1
        

        
        
        
        
        
Received on 2003-05-28 04:13:04