[OpenAFS] 5 seconds to vos release empty volume
Ken Elkabany
Ken@Elkabany.com
Wed, 18 Apr 2012 15:31:28 -0700
--0016e6de006a15871d04bdfb9fb4
Content-Type: text/plain; charset=ISO-8859-1
Hello,
We've noticed that when doing a vos release on a volume with two read-only
sites (one cheap one on the same server/partition as the RW, and one on a
separate server), the release consistently takes 5 seconds. If we only have
one read-only site (no cheap replica, just an RO on a separate server), the
vos release takes 2.5 seconds. Both operations are taking longer than we
thought they would, but we're definitely confused why adding an RO to the
RW server would double the release time (or is it 2.5s per site). Both
servers are virtually empty, and have just been setup with AFS 1.6.1pre1
(earlier recommendation from this mailing list). I've included the
respective TCP Dumps. Is there anything else I should provide?
TCP Dump of 2 RO Case (5 seconds):
Server1 has RW, and RO. Server2 has RO.
22:20:56.753732 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-name-n "user" (40)
22:20:56.755639 IP SERVER2.afs3-vlserver > SERVER1.43632: rx challenge (44)
22:20:56.755719 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx response (421)
22:20:56.757776 IP SERVER2.afs3-vlserver > SERVER1.43632: rx data vldb
reply get-entry-by-name-n "user" numservers 3 servers SERVER1 SERVER2
SERVER1 partitions a a a rwvol 536870918 rovol 536870919 backup 536870920
(504)
22:20:56.757851 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:20:56.757889 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-id-n volid 536870918 (40)
22:20:56.759712 IP SERVER2.afs3-vlserver > SERVER1.43632: rx data vldb
reply get-entry-by-id-n "user" numservers 3 servers SERVER1 SERVER2 SERVER1
partitions a a a rwvol 536870918 rovol 536870919 backup 536870920 (504)
22:20:56.759770 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:20:56.759806 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call setlock volid 536870918 type read-write (44)
22:20:56.761656 IP SERVER2.afs3-vlserver > SERVER1.43632: rx abort vldb
reply setlock errcode 5377 (32)
22:20:56.762110 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.188 (40)
22:20:56.763825 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:20:56.763915 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:20:56.763961 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.188 file 0 pos 1 length 1 (56)
22:20:56.765681 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:20:56.765738 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:20:56.765818 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:20:56.767535 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:20:56.767590 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:20:56.778381 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.188 (40)
22:20:56.789383 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:20:56.789442 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:20:56.789466 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.188 (40)
22:20:56.791175 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:20:56.791229 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:20:56.791324 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-id-n volid 536870918 type read-write (40)
22:20:56.793150 IP SERVER2.afs3-vlserver > SERVER1.43632: rx data vldb
reply get-entry-by-id-n "user" numservers 3 servers SERVER1 SERVER2 SERVER1
partitions a a a rwvol 536870918 rovol 536870919 backup 536870920 (504)
22:20:56.793215 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:21:01.799406 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call replace-entry-n volid 536870918 type read-write "user" (520)
22:21:01.801527 IP SERVER2.afs3-vlserver > SERVER1.43632: rx abort vldb
reply replace-entry-n errcode 5377 (32)
22:21:01.801908 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.190 (40)
22:21:01.803713 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:01.803794 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.803823 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.190 file 0 pos 1 length 1 (56)
22:21:01.805598 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:01.805660 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.805727 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:01.807463 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:01.807521 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.814270 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.190 (40)
22:21:01.822595 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:01.822669 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.822696 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.190 (40)
22:21:01.824406 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:01.824461 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.825220 IP SERVER1.43632 > SERVER2.afs3-volser: rx data vol call
trans-create vol 536870919 partition 0 flags 1 (44)
22:21:01.826992 IP SERVER2.afs3-volser > SERVER1.43632: rx challenge (44)
22:21:01.827053 IP SERVER1.43632 > SERVER2.afs3-volser: rx response (421)
22:21:01.829124 IP SERVER2.afs3-volser > SERVER1.43632: rx data vol reply
trans-create trans 15 (32)
22:21:01.829181 IP SERVER1.43632 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:01.829208 IP SERVER1.43632 > SERVER2.afs3-volser: rx data vol call
get-status tid (36)
22:21:01.830913 IP SERVER2.afs3-volser > SERVER1.43632: rx data vol reply
get-status volid 536870919 nextuniq 2 type 1 parentid 536870918 clone 0
backup 0 restore 0 maxquota 5000 minquota 0 owner 0 create 2012/04/18
22:20:46 access 2012/04/18 21:39:29 update 2012/04/17 06:45:12 expire
1970/01/01 00:00:00 backup 1970/01/01 00:00:00 copy 2012/04/18 22:08:26 (92)
22:21:01.830969 IP SERVER1.43632 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:01.831446 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx data vol
call restore totrans 15 flags 1 (1444)
22:21:01.833235 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx challenge
(44)
22:21:01.833249 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx ack first
1 serial 1 reason ack requested acked 1 (66)
22:21:01.833283 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx response
(116)
22:21:01.833310 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx data
(1274)
22:21:01.837345 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx data (28)
22:21:01.837419 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx ack first
2 serial 0 reason delay (65)
22:21:01.837539 IP SERVER1.43632 > SERVER2.afs3-volser: rx data vol call
set-id-types tid 15 name "user.readonly" type 1 pid 536870918 clone 0
backup 0 (72)
22:21:01.839318 IP SERVER2.afs3-volser > SERVER1.43632: rx data (28)
22:21:01.839382 IP SERVER1.43632 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:01.839400 IP SERVER1.43632 > SERVER2.afs3-volser: rx data vol call
set-flags trans 15 flags 0 (40)
22:21:01.841163 IP SERVER2.afs3-volser > SERVER1.43632: rx data (28)
22:21:01.841214 IP SERVER1.43632 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:01.841235 IP SERVER1.43632 > SERVER2.afs3-volser: rx data vol call
end-trans trans 15 (36)
22:21:01.843054 IP SERVER2.afs3-volser > SERVER1.43632: rx data vol reply
end-trans 0 (32)
22:21:01.843104 IP SERVER1.43632 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:01.843130 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call replace-entry-n volid 536870918 type read-write "user" (520)
22:21:01.844980 IP SERVER2.afs3-vlserver > SERVER1.43632: rx abort vldb
reply replace-entry-n errcode 5377 (32)
22:21:01.845207 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.192 (40)
22:21:01.846930 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:01.846999 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.847025 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.192 file 0 pos 1 length 1 (56)
22:21:01.848733 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:01.848789 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.848843 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:01.850563 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:01.850615 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.857950 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.192 (40)
22:21:01.867200 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:01.867262 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.867285 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.192 (40)
22:21:01.869006 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:01.869057 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.869524 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call replace-entry-n volid 536870918 type read-write "user" (520)
22:21:01.871371 IP SERVER2.afs3-vlserver > SERVER1.43632: rx abort vldb
reply replace-entry-n errcode 5377 (32)
22:21:01.871575 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.194 (40)
22:21:01.873254 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:01.873325 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.873350 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.194 file 0 pos 1 length 1 (56)
22:21:01.875050 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:01.875102 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.875154 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:01.876872 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:01.876922 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.885469 IP SERVER1.afs3-prserver > SERVER2.afs3-prserver: rx data
pt ubik call vote-beacon syncsite yes votestart 2012/04/18 22:21:01
dbversion 2.0 tid 0.1 (56)
22:21:01.885910 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.194 (40)
22:21:01.887198 IP SERVER2.afs3-prserver > SERVER1.afs3-prserver: rx abort
pt ubik reply vote-beacon vote yes until 2012/04/18 22:21:00 (32)
22:21:01.891081 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call vote-beacon syncsite yes votestart 2012/04/18 22:21:01
dbversion 1334787313.59 tid 1334787313.194 (56)
22:21:01.903173 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:01.903225 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.903246 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.194 (40)
22:21:01.903288 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx abort
vldb ubik reply vote-beacon vote yes until 2012/04/18 22:21:01 (32)
22:21:01.904977 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:01.905026 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.905148 IP SERVER1.43632 > SERVER2.afs3-vlserver: rx data vldb
call releaselock volid 536870918 type read-write (44)
22:21:01.906962 IP SERVER2.afs3-vlserver > SERVER1.43632: rx abort vldb
reply releaselock errcode 5377 (32)
22:21:01.907162 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.196 (40)
22:21:01.908862 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:01.908933 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.908957 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.196 file 0 pos 1 length 1 (56)
22:21:01.910653 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:01.910703 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.910754 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:01.912441 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:01.912493 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.925485 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.196 (40)
22:21:01.935032 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:01.935087 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:01.935105 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.196 (40)
22:21:01.936856 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:01.936905 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
TCP Dump of 1 RO Case (2.5 seconds):
Server1 has RW. Server2 has RO.
22:21:46.888866 IP SERVER1.afs3-prserver > SERVER2.afs3-prserver: rx data
pt ubik call vote-beacon syncsite yes votestart 2012/04/18 22:21:46
dbversion 2.0 tid 0.1 (56)
22:21:46.890748 IP SERVER2.afs3-prserver > SERVER1.afs3-prserver: rx abort
pt ubik reply vote-beacon vote yes until 2012/04/18 22:21:44 (32)
22:21:46.908429 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call vote-beacon syncsite yes votestart 2012/04/18 22:21:46
dbversion 1334787313.62 tid 1334787313.201 (56)
22:21:46.910175 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx abort
vldb ubik reply vote-beacon vote yes until 2012/04/18 22:21:43 (32)
22:21:48.996192 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-name-n "user" (40)
22:21:48.998005 IP SERVER2.afs3-vlserver > SERVER1.33472: rx challenge (44)
22:21:48.998091 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx response (421)
22:21:48.999952 IP SERVER2.afs3-vlserver > SERVER1.33472: rx data vldb
reply get-entry-by-name-n "user" numservers 2 servers SERVER1 SERVER2
partitions a a rwvol 536870918 rovol 536870919 backup 536870920 (504)
22:21:49.000025 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:21:49.000061 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-id-n volid 536870918 (40)
22:21:49.001767 IP SERVER2.afs3-vlserver > SERVER1.33472: rx data vldb
reply get-entry-by-id-n "user" numservers 2 servers SERVER1 SERVER2
partitions a a rwvol 536870918 rovol 536870919 backup 536870920 (504)
22:21:49.001821 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:21:49.001853 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call setlock volid 536870918 type read-write (44)
22:21:49.003562 IP SERVER2.afs3-vlserver > SERVER1.33472: rx abort vldb
reply setlock errcode 5377 (32)
22:21:49.004014 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.202 (40)
22:21:49.005764 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:49.005837 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.005866 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.202 file 0 pos 1 length 1 (56)
22:21:49.007550 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:49.007598 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.007660 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:49.009366 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:49.009415 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.224811 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.202 (40)
22:21:49.235117 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:49.235169 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.235187 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.202 (40)
22:21:49.236889 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:49.236941 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.237055 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call get-entry-by-id-n volid 536870918 type read-write (40)
22:21:49.238884 IP SERVER2.afs3-vlserver > SERVER1.33472: rx data vldb
reply get-entry-by-id-n "user" numservers 2 servers SERVER1 SERVER2
partitions a a rwvol 536870918 rovol 536870919 backup 536870920 (504)
22:21:49.238954 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx ack first 2
serial 0 reason delay (65)
22:21:49.259181 IP SERVER1.33472 > SERVER2.afs3-volser: rx data vol call
trans-create vol 536870919 partition 0 flags 1 (44)
22:21:49.261060 IP SERVER2.afs3-volser > SERVER1.33472: rx challenge (44)
22:21:49.261123 IP SERVER1.33472 > SERVER2.afs3-volser: rx response (421)
22:21:49.263254 IP SERVER2.afs3-volser > SERVER1.33472: rx data vol reply
trans-create trans 16 (32)
22:21:49.263308 IP SERVER1.33472 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:49.263327 IP SERVER1.33472 > SERVER2.afs3-volser: rx data vol call
get-status tid (36)
22:21:49.265117 IP SERVER2.afs3-volser > SERVER1.33472: rx data vol reply
get-status volid 536870919 nextuniq 2 type 1 parentid 536870918 clone 0
backup 0 restore 0 maxquota 5000 minquota 0 owner 0 create 2012/04/18
22:20:56 access 2012/04/18 21:39:29 update 2012/04/17 06:45:12 expire
1970/01/01 00:00:00 backup 1970/01/01 00:00:00 copy 2012/04/18 22:08:26 (92)
22:21:49.265168 IP SERVER1.33472 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:49.265613 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx data vol
call restore totrans 16 flags 1 (1444)
22:21:49.267374 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx challenge
(44)
22:21:49.267397 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx ack first
1 serial 1 reason ack requested acked 1 (66)
22:21:49.267420 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx response
(116)
22:21:49.267439 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx data
(1286)
22:21:49.271580 IP SERVER2.afs3-volser > SERVER1.afs3-volser: rx data (28)
22:21:49.271662 IP SERVER1.afs3-volser > SERVER2.afs3-volser: rx ack first
2 serial 0 reason delay (65)
22:21:49.271776 IP SERVER1.33472 > SERVER2.afs3-volser: rx data vol call
set-id-types tid 16 name "user.readonly" type 1 pid 536870918 clone 0
backup 0 (72)
22:21:49.273608 IP SERVER2.afs3-volser > SERVER1.33472: rx data (28)
22:21:49.273672 IP SERVER1.33472 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:49.273691 IP SERVER1.33472 > SERVER2.afs3-volser: rx data vol call
set-flags trans 16 flags 0 (40)
22:21:49.275498 IP SERVER2.afs3-volser > SERVER1.33472: rx data (28)
22:21:49.275546 IP SERVER1.33472 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:49.275562 IP SERVER1.33472 > SERVER2.afs3-volser: rx data vol call
end-trans trans 16 (36)
22:21:49.277415 IP SERVER2.afs3-volser > SERVER1.33472: rx data vol reply
end-trans 0 (32)
22:21:49.277463 IP SERVER1.33472 > SERVER2.afs3-volser: rx ack first 2
serial 0 reason delay (65)
22:21:49.277492 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call replace-entry-n volid 536870918 type read-write "user" (520)
22:21:49.279231 IP SERVER2.afs3-vlserver > SERVER1.33472: rx abort vldb
reply replace-entry-n errcode 5377 (32)
22:21:49.279432 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.204 (40)
22:21:49.281140 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:49.281210 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.281234 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.204 file 0 pos 1 length 1 (56)
22:21:49.282927 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:49.282976 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.283025 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:49.284729 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:49.284769 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.296536 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.204 (40)
22:21:49.306104 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:49.306155 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.306171 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.204 (40)
22:21:49.307882 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:49.307933 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.317312 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call replace-entry-n volid 536870918 type read-write "user" (520)
22:21:49.319057 IP SERVER2.afs3-vlserver > SERVER1.33472: rx abort vldb
reply replace-entry-n errcode 5377 (32)
22:21:49.319270 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.206 (40)
22:21:49.321029 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:49.321097 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.321123 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.206 file 0 pos 1 length 1 (56)
22:21:49.322826 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:49.322872 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.322919 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:49.324628 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:49.324678 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.334648 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.206 (40)
22:21:49.342338 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:49.342385 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.342402 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.206 (40)
22:21:49.344119 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:49.344169 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.344297 IP SERVER1.33472 > SERVER2.afs3-vlserver: rx data vldb
call releaselock volid 536870918 type read-write (44)
22:21:49.346032 IP SERVER2.afs3-vlserver > SERVER1.33472: rx abort vldb
reply releaselock errcode 5377 (32)
22:21:49.346231 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-begin tid 1334787313.208 (40)
22:21:49.347934 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-begin (28)
22:21:49.347997 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.348020 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-lock tid 1334787313.208 file 0 pos 1 length 1 (56)
22:21:49.349758 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-lock (28)
22:21:49.349807 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.349851 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-writev (208)
22:21:49.351539 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-writev (28)
22:21:49.351590 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.358321 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-commit tid 1334787313.208 (40)
22:21:49.366314 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-commit (28)
22:21:49.366374 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
22:21:49.366392 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx data
vldb ubik call disk-releaselocks tid 1334787313.208 (40)
22:21:49.368088 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: rx data
vldb ubik reply disk-releaselocks (28)
22:21:49.368140 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: rx ack
first 2 serial 0 reason delay (65)
--0016e6de006a15871d04bdfb9fb4
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable
<div><div>Hello,</div><div><br></div><div>We've noticed that when doing=
a vos release on a volume with two read-only sites (one cheap one on the s=
ame server/partition as the RW, and one on a separate server), the release =
consistently takes 5 seconds. If we only have one read-only site (no cheap =
replica, just an RO on a separate server), the vos release takes 2.5 second=
s. Both operations are taking longer than we thought they would, but we'=
;re definitely confused why adding an RO to the RW server would double the =
release time (or is it 2.5s per site). Both servers are virtually empty, an=
d have just been setup with AFS 1.6.1pre1 (earlier recommendation from this=
mailing list). I've included the respective TCP Dumps. Is there anythi=
ng else I should provide?</div>
<div><br></div><div>TCP Dump of 2 RO Case (5 seconds):</div><div>Server1 ha=
s RW, and RO. Server2 has RO.</div><div><br></div><div>22:20:56.753732 IP S=
ERVER1.43632 > SERVER2.afs3-vlserver: =A0rx data vldb call get-entry-by-=
name-n "user" (40)</div>
<div>22:20:56.755639 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx cha=
llenge (44)</div><div>22:20:56.755719 IP SERVER1.43632 > SERVER2.afs3-vl=
server: =A0rx response (421)</div><div>22:20:56.757776 IP SERVER2.afs3-vlse=
rver > SERVER1.43632: =A0rx data vldb reply get-entry-by-name-n "us=
er" numservers 3 servers SERVER1 SERVER2 SERVER1 partitions a a a rwvo=
l 536870918 rovol 536870919 backup 536870920 (504)</div>
<div>22:20:56.757851 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:20:56.757889 IP SERVER1.43=
632 > SERVER2.afs3-vlserver: =A0rx data vldb call get-entry-by-id-n voli=
d 536870918 (40)</div>
<div>22:20:56.759712 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx dat=
a vldb reply get-entry-by-id-n "user" numservers 3 servers SERVER=
1 SERVER2 SERVER1 partitions a a a rwvol 536870918 rovol 536870919 backup 5=
36870920 (504)</div>
<div>22:20:56.759770 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:20:56.759806 IP SERVER1.43=
632 > SERVER2.afs3-vlserver: =A0rx data vldb call setlock volid 53687091=
8 type read-write (44)</div>
<div>22:20:56.761656 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx abo=
rt vldb reply setlock errcode 5377 (32)</div><div>22:20:56.762110 IP SERVER=
1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call disk-=
begin tid 1334787313.188 (40)</div>
<div>22:20:56.763825 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-begin (28)</div><div>22:20:56.763915 IP SER=
VER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 r=
eason delay (65)</div>
<div>22:20:56.763961 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-lock tid 1334787313.188 file 0 pos 1 length =
1 (56)</div><div>22:20:56.765681 IP SERVER2.afs3-vlserver > SERVER1.afs3=
-vlserver: =A0rx data vldb ubik reply disk-lock (28)</div>
<div>22:20:56.765738 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:20:56.765818 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-writev (208)</div>
<div>22:20:56.767535 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-writev (28)</div><div>22:20:56.767590 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:20:56.778381 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-commit tid 1334787313.188 (40)</div><div>22:=
20:56.789383 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx dat=
a vldb ubik reply disk-commit (28)</div>
<div>22:20:56.789442 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:20:56.789466 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-releaselocks tid 1334787313.188 (40)</div>
<div>22:20:56.791175 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-releaselocks (28)</div><div>22:20:56.791229=
IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 ser=
ial 0 reason delay (65)</div>
<div>22:20:56.791324 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx dat=
a vldb call get-entry-by-id-n volid 536870918 type read-write (40)</div><di=
v>22:20:56.793150 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx data v=
ldb reply get-entry-by-id-n "user" numservers 3 servers SERVER1 S=
ERVER2 SERVER1 partitions a a a rwvol 536870918 rovol 536870919 backup 5368=
70920 (504)</div>
<div>22:20:56.793215 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:21:01.799406 IP SERVER1.43=
632 > SERVER2.afs3-vlserver: =A0rx data vldb call replace-entry-n volid =
536870918 type read-write "user" (520)</div>
<div>22:21:01.801527 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx abo=
rt vldb reply replace-entry-n errcode 5377 (32)</div><div>22:21:01.801908 I=
P SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik ca=
ll disk-begin tid 1334787313.190 (40)</div>
<div>22:21:01.803713 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-begin (28)</div><div>22:21:01.803794 IP SER=
VER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 r=
eason delay (65)</div>
<div>22:21:01.803823 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-lock tid 1334787313.190 file 0 pos 1 length =
1 (56)</div><div>22:21:01.805598 IP SERVER2.afs3-vlserver > SERVER1.afs3=
-vlserver: =A0rx data vldb ubik reply disk-lock (28)</div>
<div>22:21:01.805660 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.805727 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-writev (208)</div>
<div>22:21:01.807463 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-writev (28)</div><div>22:21:01.807521 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:01.814270 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-commit tid 1334787313.190 (40)</div><div>22:=
21:01.822595 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx dat=
a vldb ubik reply disk-commit (28)</div>
<div>22:21:01.822669 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.822696 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-releaselocks tid 1334787313.190 (40)</div>
<div>22:21:01.824406 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-releaselocks (28)</div><div>22:21:01.824461=
IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 ser=
ial 0 reason delay (65)</div>
<div>22:21:01.825220 IP SERVER1.43632 > SERVER2.afs3-volser: =A0rx data =
vol call trans-create vol 536870919 partition 0 flags 1 (44)</div><div>22:2=
1:01.826992 IP SERVER2.afs3-volser > SERVER1.43632: =A0rx challenge (44)=
</div>
<div>22:21:01.827053 IP SERVER1.43632 > SERVER2.afs3-volser: =A0rx respo=
nse (421)</div><div>22:21:01.829124 IP SERVER2.afs3-volser > SERVER1.436=
32: =A0rx data vol reply trans-create trans 15 (32)</div><div>22:21:01.8291=
81 IP SERVER1.43632 > SERVER2.afs3-volser: =A0rx ack first 2 serial 0 re=
ason delay (65)</div>
<div>22:21:01.829208 IP SERVER1.43632 > SERVER2.afs3-volser: =A0rx data =
vol call get-status tid (36)</div><div>22:21:01.830913 IP SERVER2.afs3-vols=
er > SERVER1.43632: =A0rx data vol reply get-status volid 536870919 next=
uniq 2 type 1 parentid 536870918 clone 0 backup 0 restore 0 maxquota 5000 m=
inquota 0 owner 0 create 2012/04/18 22:20:46 access 2012/04/18 21:39:29 upd=
ate 2012/04/17 06:45:12 expire 1970/01/01 00:00:00 backup 1970/01/01 00:00:=
00 copy 2012/04/18 22:08:26 (92)</div>
<div>22:21:01.830969 IP SERVER1.43632 > SERVER2.afs3-volser: =A0rx ack f=
irst 2 serial 0 reason delay (65)</div><div>22:21:01.831446 IP SERVER1.afs3=
-volser > SERVER2.afs3-volser: =A0rx data vol call restore totrans 15 fl=
ags 1 (1444)</div>
<div>22:21:01.833235 IP SERVER2.afs3-volser > SERVER1.afs3-volser: =A0rx=
challenge (44)</div><div>22:21:01.833249 IP SERVER2.afs3-volser > SERVE=
R1.afs3-volser: =A0rx ack first 1 serial 1 reason ack requested acked 1 (66=
)</div>
<div>22:21:01.833283 IP SERVER1.afs3-volser > SERVER2.afs3-volser: =A0rx=
response (116)</div><div>22:21:01.833310 IP SERVER1.afs3-volser > SERVE=
R2.afs3-volser: =A0rx data (1274)</div><div>22:21:01.837345 IP SERVER2.afs3=
-volser > SERVER1.afs3-volser: =A0rx data (28)</div>
<div>22:21:01.837419 IP SERVER1.afs3-volser > SERVER2.afs3-volser: =A0rx=
ack first 2 serial 0 reason delay (65)</div><div>22:21:01.837539 IP SERVER=
1.43632 > SERVER2.afs3-volser: =A0rx data vol call set-id-types tid 15 n=
ame "user.readonly" type 1 pid 536870918 clone 0 backup 0 (72)</d=
iv>
<div>22:21:01.839318 IP SERVER2.afs3-volser > SERVER1.43632: =A0rx data =
(28)</div><div>22:21:01.839382 IP SERVER1.43632 > SERVER2.afs3-volser: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.839400 IP S=
ERVER1.43632 > SERVER2.afs3-volser: =A0rx data vol call set-flags trans =
15 flags 0 (40)</div>
<div>22:21:01.841163 IP SERVER2.afs3-volser > SERVER1.43632: =A0rx data =
(28)</div><div>22:21:01.841214 IP SERVER1.43632 > SERVER2.afs3-volser: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.841235 IP S=
ERVER1.43632 > SERVER2.afs3-volser: =A0rx data vol call end-trans trans =
15 (36)</div>
<div>22:21:01.843054 IP SERVER2.afs3-volser > SERVER1.43632: =A0rx data =
vol reply end-trans 0 (32)</div><div>22:21:01.843104 IP SERVER1.43632 > =
SERVER2.afs3-volser: =A0rx ack first 2 serial 0 reason delay (65)</div><div=
>
22:21:01.843130 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx data vld=
b call replace-entry-n volid 536870918 type read-write "user" (52=
0)</div><div>22:21:01.844980 IP SERVER2.afs3-vlserver > SERVER1.43632: =
=A0rx abort vldb reply replace-entry-n errcode 5377 (32)</div>
<div>22:21:01.845207 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-begin tid 1334787313.192 (40)</div><div>22:2=
1:01.846930 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data=
vldb ubik reply disk-begin (28)</div>
<div>22:21:01.846999 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.847025 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-lock tid 1334787313.192 file 0 pos 1 length 1 (56)</div>
<div>22:21:01.848733 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-lock (28)</div><div>22:21:01.848789 IP SERV=
ER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 re=
ason delay (65)</div>
<div>22:21:01.848843 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-writev (208)</div><div>22:21:01.850563 IP SE=
RVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data vldb ubik reply =
disk-writev (28)</div>
<div>22:21:01.850615 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.857950 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-commit tid 1334787313.192 (40)</div>
<div>22:21:01.867200 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-commit (28)</div><div>22:21:01.867262 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:01.867285 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-releaselocks tid 1334787313.192 (40)</div><d=
iv>22:21:01.869006 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0=
rx data vldb ubik reply disk-releaselocks (28)</div>
<div>22:21:01.869057 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.869524 IP S=
ERVER1.43632 > SERVER2.afs3-vlserver: =A0rx data vldb call replace-entry=
-n volid 536870918 type read-write "user" (520)</div>
<div>22:21:01.871371 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx abo=
rt vldb reply replace-entry-n errcode 5377 (32)</div><div>22:21:01.871575 I=
P SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik ca=
ll disk-begin tid 1334787313.194 (40)</div>
<div>22:21:01.873254 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-begin (28)</div><div>22:21:01.873325 IP SER=
VER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 r=
eason delay (65)</div>
<div>22:21:01.873350 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-lock tid 1334787313.194 file 0 pos 1 length =
1 (56)</div><div>22:21:01.875050 IP SERVER2.afs3-vlserver > SERVER1.afs3=
-vlserver: =A0rx data vldb ubik reply disk-lock (28)</div>
<div>22:21:01.875102 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.875154 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-writev (208)</div>
<div>22:21:01.876872 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-writev (28)</div><div>22:21:01.876922 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:01.885469 IP SERVER1.afs3-prserver > SERVER2.afs3-prserver: =
=A0rx data pt ubik call vote-beacon syncsite yes votestart 2012/04/18 22:21=
:01 dbversion 2.0 tid 0.1 (56)</div><div>22:21:01.885910 IP SERVER1.afs3-vl=
server > SERVER2.afs3-vlserver: =A0rx data vldb ubik call disk-commit ti=
d 1334787313.194 (40)</div>
<div>22:21:01.887198 IP SERVER2.afs3-prserver > SERVER1.afs3-prserver: =
=A0rx abort pt ubik reply vote-beacon vote yes until 2012/04/18 22:21:00 (3=
2)</div><div>22:21:01.891081 IP SERVER1.afs3-vlserver > SERVER2.afs3-vls=
erver: =A0rx data vldb ubik call vote-beacon syncsite yes votestart 2012/04=
/18 22:21:01 dbversion 1334787313.59 tid 1334787313.194 (56)</div>
<div>22:21:01.903173 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-commit (28)</div><div>22:21:01.903225 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:01.903246 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-releaselocks tid 1334787313.194 (40)</div><d=
iv>22:21:01.903288 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0=
rx abort vldb ubik reply vote-beacon vote yes until 2012/04/18 22:21:01 (32=
)</div>
<div>22:21:01.904977 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-releaselocks (28)</div><div>22:21:01.905026=
IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 ser=
ial 0 reason delay (65)</div>
<div>22:21:01.905148 IP SERVER1.43632 > SERVER2.afs3-vlserver: =A0rx dat=
a vldb call releaselock volid 536870918 type read-write (44)</div><div>22:2=
1:01.906962 IP SERVER2.afs3-vlserver > SERVER1.43632: =A0rx abort vldb r=
eply releaselock errcode 5377 (32)</div>
<div>22:21:01.907162 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-begin tid 1334787313.196 (40)</div><div>22:2=
1:01.908862 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data=
vldb ubik reply disk-begin (28)</div>
<div>22:21:01.908933 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.908957 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-lock tid 1334787313.196 file 0 pos 1 length 1 (56)</div>
<div>22:21:01.910653 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-lock (28)</div><div>22:21:01.910703 IP SERV=
ER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 re=
ason delay (65)</div>
<div>22:21:01.910754 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-writev (208)</div><div>22:21:01.912441 IP SE=
RVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data vldb ubik reply =
disk-writev (28)</div>
<div>22:21:01.912493 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:01.925485 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-commit tid 1334787313.196 (40)</div>
<div>22:21:01.935032 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-commit (28)</div><div>22:21:01.935087 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:01.935105 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-releaselocks tid 1334787313.196 (40)</div><d=
iv>22:21:01.936856 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0=
rx data vldb ubik reply disk-releaselocks (28)</div>
<div>22:21:01.936905 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div><br></div><div><br><=
/div><div><br></div><div>TCP Dump of 1 RO Case (2.5 seconds):</div><div>Ser=
ver1 has RW. Server2 has RO.</div>
<div><br></div><div>22:21:46.888866 IP SERVER1.afs3-prserver > SERVER2.a=
fs3-prserver: =A0rx data pt ubik call vote-beacon syncsite yes votestart 20=
12/04/18 22:21:46 dbversion 2.0 tid 0.1 (56)</div><div>22:21:46.890748 IP S=
ERVER2.afs3-prserver > SERVER1.afs3-prserver: =A0rx abort pt ubik reply =
vote-beacon vote yes until 2012/04/18 22:21:44 (32)</div>
<div>22:21:46.908429 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call vote-beacon syncsite yes votestart 2012/04/18 22:=
21:46 dbversion 1334787313.62 tid 1334787313.201 (56)</div><div>22:21:46.91=
0175 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx abort vldb =
ubik reply vote-beacon vote yes until 2012/04/18 22:21:43 (32)</div>
<div>22:21:48.996192 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx dat=
a vldb call get-entry-by-name-n "user" (40)</div><div>22:21:48.99=
8005 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx challenge (44)</div=
>
<div>22:21:48.998091 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx res=
ponse (421)</div><div>22:21:48.999952 IP SERVER2.afs3-vlserver > SERVER1=
.33472: =A0rx data vldb reply get-entry-by-name-n "user" numserve=
rs 2 servers SERVER1 SERVER2 partitions a a rwvol 536870918 rovol 536870919=
backup 536870920 (504)</div>
<div>22:21:49.000025 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:21:49.000061 IP SERVER1.33=
472 > SERVER2.afs3-vlserver: =A0rx data vldb call get-entry-by-id-n voli=
d 536870918 (40)</div>
<div>22:21:49.001767 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx dat=
a vldb reply get-entry-by-id-n "user" numservers 2 servers SERVER=
1 SERVER2 partitions a a rwvol 536870918 rovol 536870919 backup 536870920 (=
504)</div>
<div>22:21:49.001821 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:21:49.001853 IP SERVER1.33=
472 > SERVER2.afs3-vlserver: =A0rx data vldb call setlock volid 53687091=
8 type read-write (44)</div>
<div>22:21:49.003562 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx abo=
rt vldb reply setlock errcode 5377 (32)</div><div>22:21:49.004014 IP SERVER=
1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call disk-=
begin tid 1334787313.202 (40)</div>
<div>22:21:49.005764 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-begin (28)</div><div>22:21:49.005837 IP SER=
VER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 r=
eason delay (65)</div>
<div>22:21:49.005866 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-lock tid 1334787313.202 file 0 pos 1 length =
1 (56)</div><div>22:21:49.007550 IP SERVER2.afs3-vlserver > SERVER1.afs3=
-vlserver: =A0rx data vldb ubik reply disk-lock (28)</div>
<div>22:21:49.007598 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.007660 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-writev (208)</div>
<div>22:21:49.009366 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-writev (28)</div><div>22:21:49.009415 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:49.224811 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-commit tid 1334787313.202 (40)</div><div>22:=
21:49.235117 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx dat=
a vldb ubik reply disk-commit (28)</div>
<div>22:21:49.235169 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.235187 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-releaselocks tid 1334787313.202 (40)</div>
<div>22:21:49.236889 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-releaselocks (28)</div><div>22:21:49.236941=
IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 ser=
ial 0 reason delay (65)</div>
<div>22:21:49.237055 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx dat=
a vldb call get-entry-by-id-n volid 536870918 type read-write (40)</div><di=
v>22:21:49.238884 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx data v=
ldb reply get-entry-by-id-n "user" numservers 2 servers SERVER1 S=
ERVER2 partitions a a rwvol 536870918 rovol 536870919 backup 536870920 (504=
)</div>
<div>22:21:49.238954 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx ack=
first 2 serial 0 reason delay (65)</div><div>22:21:49.259181 IP SERVER1.33=
472 > SERVER2.afs3-volser: =A0rx data vol call trans-create vol 53687091=
9 partition 0 flags 1 (44)</div>
<div>22:21:49.261060 IP SERVER2.afs3-volser > SERVER1.33472: =A0rx chall=
enge (44)</div><div>22:21:49.261123 IP SERVER1.33472 > SERVER2.afs3-vols=
er: =A0rx response (421)</div><div>22:21:49.263254 IP SERVER2.afs3-volser &=
gt; SERVER1.33472: =A0rx data vol reply trans-create trans 16 (32)</div>
<div>22:21:49.263308 IP SERVER1.33472 > SERVER2.afs3-volser: =A0rx ack f=
irst 2 serial 0 reason delay (65)</div><div>22:21:49.263327 IP SERVER1.3347=
2 > SERVER2.afs3-volser: =A0rx data vol call get-status tid (36)</div><d=
iv>
22:21:49.265117 IP SERVER2.afs3-volser > SERVER1.33472: =A0rx data vol r=
eply get-status volid 536870919 nextuniq 2 type 1 parentid 536870918 clone =
0 backup 0 restore 0 maxquota 5000 minquota 0 owner 0 create 2012/04/18 22:=
20:56 access 2012/04/18 21:39:29 update 2012/04/17 06:45:12 expire 1970/01/=
01 00:00:00 backup 1970/01/01 00:00:00 copy 2012/04/18 22:08:26 (92)</div>
<div>22:21:49.265168 IP SERVER1.33472 > SERVER2.afs3-volser: =A0rx ack f=
irst 2 serial 0 reason delay (65)</div><div>22:21:49.265613 IP SERVER1.afs3=
-volser > SERVER2.afs3-volser: =A0rx data vol call restore totrans 16 fl=
ags 1 (1444)</div>
<div>22:21:49.267374 IP SERVER2.afs3-volser > SERVER1.afs3-volser: =A0rx=
challenge (44)</div><div>22:21:49.267397 IP SERVER2.afs3-volser > SERVE=
R1.afs3-volser: =A0rx ack first 1 serial 1 reason ack requested acked 1 (66=
)</div>
<div>22:21:49.267420 IP SERVER1.afs3-volser > SERVER2.afs3-volser: =A0rx=
response (116)</div><div>22:21:49.267439 IP SERVER1.afs3-volser > SERVE=
R2.afs3-volser: =A0rx data (1286)</div><div>22:21:49.271580 IP SERVER2.afs3=
-volser > SERVER1.afs3-volser: =A0rx data (28)</div>
<div>22:21:49.271662 IP SERVER1.afs3-volser > SERVER2.afs3-volser: =A0rx=
ack first 2 serial 0 reason delay (65)</div><div>22:21:49.271776 IP SERVER=
1.33472 > SERVER2.afs3-volser: =A0rx data vol call set-id-types tid 16 n=
ame "user.readonly" type 1 pid 536870918 clone 0 backup 0 (72)</d=
iv>
<div>22:21:49.273608 IP SERVER2.afs3-volser > SERVER1.33472: =A0rx data =
(28)</div><div>22:21:49.273672 IP SERVER1.33472 > SERVER2.afs3-volser: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.273691 IP S=
ERVER1.33472 > SERVER2.afs3-volser: =A0rx data vol call set-flags trans =
16 flags 0 (40)</div>
<div>22:21:49.275498 IP SERVER2.afs3-volser > SERVER1.33472: =A0rx data =
(28)</div><div>22:21:49.275546 IP SERVER1.33472 > SERVER2.afs3-volser: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.275562 IP S=
ERVER1.33472 > SERVER2.afs3-volser: =A0rx data vol call end-trans trans =
16 (36)</div>
<div>22:21:49.277415 IP SERVER2.afs3-volser > SERVER1.33472: =A0rx data =
vol reply end-trans 0 (32)</div><div>22:21:49.277463 IP SERVER1.33472 > =
SERVER2.afs3-volser: =A0rx ack first 2 serial 0 reason delay (65)</div><div=
>
22:21:49.277492 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx data vld=
b call replace-entry-n volid 536870918 type read-write "user" (52=
0)</div><div>22:21:49.279231 IP SERVER2.afs3-vlserver > SERVER1.33472: =
=A0rx abort vldb reply replace-entry-n errcode 5377 (32)</div>
<div>22:21:49.279432 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-begin tid 1334787313.204 (40)</div><div>22:2=
1:49.281140 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data=
vldb ubik reply disk-begin (28)</div>
<div>22:21:49.281210 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.281234 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-lock tid 1334787313.204 file 0 pos 1 length 1 (56)</div>
<div>22:21:49.282927 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-lock (28)</div><div>22:21:49.282976 IP SERV=
ER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 re=
ason delay (65)</div>
<div>22:21:49.283025 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-writev (208)</div><div>22:21:49.284729 IP SE=
RVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data vldb ubik reply =
disk-writev (28)</div>
<div>22:21:49.284769 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.296536 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-commit tid 1334787313.204 (40)</div>
<div>22:21:49.306104 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-commit (28)</div><div>22:21:49.306155 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:49.306171 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-releaselocks tid 1334787313.204 (40)</div><d=
iv>22:21:49.307882 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0=
rx data vldb ubik reply disk-releaselocks (28)</div>
<div>22:21:49.307933 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.317312 IP S=
ERVER1.33472 > SERVER2.afs3-vlserver: =A0rx data vldb call replace-entry=
-n volid 536870918 type read-write "user" (520)</div>
<div>22:21:49.319057 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx abo=
rt vldb reply replace-entry-n errcode 5377 (32)</div><div>22:21:49.319270 I=
P SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik ca=
ll disk-begin tid 1334787313.206 (40)</div>
<div>22:21:49.321029 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-begin (28)</div><div>22:21:49.321097 IP SER=
VER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 r=
eason delay (65)</div>
<div>22:21:49.321123 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-lock tid 1334787313.206 file 0 pos 1 length =
1 (56)</div><div>22:21:49.322826 IP SERVER2.afs3-vlserver > SERVER1.afs3=
-vlserver: =A0rx data vldb ubik reply disk-lock (28)</div>
<div>22:21:49.322872 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.322919 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-writev (208)</div>
<div>22:21:49.324628 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-writev (28)</div><div>22:21:49.324678 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:49.334648 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-commit tid 1334787313.206 (40)</div><div>22:=
21:49.342338 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx dat=
a vldb ubik reply disk-commit (28)</div>
<div>22:21:49.342385 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.342402 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-releaselocks tid 1334787313.206 (40)</div>
<div>22:21:49.344119 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-releaselocks (28)</div><div>22:21:49.344169=
IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 ser=
ial 0 reason delay (65)</div>
<div>22:21:49.344297 IP SERVER1.33472 > SERVER2.afs3-vlserver: =A0rx dat=
a vldb call releaselock volid 536870918 type read-write (44)</div><div>22:2=
1:49.346032 IP SERVER2.afs3-vlserver > SERVER1.33472: =A0rx abort vldb r=
eply releaselock errcode 5377 (32)</div>
<div>22:21:49.346231 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-begin tid 1334787313.208 (40)</div><div>22:2=
1:49.347934 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data=
vldb ubik reply disk-begin (28)</div>
<div>22:21:49.347997 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.348020 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-lock tid 1334787313.208 file 0 pos 1 length 1 (56)</div>
<div>22:21:49.349758 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-lock (28)</div><div>22:21:49.349807 IP SERV=
ER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 re=
ason delay (65)</div>
<div>22:21:49.349851 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-writev (208)</div><div>22:21:49.351539 IP SE=
RVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0rx data vldb ubik reply =
disk-writev (28)</div>
<div>22:21:49.351590 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div><div>22:21:49.358321 IP S=
ERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx data vldb ubik call =
disk-commit tid 1334787313.208 (40)</div>
<div>22:21:49.366314 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =
=A0rx data vldb ubik reply disk-commit (28)</div><div>22:21:49.366374 IP SE=
RVER1.afs3-vlserver > SERVER2.afs3-vlserver: =A0rx ack first 2 serial 0 =
reason delay (65)</div>
<div>22:21:49.366392 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx data vldb ubik call disk-releaselocks tid 1334787313.208 (40)</div><d=
iv>22:21:49.368088 IP SERVER2.afs3-vlserver > SERVER1.afs3-vlserver: =A0=
rx data vldb ubik reply disk-releaselocks (28)</div>
<div>22:21:49.368140 IP SERVER1.afs3-vlserver > SERVER2.afs3-vlserver: =
=A0rx ack first 2 serial 0 reason delay (65)</div></div><div><br></div>
--0016e6de006a15871d04bdfb9fb4--