[tahoe-dev] multi-second delays when uploading mutable files Re: warning: Boing-Boinging imminent

Zooko O'Whielacronx zooko at zooko.com
Wed Sep 29 23:54:29 UTC 2010 

On Wed, Sep 29, 2010 at 4:06 PM, slush <slush at centrum.cz> wrote:
> Zooko, I'm speaking about more-than-minute responses.
>
> When I try to do POST http://pubgrid.tahoe-lafs.org/uri?t=mkdir , script
> hangs. Tested many times, many days. Doing the same on volunteergrid is
> almost instant. Maybe there is some other problem. Please try mkdir by self
> to test if I'm not alone who experience these problems.

I looked on the "Recent Uploads and Downloads" page on the public
pubgrid gateway:

http://pubgrid.tahoe-lafs.org/status/

mkdir operates by publishing a mutable file, so I looked for recent
"publish" operations. I found five (appended below). The time to
upload the data to the storage servers were: 880 ms, 638 ms, 632 ms,
5000 ms, and 6000 ms.

For the two uploads that took several seconds, one of them showed that
it finished uploading one share to one server (62nlabgf -- "sunpal7")
after 6s and another server (4rk5oqd7 -- "ahi") after 1.07s. The other
doesn't show any uploads taking very long, which makes me think there
is a bug in the timings display or perhaps even in the actual mutable
uploader. If someone out there wants to jump in and help diagnose
this, I would be grateful.

One good step forward would probably be writing a unit test of what
gets shown on the timings display page if one of the servers times out
instead of replying to your block request. Another good step forward
would probably be trying to reproduce this problem by using your own
local gateway node instead of http://pubgrid.tahoe-lafs.org . Another
would be examining sunpal7 and ahi for unusual characteristics.
Another would be adding features to Tahoe-LAFS to make it easy to
monitor and measure node behavior: #486, #648, #1163 . If you operate
sunpal7 or ahi then (until the next time you restart it) you can get
some stats about its behavior by visiting
http://$YOURHOST:$YOURIP/statistics .

Regards,

Zooko

http://tahoe-lafs.org/trac/tahoe-lafs/ticket/486# add munin graphs of
server-operation latency
http://tahoe-lafs.org/trac/tahoe-lafs/ticket/648# collect server
capacities and put them on the welcome page, output of 'df' for SFTP,
etc.
http://tahoe-lafs.org/trac/tahoe-lafs/ticket/1163# server stats

Mutable File Publish Status

    Started: 00:52:00 30-Sep-2010
    Storage Index: lzeqv7uwvpxdk63jok63fsd6yi
    Helper?: No
    Current Size: 9933
    Progress: 100.0%
    Status: Finished

Retrieve Results

    Encoding: 3 of 10
    Sharemap:
        0 -> Placed on [xflgj7cg], [fp3xjndg]
        1 -> Placed on [sp26qyqc], [4rk5oqd7]
        2 -> Placed on [62nlabgf], [vjm3frhz]
        3 -> Placed on [varyf6dy]
        4 -> Placed on [fp3xjndg], [62nlabgf]
        5 -> Placed on [sp26qyqc], [pnxevooc]
        6 -> Placed on [qnkwst2j], [q3iv63oa]
        7 -> Placed on [5ouv6kib], [pnxevooc], [qnkwst2j]
        8 -> Placed on [fp3xjndg]
        9 -> Placed on [sp26qyqc], [nszizgf5]
    Timings:
        Total: 887ms (11.2kBps)
            Setup: 390us
            Encrypting: 95us (104.68MBps)
            Encoding: 173us (57.39MBps)
            Packing Shares: 6.7ms (1.49MBps)
                RSA Signature: 5.2ms
            Pushing: 880ms (11.3kBps)
        Per-Server Response Times:
            [fp3xjndg]: 667ms
            [nszizgf5]: 226ms
            [pnxevooc]: 139ms
            [qnkwst2j]: 295ms
            [q3iv63oa]: 224ms
            [sp26qyqc]: 324ms
            [varyf6dy]: 449ms
            [vjm3frhz]: 89ms
            [xflgj7cg]: 56ms
            [4rk5oqd7]: 441ms
            [5ouv6kib]: 877ms
            [62nlabgf]: 430ms

Return to the Welcome Page

Mutable File Publish Status

    Started: 01:02:02 30-Sep-2010
    Storage Index: lzeqv7uwvpxdk63jok63fsd6yi
    Helper?: No
    Current Size: 9591
    Progress: 100.0%
    Status: Finished

Retrieve Results

    Encoding: 3 of 10
    Sharemap:
        0 -> Placed on [xflgj7cg], [fp3xjndg]
        1 -> Placed on [sp26qyqc], [4rk5oqd7]
        2 -> Placed on [vjm3frhz]
        3 -> Placed on [varyf6dy]
        4 -> Placed on [fp3xjndg]
        5 -> Placed on [sp26qyqc], [pnxevooc]
        6 -> Placed on [qnkwst2j], [q3iv63oa]
        7 -> Placed on [5ouv6kib], [pnxevooc], [qnkwst2j]
        8 -> Placed on [fp3xjndg]
        9 -> Placed on [sp26qyqc], [nszizgf5]
    Timings:
        Total: 638ms (15.0kBps)
            Setup: 578us
            Encrypting: 102us (93.99MBps)
            Encoding: 169us (56.74MBps)
            Packing Shares: 7.0ms (1.37MBps)
                RSA Signature: 5.3ms
            Pushing: 630ms (15.2kBps)
        Per-Server Response Times:
            [fp3xjndg]: 627ms
            [nszizgf5]: 236ms
            [pnxevooc]: 152ms
            [qnkwst2j]: 314ms
            [q3iv63oa]: 146ms
            [sp26qyqc]: 282ms
            [varyf6dy]: 276ms
            [vjm3frhz]: 99ms
            [xflgj7cg]: 60ms
            [4rk5oqd7]: 449ms
            [5ouv6kib]: 362ms

