[OpenAFS] A few Windows clients hitting the VLDB
Dan Van Der Ster
daniel.vanderster@cern.ch
Thu, 29 Nov 2012 16:03:19 +0000
Dear OpenAFS-Info,
Recently we noticed lots and lots of traffic coming to our vlservers and ha=
ve found it to be coming from a few Windows clients. Some example traffic i=
s shown in the P.S. -- it goes on and on without stopping. We've observed i=
t coming from Windows client versions 1.7.15, 1.7.16, and 1.7.20.=20
Sitting with one of the users, we found that the traffic is generated whene=
ver Explorer is open and browsing an AFS folder; when the Explorer window i=
s closed, the traffic stops. The generated traffic correlates to high CPU l=
oad in afsd_service.exe (see https://dl.dropbox.com/u/58475/image007.png). =
And using procmon from sysinternals, we found that explorer.exe spins on _.=
_AFS_IOCTL_._ (see https://dl.dropbox.com/u/58475/image004.png).
Any idea what's going on?
Best Regards,=20
Dan van der Ster, CERN IT-DSS
on behalf of the CERN AFS Admins
P.S. Example tcpdumps...
tcpdump -i eth0 dst port 7003 and host pcbe13987.cern.ch
16:36:31.006298 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#896720001 (60)
16:36:31.006643 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.006648 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1110169244 (100)
16:36:31.006693 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1695798359 (60)
16:36:31.006992 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.006997 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.007042 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1415608494 (100)
16:36:31.007046 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-367297746 (100)
16:36:31.007050 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.007393 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.007398 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-537643410 (100)
16:36:31.007401 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#651702350 (60)
16:36:31.007743 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.007747 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1635868663 (60)
16:36:31.007791 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.007891 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.008439 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.008491 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#73062445 (100)
16:36:31.008496 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.008500 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1063333442 (100)
16:36:31.008840 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1511646841 (60)
16:36:31.009138 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1506466357 (60)
16:36:31.009488 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.009493 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.009838 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.009843 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.009887 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#32481037 (100)
16:36:31.009892 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-502940616 (100)
16:36:31.010137 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.010537 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.010936 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#2063817775 (60)
16:36:31.011285 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-942467498 (60)
16:36:31.011634 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.011639 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-533154711 (100)
16:36:31.011984 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#519056367 (60)
16:36:31.011989 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.011993 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.012034 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1823299792 (100)
16:36:31.012334 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1187342380 (60)
16:36:31.012683 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.012688 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.012692 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#89585461 (100)
16:36:31.013033 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.013038 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.013082 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1973255886 (100)
16:36:31.013381 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.014480 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1356377853 (60)
16:36:31.014833 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1193223115 (60)
16:36:31.014838 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#26260738 (60)
16:36:31.015180 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.015186 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#970680065 (100)
16:36:31.015528 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.015533 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-1037112767 (100)
16:36:31.015880 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.015884 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.015928 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#969090833 (100)
16:36:31.015977 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.016377 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#1737739362 (60)
16:36:31.017552 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.017602 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.017606 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#971924910 (100)
16:36:31.018001 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx ack first 2 serial 0 reason delay (65)
16:36:31.018201 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#-23838290 (60)
16:36:31.018206 IP pcbe13987.cern.ch.afs3-callback > afsdb1.cern.ch.afs3-vl=
server: rx data vldb call op#814523112 (60)
tcpdump -i eth0 dst port 7003 and host pcithmh05-v1
16:44:04.365776 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#2119374991 (60)
16:44:04.366424 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-652751162 (60)
16:44:04.366874 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.366882 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#602329910 (100)
16:44:04.367822 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.367832 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1100025215 (100)
16:44:04.368271 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.369370 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.374261 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-534588431 (60)
16:44:04.375161 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.375169 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#1327748128 (100)
16:44:04.376158 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1325783088 (60)
16:44:04.376166 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.377258 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.377614 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#1050279245 (100)
16:44:04.377620 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#46775121 (60)
16:44:04.378605 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.378612 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.378615 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#1373955964 (100)
16:44:04.379453 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.384895 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#574482788 (60)
16:44:04.386242 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.386250 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#1288924644 (100)
16:44:04.386792 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1954368271 (60)
16:44:04.386800 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-826939 (60)
16:44:04.387390 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.387989 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.387997 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#749270247 (100)
16:44:04.388001 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.388005 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-2075996140 (100)
16:44:04.389537 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.389791 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.395028 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#2089827799 (60)
16:44:04.396327 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.396335 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#1486991406 (100)
16:44:04.397025 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1361796420 (60)
16:44:04.397032 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#590173735 (60)
16:44:04.397526 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.398173 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.398188 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-559108108 (100)
16:44:04.398191 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.398195 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#810843346 (100)
16:44:04.399221 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.399228 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.405312 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#907657597 (60)
16:44:04.406464 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.406471 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-77135190 (100)
16:44:04.406475 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1411314370 (60)
16:44:04.407109 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-623122759 (60)
16:44:04.407809 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.408219 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.408226 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#-1533427247 (100)
16:44:04.408230 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.408234 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#949525004 (100)
16:44:04.409756 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.409763 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx ack first 2 serial 0 reason delay (65)
16:44:04.415849 IP pcithmh05-v1.cern.ch.afs3-callback > afsdb1.cern.ch.afs3=
-vlserver: rx data vldb call op#735232449 (60)