[OpenAFS-port-freebsd] Client deadlock?

Garrett Wollman wollman@csail.MIT.EDU
Thu, 31 Mar 2011 12:58:34 -0400


<<On Wed, 30 Mar 2011 21:18:05 -0400 (EDT), Benjamin Kaduk <kaduk@MIT.EDU> said:

> cmdebug -cache would be more authoritative (the last time I tripped the 
> "small cache" behavior was when I was passing enough arguments to afsd 
> that the memcache size was determined by them and the cachinfo 
> specification was ignored).

It reports:

Chunk files:   1464
Stat caches:   2196
Data caches:   1464
Volume caches: 200
Chunk size:    1048576
Cache size:    1499136 kB
Set time:      no
Cache type:    memory

It turns out that even dd(1) hangs it nearly immediately:

$ dd if=/dev/zero of=test bs=64k count=1048576
load: 0.04  cmd: dd 7375 [afsslp] 17.63r 0.01u 0.45s 0% 1088k
load: 0.03  cmd: dd 7375 [afsslp] 21.97r 0.01u 0.45s 0% 1088k

Similar symptoms: two afsd's sleeping on afsslp, one in sbwait, and
rxdebug shows no connection with the server; other afsds doing
nothing, but the client does respond to rxdebug requests on the
callback port:

wollman@modesty:~$ rxdebug incoming-new 7001
Trying 128.30.2.181 (port 7001):
Free packets: 269, packet reclaims: 6, calls: 113, used FDs: 64
not waiting for packets.
0 calls waiting for a thread
1 threads are idle
Connection from host 128.30.2.188, port 7000, Cuid b40e39c4/43383920
  serial 57003675,  natMTU 1444, flags DESTROYED pktCksum, security index 2, client conn
  rxkad: level crypt, flags pktCksum
  Received -1197234936 bytes in 7808384 packets
  Sent 1414335526 bytes in 49636663 packets
    call 0: # 4370276, state dally, mode: receiving, flags: receive_done
    call 1: # 2057007, state not initialized
    call 2: # 0, state not initialized
    call 3: # 0, state not initialized
Done.

(incoming-new is the client, modesty is the server this particular
volume is on).

cmdebug -long reports:

