[OpenAFS] Windows client spraying file server.

Anders Magnusson ragge@ltu.se
Mon, 05 Oct 2009 15:17:40 +0200


We just noticed a quite disturbing event on some windows clients; they 
are sending packets continuously to
a fileserver, causing the fileserver process to take 100% CPU.  And more 
annoying, noone is
logged in to the machines when they do so.  afsd_service works, but 
cannot be restarted and have to be
killed hard.  Despite this, afs works when logging in to the machine but 
it continue to spray packets.

Fileserver runs 1.4.11, client 1.5.62.  I didn't notice anything in the 
changelog that says that this bug
is fixed in a later version.

A quick fs trace -on + fs trace -dump gives entries like the below over 
and over again.  Any hints?

-- Ragge


time 0.866130, tid 3756 rx_Write succeeded bp 0x05365C14, 4096
time 0.866260, tid 3756 rx_Write succeeded bp 0x05365CA4, 4096
time 0.884850, tid 3756 rx_Write failed bp 0x05365D34, 0 != 4096
time 0.884870, tid 3756 cm_Analyze connp 0x293BC060, code 0xffffffff
time 0.884870, tid 3756 cm_Analyze: Rx Call Dead addr[130.240.42.225] 
forcedNew[no]
time 0.884870, tid 3756 CALL StoreData FAILURE scp 0x03D89798, code 
0x66543202
time 0.884930, tid 3756 cm_ConnByServer returning conn 0x293BC060
time 0.884960, tid 3756 CALL StartRXAFS_StoreData64 scp 0x03D89798, 
offset 0x0:00025000, length 0x15000
time 0.885400, tid 3756 rx_Write succeeded bp 0x05365284, 4096
time 0.885470, tid 3756 rx_Write succeeded bp 0x05365314, 4096
time 0.885530, tid 3756 rx_Write succeeded bp 0x053653A4, 4096
time 0.885570, tid 3756 rx_Write succeeded bp 0x05365434, 4096
time 0.885610, tid 3756 rx_Write succeeded bp 0x053654C4, 4096
time 0.885650, tid 3756 rx_Write succeeded bp 0x05365554, 4096
time 0.885700, tid 3756 rx_Write succeeded bp 0x053655E4, 4096
time 0.885740, tid 3756 rx_Write succeeded bp 0x05365674, 4096
time 0.885780, tid 3756 rx_Write succeeded bp 0x05365704, 4096
time 0.886720, tid 3856 SRXAFSCB_TellMeAboutYourself from host 
0x82f02ae1 port 7000
time 0.888370, tid 3756 rx_Write succeeded bp 0x05365794, 4096
time 0.888430, tid 3756 rx_Write succeeded bp 0x05365824, 4096
time 0.888490, tid 3756 rx_Write succeeded bp 0x053658B4, 4096
time 0.888570, tid 3756 rx_Write succeeded bp 0x05365944, 4096
time 0.888630, tid 3756 rx_Write succeeded bp 0x053659D4, 4096
time 0.888690, tid 3756 rx_Write succeeded bp 0x05365A64, 4096
time 0.888790, tid 3756 rx_Write succeeded bp 0x05365AF4, 4096
time 0.888850, tid 3756 rx_Write succeeded bp 0x05365B84, 4096
time 0.888910, tid 3756 rx_Write succeeded bp 0x05365C14, 4096
time 0.889000, tid 3756 rx_Write succeeded bp 0x05365CA4, 4096
time 0.919260, tid 3756 rx_Write failed bp 0x05365D34, 0 != 4096
time 0.919270, tid 3756 cm_Analyze connp 0x293BC060, code 0xffffffff
time 0.919270, tid 3756 cm_Analyze: Rx Call Dead addr[130.240.42.225] 
forcedNew[no]
time 0.919270, tid 3756 CALL StoreData FAILURE scp 0x03D89798, code 
0x66543202
time 0.919310, tid 3756 cm_ConnByServer returning conn 0x293BC060
time 0.919340, tid 3756 CALL StartRXAFS_StoreData64 scp 0x03D89798, 
offset 0x0:00025000, length 0x15000
time 0.919780, tid 3756 rx_Write succeeded bp 0x05365284, 4096
time 0.919850, tid 3756 rx_Write succeeded bp 0x05365314, 4096
time 0.919910, tid 3756 rx_Write succeeded bp 0x053653A4, 4096
time 0.919950, tid 3756 rx_Write succeeded bp 0x05365434, 4096
time 0.919990, tid 3756 rx_Write succeeded bp 0x053654C4, 4096
time 0.920030, tid 3756 rx_Write succeeded bp 0x05365554, 4096
time 0.920080, tid 3756 rx_Write succeeded bp 0x053655E4, 4096
time 0.920120, tid 3756 rx_Write succeeded bp 0x05365674, 4096