Return to the Welcome Page

Mutable File Publish Status

    Started: 01:06:34 30-Sep-2010
    Storage Index: lzeqv7uwvpxdk63jok63fsd6yi
    Helper?: No
    Current Size: 9202
    Progress: 100.0%
    Status: Finished

Retrieve Results

    Encoding: 3 of 10
    Sharemap:
        0 -> Placed on [xflgj7cg], [fp3xjndg]
        1 -> Placed on [sp26qyqc], [4rk5oqd7]
        2 -> Placed on [62nlabgf], [vjm3frhz]
        3 -> Placed on [varyf6dy]
        4 -> Placed on [fp3xjndg], [62nlabgf]
        5 -> Placed on [sp26qyqc], [pnxevooc]
        6 -> Placed on [qnkwst2j], [q3iv63oa]
        7 -> Placed on [5ouv6kib], [pnxevooc], [qnkwst2j]
        8 -> Placed on [fp3xjndg]
        9 -> Placed on [sp26qyqc], [nszizgf5]
    Timings:
        Total: 632ms (14.6kBps)
            Setup: 430us
            Encrypting: 88us (104.60MBps)
            Encoding: 146us (62.96MBps)
            Packing Shares: 7.6ms (1.22MBps)
                RSA Signature: 5.8ms
            Pushing: 624ms (14.8kBps)
        Per-Server Response Times:
            [fp3xjndg]: 621ms
            [nszizgf5]: 228ms
            [pnxevooc]: 143ms
            [qnkwst2j]: 316ms
            [q3iv63oa]: 141ms
            [sp26qyqc]: 330ms
            [varyf6dy]: 273ms
            [vjm3frhz]: 73ms
            [xflgj7cg]: 53ms
            [4rk5oqd7]: 343ms
            [5ouv6kib]: 272ms
            [62nlabgf]: 423ms

Return to the Welcome Page

Mutable File Publish Status

    Started: 01:22:30 30-Sep-2010
    Storage Index: oacms2v5mzz5twbldip53fne5e
    Helper?: No
    Current Size: 0
    Progress: 100.0%
    Status: Finished

Retrieve Results

    Encoding: 3 of 10
    Sharemap:
        0 -> Placed on [q3iv63oa]
        1 -> Placed on [fp3xjndg]
        2 -> Placed on [vjm3frhz]
        3 -> Placed on [lwlukwtw]
        4 -> Placed on [xflgj7cg]
        5 -> Placed on [5ouv6kib]
        6 -> Placed on [pnxevooc]
        7 -> Placed on [varyf6dy]
        8 -> Placed on [rpiw4n3f]
        9 -> Placed on [nszizgf5]
    Timings:
        Total: 5 minutes (0Bps)
            Setup: 235us
            Encrypting: 39us (0Bps)
            Encoding: 100us (0Bps)
            Packing Shares: 6.7ms (0Bps)
                RSA Signature: 5.4ms
            Pushing: 5 minutes (0Bps)
        Per-Server Response Times:
            [fp3xjndg]: 229ms
            [lwlukwtw]: 86ms
            [nszizgf5]: 128ms
            [pnxevooc]: 81ms
            [q3iv63oa]: 124ms
            [rpiw4n3f]: 135ms
            [varyf6dy]: 252ms
            [vjm3frhz]: 30ms
            [xflgj7cg]: 35ms
            [5ouv6kib]: 227ms

Return to the Welcome Page

Mutable File Publish Status

    Started: 02:00:38 30-Sep-2010
    Storage Index: b6wmbcbz2zuaudtlowjzpe4gr4
    Helper?: No
    Current Size: 0
    Progress: 100.0%
    Status: Finished

Retrieve Results

    Encoding: 3 of 10
    Sharemap:
        0 -> Placed on [62nlabgf]
        1 -> Placed on [qnkwst2j]
        2 -> Placed on [nszizgf5]
        3 -> Placed on [5ouv6kib]
        4 -> Placed on [vjm3frhz]
        5 -> Placed on [fp3xjndg]
        6 -> Placed on [lwlukwtw]
        7 -> Placed on [4rk5oqd7]
        8 -> Placed on [3fayzg6e]
        9 -> Placed on [sp26qyqc]
    Timings:
        Total: 6 minutes (0Bps)
            Setup: 260us
            Encrypting: 45us (0Bps)
            Encoding: 84us (0Bps)
            Packing Shares: 6.3ms (0Bps)
                RSA Signature: 5.0ms
            Pushing: 6 minutes (0Bps)
        Per-Server Response Times:
            [fp3xjndg]: 223ms
            [lwlukwtw]: 82ms
            [nszizgf5]: 123ms
            [qnkwst2j]: 156ms
            [sp26qyqc]: 125ms
            [vjm3frhz]: 52ms
            [3fayzg6e]: 205ms
            [4rk5oqd7]: 1.06s
            [5ouv6kib]: 139ms
            [62nlabgf]: 6 minutes

Return to the Welcome Page

More information about the tahoe-dev mailing list