$ cmdebug -long localhost
Lock afs_xvcache status: (none_waiting)
Lock afs_xdcache status: (none_waiting)
Lock afs_xserver status: (none_waiting)
Lock afs_xvcb status: (none_waiting)
Lock afs_xbrs status: (none_waiting)
Lock afs_xcell status: (none_waiting)
Lock afs_xconn status: (none_waiting)
Lock afs_xuser status: (none_waiting)
Lock afs_xvolume status: (none_waiting)
Lock puttofile status: (none_waiting)
Lock afs_ftf status: (none_waiting)
Lock afs_xcbhash status: (none_waiting)
Lock afs_xaxs status: (none_waiting)
Lock afs_xinterface status: (none_waiting)
Lock afs_xosi status: (none_waiting)
Lock afs_xsrvAddr status: (none_waiting)
Lock afs_xvreclaim status: (none_waiting)
Lock afsdb_client_loc status: (none_waiting)
Lock afsdb_req_lock status: (none_waiting)
Lock afs_discon_lock status: (none_waiting)
Lock afs_disconDirtyL status: (none_waiting)
Lock afs_discon_vc_di status: (none_waiting)
Lock dynroot status: (none_waiting)
Lock rl.ac.uk status: (none_waiting)
Lock hep.man.ac.uk status: (none_waiting)
Lock ic.ac.uk status: (none_waiting)
Lock inf.ed.ac.uk status: (none_waiting)
Lock phy.bris.ac.uk status: (none_waiting)
Lock hep-ex.physics.m status: (none_waiting)
Lock ihep.su status: (none_waiting)
Lock p-ng.si status: (none_waiting)
Lock f9.ijs.si status: (none_waiting)
Lock su.se status: (none_waiting)
Lock sanchin.se status: (none_waiting)
Lock physto.se status: (none_waiting)
Lock syd.kth.se status: (none_waiting)
Lock stacken.kth.se status: (none_waiting)
Lock pdc.kth.se status: (none_waiting)
Lock nada.kth.se status: (none_waiting)
Lock mech.kth.se status: (none_waiting)
Lock md.kth.se status: (none_waiting)
Lock it.kth.se status: (none_waiting)
Lock isk.kth.se status: (none_waiting)
Lock kth.se status: (none_waiting)
Lock riscpkg.org status: (none_waiting)
Lock pfriedma.org status: (none_waiting)
Lock oc7.org status: (none_waiting)
Lock nomh.org status: (none_waiting)
Lock mstacm.org status: (none_waiting)
Lock mrph.org status: (none_waiting)
Lock mrow.org status: (none_waiting)
Lock jeaton.org status: (none_waiting)
Lock idahofuturetruck status: (none_waiting)
Lock dementia.org status: (none_waiting)
Lock coed.org status: (none_waiting)
Lock bazquux.org status: (none_waiting)
Lock adrake.org status: (none_waiting)
Lock acm-csuf.org status: (none_waiting)
Lock 1ts.org status: (none_waiting)
Lock nikhef.nl status: (none_waiting)
Lock interdose.net status: (none_waiting)
Lock tproa.net status: (none_waiting)
Lock slackers.net status: (none_waiting)
Lock sinenomine.net status: (none_waiting)
Lock laroia.net status: (none_waiting)
Lock gorlaeus.net status: (none_waiting)
Lock es.net status: (none_waiting)
Lock epitech.net status: (none_waiting)
Lock crossproduct.net status: (none_waiting)
Lock lcp.nrl.navy.mil status: (none_waiting)
Lock cmf.nrl.navy.mil status: (none_waiting)
Lock italia status: (none_waiting)
Lock vn.uniroma3.it status: (none_waiting)
Lock dia.uniroma3.it status: (none_waiting)
Lock ing.uniroma1.it status: (none_waiting)
Lock math.unifi.it status: (none_waiting)
Lock tgrid.it status: (none_waiting)
Lock psm.it status: (none_waiting)
Lock roma3.infn.it status: (none_waiting)
Lock pi.infn.it status: (none_waiting)
Lock lngs.infn.it status: (none_waiting)
Lock lnf.infn.it status: (none_waiting)
Lock le.infn.it status: (none_waiting)
Lock kloe.infn.it status: (none_waiting)
Lock ba.infn.it status: (none_waiting)
Lock infn.it status: (none_waiting)
Lock ictp.it status: (none_waiting)
Lock icemb.it status: (none_waiting)
Lock fusione.it status: (none_waiting)
Lock enea.it status: (none_waiting)
Lock caspur.it status: (none_waiting)
Lock kfki.hu status: (none_waiting)
Lock bme.hu status: (none_waiting)
Lock doe.atomki.hu status: (none_waiting)
Lock nersc.gov status: (none_waiting)
Lock jpl.nasa.gov status: (none_waiting)
Lock ic-afs.arc.nasa. status: (none_waiting)
Lock fnal.gov status: (none_waiting)
Lock usatlas.bnl.gov status: (none_waiting)
Lock rhic.bnl.gov status: (none_waiting)
Lock anl.gov status: (none_waiting)
Lock mcc.ac.gb status: (none_waiting)
Lock in2p3.fr status: (none_waiting)
Lock dapnia.saclay.ce status: (none_waiting)
Lock biocenter.helsin status: (none_waiting)
Lock ific.uv.es status: (none_waiting)
Lock ifca.unican.es status: (none_waiting)
Lock ciemat.es status: (none_waiting)
Lock physics.wisc.edu status: (none_waiting)
Lock hep.wisc.edu status: (none_waiting)
Lock engr.wisc.edu status: (none_waiting)
Lock cs.wisc.edu status: (none_waiting)
Lock cs.uwm.edu status: (none_waiting)
Lock eng.utah.edu status: (none_waiting)
Lock uncc.edu status: (none_waiting)
Lock physics.unc.edu status: (none_waiting)
Lock isis.unc.edu status: (none_waiting)
Lock sph.umich.edu status: (none_waiting)
Lock citi.umich.edu status: (none_waiting)
Lock atlas.umich.edu status: (none_waiting)
Lock umich.edu status: (none_waiting)
Lock wam.umd.edu status: (none_waiting)
Lock glue.umd.edu status: (none_waiting)
Lock umbc.edu status: (none_waiting)
Lock ncsa.uiuc.edu status: (none_waiting)
Lock illigal.uiuc.edu status: (none_waiting)
Lock acm.uiuc.edu status: (none_waiting)
Lock cats.ucsc.edu status: (none_waiting)
Lock physics.ucsb.edu status: (none_waiting)
Lock slac.stanford.ed status: (none_waiting)
Lock ir.stanford.edu status: (none_waiting)
Lock cs.stanford.edu status: (none_waiting)
Lock hep.sc.edu status: (none_waiting)
Lock rpi.edu status: (none_waiting)
Lock cs.rose-hulman.e status: (none_waiting)
Lock rose-hulman.edu status: (none_waiting)
Lock cede.psu.edu status: (none_waiting)
Lock scoobydoo.psc.ed status: (none_waiting)
Lock psc.edu status: (none_waiting)
Lock cs.pitt.edu status: (none_waiting)
Lock pitt.edu status: (none_waiting)
Lock crc.nd.edu status: (none_waiting)
Lock nd.edu status: (none_waiting)
Lock msu.edu status: (none_waiting)
Lock soap.mit.edu status: (none_waiting)
Lock sipb.mit.edu status: (none_waiting)
Lock numenor.mit.edu status: (none_waiting)
Lock net.mit.edu status: (none_waiting)
Lock dev.mit.edu status: (none_waiting)
Lock athena.mit.edu status: (none_waiting)
Lock iastate.edu status: (none_waiting)
Lock eecs.harvard.edu status: (none_waiting)
Lock cs.hm.edu status: (none_waiting)
Lock northstar.dartmo status: (none_waiting)
Lock dbic.dartmouth.e status: (none_waiting)
Lock msc.cornell.edu status: (none_waiting)
Lock math.cornell.edu status: (none_waiting)
Lock cnf.cornell.edu status: (none_waiting)
Lock sbp.ri.cmu.edu status: (none_waiting)
Lock qatar.cmu.edu status: (none_waiting)
Lock scotch.ece.cmu.e status: (none_waiting)
Lock ece.cmu.edu status: (none_waiting)
Lock cs.cmu.edu status: (none_waiting)
Lock chem.cmu.edu status: (none_waiting)
Lock club.cc.cmu.edu status: (none_waiting)
Lock mw.andrew.cmu.ed status: (none_waiting)
Lock andrew.cmu.edu status: (none_waiting)
Lock clarkson.edu status: (none_waiting)
Lock ugcs.caltech.edu status: (none_waiting)
Lock hep.caltech.edu status: (none_waiting)
Lock eecs.berkeley.ed status: (none_waiting)
Lock mars.asu.edu status: (none_waiting)
Lock asu.edu status: (none_waiting)
Lock ies.auc.dk status: (none_waiting)
Lock s-et.aau.dk status: (none_waiting)
Lock physik.uni-wuppe status: (none_waiting)
Lock uni-paderborn.de status: (none_waiting)
Lock uni-mannheim.de status: (none_waiting)
Lock physik.uni-mainz status: (none_waiting)
Lock rrz.uni-koeln.de status: (none_waiting)
Lock meteo.uni-koeln. status: (none_waiting)
Lock impetus.uni-koel status: (none_waiting)
Lock rz.uni-jena.de status: (none_waiting)
Lock uni-hohenheim.de status: (none_waiting)
Lock ziti.uni-heidelb status: (none_waiting)
Lock urz.uni-heidelbe status: (none_waiting)
Lock mathi.uni-heidel status: (none_waiting)
Lock physnet.uni-hamb status: (none_waiting)
Lock physik.uni-freib status: (none_waiting)
Lock uni-freiburg.de status: (none_waiting)
Lock atlass01.physik. status: (none_waiting)
Lock e18.ph.tum.de status: (none_waiting)
Lock tu-chemnitz.de status: (none_waiting)
Lock tu-bs.de status: (none_waiting)
Lock combi.tfh-wildau status: (none_waiting)
Lock i1.informatik.rw status: (none_waiting)
Lock nicsys.de status: (none_waiting)
Lock mpe.mpg.de status: (none_waiting)
Lock ipp-garching.mpg status: (none_waiting)
Lock lrz-muenchen.de status: (none_waiting)
Lock integra-ev.de status: (none_waiting)
Lock ifh.de status: (none_waiting)
Lock cms.hu-berlin.de status: (none_waiting)
Lock gppc.de status: (none_waiting)
Lock desy.de status: (none_waiting)
Lock zcu.cz status: (none_waiting)
Lock ics.muni.cz status: (none_waiting)
Lock ruk.cuni.cz status: (none_waiting)
Lock sodre.cx status: (none_waiting)
Lock setfilepointer.c status: (none_waiting)
Lock membrain.com status: (none_waiting)
Lock freedaemon.com status: (none_waiting)
Lock extundo.com status: (none_waiting)
Lock psi.ch status: (none_waiting)
Lock ethz.ch status: (none_waiting)
Lock epfl.ch status: (none_waiting)
Lock ams.cern.ch status: (none_waiting)
Lock cern.ch status: (none_waiting)
Lock ualberta.ca status: (none_waiting)
Lock sums.math.mcgill status: (none_waiting)
Lock itp.tugraz.at status: (none_waiting)
Lock cgv.tugraz.at status: (none_waiting)
Lock hephy.at status: (none_waiting)
Lock wu-wien.ac.at status: (none_waiting)
Lock grand.central.or status: (none_waiting)
Lock csail.mit.edu status: (none_waiting)
** Cache entry @ 0x01916000 for 0.1.1.1 [dynroot]
            2048 bytes  DV          208  refcnt     1
    callback 00000000   expires 0
    0 opens     0 writers
    volume root
    states (0x5), stat'd, read-only
