[tahoe-lafs-trac-stream] [tahoe-lafs] #1456: High latency for 'tahoe get' if 'tahoe put' in parallel

[tahoe-lafs]

#1456: High latency for 'tahoe get' if 'tahoe put' in parallel
-------------------------+-------------------------------------------------
     Reporter:  T_X      |      Owner:  T_X
         Type:  defect   |     Status:  new
     Priority:           |  Milestone:  undecided
  critical               |    Version:  1.8.2
    Component:  code     |   Keywords:  download upload latency performance
   Resolution:           |  gateway vm kvm vpn trickle
Launchpad Bug:           |
-------------------------+-------------------------------------------------

Comment (by T_X):

 Okay, now with having figured out the cause of #1462, I tried test 2 and
 had a look at the status page again. And the "download timings" are
 actually fine, I think:
 {{{
     Started: 17:49:57 07-Aug-2011 (1312735797.17)
     Storage Index: 3pysvkzdgfswxkpkfyunwzblim
     Helper?: No
     Total Size: 95
     Progress: 100.0%
     Status: idle
     timeline

 DYHB Requests:
 serverid        sent    received        shnums  RTT
 sbw63iqt        +0.001030s      +0.090083s      0,1,2,3,4,5,6,7,8,9
 89ms

 Read Events:
 range   start   finish  got     time    decrypttime     pausedtime
 speed
 [0:+95] +0.000000s      +0.149550s      95      150ms   11us    0us
 635Bps

 Segment Events:
 segnum  start   active  finish  range   decodetime      segtime speed
 seg0    +0.000396s      +0.000461s      +0.148877s      [0:+95] 32us
 148ms   640Bps

 Requests:
 serverid        shnum   range   txtime  rxtime  received        RTT
 sbw63iqt        0       [0:+2445]       +0.120100s      +0.124593s
 1473    4.5ms
 }}}

 And actually all other timings on this web status page seem fine too,
 nothing that is remotely as high as the 500s+.

 Instead I noticed that the first mapupdate takes a very, very long time:
 - 'tahoe get' started at Sun Aug  7 17:36:55 BST 2011

 - Output of web page:
 {{{
 Recent Operations:
 Started         Type    Storage Index   Helper?         Total Size
 Progress        Status
 17:50:15 07-Aug-2011    publish         zb24cwlnpwynz7dtqszava76cm      No
 790B    100.0%  Finished
 17:50:15 07-Aug-2011    retrieve        zb24cwlnpwynz7dtqszava76cm      No
 790B    100.0%  Finished
 17:50:15 07-Aug-2011    mapupdate MODE_WRITE    zb24cwlnpwynz7dtqszava76cm
 No      -NA-    100.0%  Finished
 17:49:57 07-Aug-2011    download        3pysvkzdgfswxkpkfyunwzblim      No
 95B     100.0%  idle
 17:49:57 07-Aug-2011    retrieve        zb24cwlnpwynz7dtqszava76cm      No
 790B    100.0%  Finished
 17:49:56 07-Aug-2011    mapupdate MODE_READ     zb24cwlnpwynz7dtqszava76cm
 No      -NA-    100.0%  Finished
 17:49:56 07-Aug-2011    retrieve        zb24cwlnpwynz7dtqszava76cm      No
 790B    100.0%  Finished
 17:49:56 07-Aug-2011    mapupdate MODE_READ     zb24cwlnpwynz7dtqszava76cm
 No      -NA-    100.0%  Finished
 }}}

 - 'tahoe get' finished 782.01s after the start time.

 I'll make a tcpdump in a minute.

-- 
Ticket URL: <http://tahoe-lafs.org/trac/tahoe-lafs/ticket/1456#comment:4>
tahoe-lafs <http://tahoe-lafs.org>
secure decentralized storage