** Cache entry @ 0x0195ac40 for 203.536870916.1.1 [csail.mit.edu]
            2048 bytes  DV          256  refcnt     0
    callback 0a8bb280   expires 1301597388
    0 opens     0 writers
    volume root
    states (0x5), stat'd, read-only
** Cache entry @ 0x019a47d0 for 203.536870916.4.213 [csail.mit.edu]
               3 bytes  DV            1  refcnt     0
    callback 0a8bb280   expires 1301597388
    0 opens     0 writers
    mount point
    states (0xd), stat'd, read-only, mt pt valid
** Cache entry @ 0x0191ef70 for 203.536870921.1.1 [csail.mit.edu]
           18432 bytes  DV         4048  refcnt     0
    callback 0a158280   expires 1301604556
    0 opens     0 writers
    volume root
    states (0x1), stat'd
** Cache entry @ 0x019e5090 for 203.536870928.1.1 [csail.mit.edu]
            2048 bytes  DV          261  refcnt     0
    callback 0a8bb280   expires 1301597388
    0 opens     0 writers
    volume root
    states (0x5), stat'd, read-only
** Cache entry @ 0x019b8000 for 203.536870928.24.650 [csail.mit.edu]
              11 bytes  DV            0  refcnt     0
    callback 0a8bb280   expires 1301597388
    0 opens     0 writers
    mount point
    states (0xd), stat'd, read-only, mt pt valid
** Cache entry @ 0x01918d90 for 203.536870928.47.636 [csail.mit.edu]
            6144 bytes  DV          181  refcnt     0
    callback 0a8bb280   expires 1301597388
    0 opens     0 writers
    normal file
    states (0x5), stat'd, read-only
** Cache entry @ 0x0192a400 for 203.536870921.110.888004 [csail.mit.edu]
              19 bytes  DV            0  refcnt     2
    callback 0a158280   expires 1301604556
    0 opens     0 writers
    mount point
    states (0x9), stat'd, mt pt valid
** Cache entry @ 0x0198c560 for 203.537011527.1.1 [csail.mit.edu]
          370688 bytes  DV        38156  refcnt     0
    callback 0a8ba500   expires 1301604556
    0 opens     0 writers
    volume root
    states (0x1), stat'd
!!!!!!!!!!!!!!!!!!!!!!!!!! this vvvvvvvvvvvvvvvvvvvvvvv is the output file
** Cache entry @ 0x0194ea30 for 203.537011527.2.2096586 [csail.mit.edu]
      1504706560 bytes  DV            0  refcnt     1
    callback 0a8ba500   expires 1301604555
    1 opens     1 writers
    normal file
    states (0x21), stat'd
!!!!!!!!!!!!!!!!!!!!!!!!!!
** Cache entry @ 0x019dd710 for 203.537011527.3.1184272 [csail.mit.edu]
            2048 bytes  DV           12  refcnt     0
    callback 0a8ba500   expires 1301604556
    0 opens     0 writers
    normal file
    states (0x1), stat'd
** Cache entry @ 0x019793f0 for 203.537011527.5.1184273 [csail.mit.edu]
            2048 bytes  DV           12  refcnt     0
    callback 0a8ba500   expires 1301604556
    0 opens     0 writers
    normal file
    states (0x1), stat'd
** Cache entry @ 0x01960400 for 0.1.16778028.1 [dynroot]
              24 bytes  DV            1  refcnt     0
    callback 00000000   expires 0
    0 opens     0 writers
    mount point
    states (0xd), stat'd, read-only, mt pt valid

-GAWollman