high CPU load on storage servers when uploading large mutable file #983

New issue

Closed

opened 2010-03-09 06:11:31 +00:00 by zooko · 26 comments

zooko commented

2010-03-09 06:11:31 +00:00

Jody Harris and Justin Stottlemyer both reported that uploading a large mutable file causes high CPU load on storage servers. Brian then found this bug: http://foolscap.lothar.com/trac/ticket/149 (O(n^2^) CPU/malloc during receive of large strings) which could explain their problems. Jody's report was on the mailing list and Justin's was #962.

The next step is for Brian to fix this issue in foolscap and then for Jody and Justin to test out the new version of foolscap with Tahoe-LAFS and see if that fixes that problem.

Jody Harris and Justin Stottlemyer both reported that uploading a large mutable file causes high CPU load on storage servers. Brian then found this bug: <http://foolscap.lothar.com/trac/ticket/149> (O(n^2^) CPU/malloc during receive of large strings) which could explain their problems. Jody's [report was on the mailing list](http://allmydata.org/pipermail/tahoe-dev/2010-March/004049.html) and Justin's was #962. The next step is for Brian to fix this issue in foolscap and then for Jody and Justin to test out the new version of foolscap with Tahoe-LAFS and see if that fixes that problem.

zooko added the

labels 2010-03-09 06:11:31 +00:00

zooko added this to the undecided milestone 2010-03-09 06:11:31 +00:00

zooko commented

2010-03-10 18:19:11 +00:00

Author

Brian: wouldn't this cause a similar high CPU load on storage clients during download of a large mutable file just as it does on storage servers during upload of a large mutable file? As far as I understand, the high CPU load is incurred whenever a large string is transferred through foolscap.

zooko commented

2010-03-10 18:20:51 +00:00

Author

In the initial message I wrote:

The next step is for Brian to fix this issue in foolscap

Well actually Brian doesn't have to be the one to do it! I posted some untested example code over on (@@http://foolscap.lothar.com/trac/ticket/149#comment:-1@@) which shows one way that I might do it if I were fixing the code. Perhaps I or someone else could write the appropriate unit tests and implement that solution or another solution, provided that Brian indicates willingness to accept such patches into foolscap.

In the initial message I wrote: > The next step is for Brian to fix this issue in foolscap Well actually Brian doesn't have to be the one to do it! I posted some untested example code over on (@@http://foolscap.lothar.com/trac/ticket/149#[comment:-1](/tahoe-lafs/trac/issues/983#issuecomment--1)@@) which shows one way that I might do it if I were fixing the code. Perhaps I or someone else could write the appropriate unit tests and implement that solution or another solution, provided that Brian indicates willingness to accept such patches into foolscap.

warner commented

2010-03-10 20:11:22 +00:00

Your sample code is a good starting point.. I want to clean up the token-parsing state machine at the same time, so I'll be incorporating your ideas into the full fix. Thanks!

Yes, the foolscap bug affects the recipient of a large token (such as the single large block in a large mutable file). That will be either the storage server during upload, or the client during download. Your sample code is a good starting point.. I want to clean up the token-parsing state machine at the same time, so I'll be incorporating your ideas into the full fix. Thanks!

zooko commented

2010-03-25 09:07:29 +00:00

Author

I've offered a patch over on http://foolscap.lothar.com/trac/ticket/149 . Review needed, I guess. Although Brian hasn't indicated that he's willing to accept this sort of patch (replacing the current string buffer in banana.py a StringChain) and he has started on a patch that fixes the issue in a different way.

I've offered a patch over on <http://foolscap.lothar.com/trac/ticket/149> . Review needed, I guess. Although Brian hasn't indicated that he's willing to accept this sort of patch (replacing the current string buffer in banana.py a `StringChain`) and he has started on a patch that fixes the issue in a different way.

zooko commented

2010-03-26 18:37:13 +00:00

Author

Yay Brian accepted the patch and released foolscap v0.5.1. Here is the request to upload foolscap v0.5.1 to Lucid: https://bugs.launchpad.net/ubuntu/+source/foolscap/+bug/548993

Yay Brian accepted the patch and released foolscap v0.5.1. Here is the request to upload foolscap v0.5.1 to Lucid: <https://bugs.launchpad.net/ubuntu/+source/foolscap/+bug/548993>

zooko added the

r/fixed

label 2010-03-27 03:39:35 +00:00

zooko closed this issue

2010-03-27 03:39:35 +00:00

zooko commented

2010-03-31 01:04:18 +00:00

Author

maco package foolscap 0.5.1 for Ubuntu Lucid and ChosenOne ran some experiments. His experiments showed that storage servers running foolscap 0.5.1 did not accept shares of large mutable files faster than when they were running foolscap 0.4.2:

While using 0.4.2:

http://pastie.org/private/39twijkh8ip5ffzeiog

    * Current Size: 41943040
          o Per-Server Response Times:
                + [uydf5ds4]: 846ms

http://pastie.org/private/ofjv1dgmw44q44nt1jo4nw

    * Current Size: 104857600
          o Per-Server Response Times:
                + [uydf5ds4]: 6.07s

http://pastie.org/private/zcns60kuyx2rjdpfhnl2g

    * Current Size: 209715200
          o Per-Server Response Times:
                + [uydf5ds4]: 20 seconds

After upgrading to foolscap 0.5.1:

http://pastie.org/private/g9xfymdchzvxqpkoxdowkq

    * Current Size: 209715200
          o Per-Server Response Times:
                + [uydf5ds4]: 36 seconds

http://pastie.org/private/fnkdkn7jkhm7yriidkx0ba

    * Current Size: 209715200
          o Per-Server Response Times:
                + [uydf5ds4]: 69 seconds

Hm. In fact, the pattern, if there is one, is that it takes twice as long every time he uploads a file!

maco package foolscap 0.5.1 for Ubuntu Lucid and ChosenOne ran some experiments. His experiments showed that storage servers running foolscap 0.5.1 did *not* accept shares of large mutable files faster than when they were running foolscap 0.4.2: While using 0.4.2: <http://pastie.org/private/39twijkh8ip5ffzeiog> ``` * Current Size: 41943040 o Per-Server Response Times: + [uydf5ds4]: 846ms ``` <http://pastie.org/private/ofjv1dgmw44q44nt1jo4nw> ``` * Current Size: 104857600 o Per-Server Response Times: + [uydf5ds4]: 6.07s ``` <http://pastie.org/private/zcns60kuyx2rjdpfhnl2g> ``` * Current Size: 209715200 o Per-Server Response Times: + [uydf5ds4]: 20 seconds ``` After upgrading to foolscap 0.5.1: <http://pastie.org/private/g9xfymdchzvxqpkoxdowkq> ``` * Current Size: 209715200 o Per-Server Response Times: + [uydf5ds4]: 36 seconds ``` <http://pastie.org/private/fnkdkn7jkhm7yriidkx0ba> ``` * Current Size: 209715200 o Per-Server Response Times: + [uydf5ds4]: 69 seconds ``` Hm. In fact, the pattern, if there is one, is that it takes twice as long every time he uploads a file!

zooko removed the

r/fixed

label 2010-03-31 01:04:18 +00:00

zooko reopened this issue

2010-03-31 01:04:18 +00:00

zooko commented

2010-04-09 04:00:24 +00:00

Author

I tried to reproduce ChosenOne's results. I don't think I succeeded:

size MB push rate MBps (all results from several trials)
------- ------------------------------------------------
10      2.88 1.97 1.35 2.17
20      1.99 2.39 2.89
40      1.37 1.18 2.88 
80      3.02 1.18 1.22 3.02
160     2.12 0.82 1.10 2.12
320     1.75

So my best hypothesis is that ChosenOne was somehow still using foolscap 0.4.2 when he did the second set of experiments and he thought he was using foolscap 0.5.1. However, I asked him several times to check for that when he was running those experiments and he did check and he was pretty sure the storage servers were running 0.5.1.
So, I think we need someone else to try to reproduce this. I guess it is possible that the foolscap-0.5.1 package from Ubuntu (which is what ChosenOne was testing) has some terrible performance flaw in it but foolscap-0.5.1 upstream doesn't.
Note that there is a lot of variance. In my experiments (which were performed under not-really-controlled conditions where I was using my laptop for other things at the same time as running the benchmarks) there was large variance -- 2 x or 3 x between successive runs at the same file size.
So another next step would be for ChosenOne to try to reproduce his own experiment and run the 200 MiB mutable file upload several times with foolscap-0.5.1 and several times with foolscap-0.4.2 and see if there is a pattern after, say, half-a-dozen runs each.
Oh, and one time I accidentally left off the "mutable" checkbox and uploaded a 40 MB file as an immutable file. Look what happened!

# Encode And Push: 3 minutes (216.7kBps)

    * Cumulative Encoding: 6.31s (6.34MBps)
    * Cumulative Pushing: 2 minutes (224.4kBps)
    * Send Hashes And Close: 928ms

With foolscap-0.5.1, Tahoe-LAFS v1.6.1 uploads mutable files much faster than immutable files. It's kind of disappointing how slow Tahoe-LAFS is at immutable file upload (and nobody knows why! #320, #392, #809).

On the other hand, the slowness of uploading immutable files is probably mostly due to waiting unnecessarily for round trips, so it is "network nice" -- uploading a large immutable file probably won't slam your network and interfere with your web browsing as much as uploading a large mutable file will. Also, the behavior will be about the same for a file of any size.

The slowdown that we had with large mutable files (the subject of this ticket) was due to burning up the CPU on the receiver's side, which is definitely not nice and which got less nice the larger your file was, so I'm very glad this ticket has been fixed.

If it has.

Assigning to ChosenOne to try to reproduce it.

I tried to reproduce ChosenOne's results. I don't think I succeeded: ``` size MB push rate MBps (all results from several trials) ------- ------------------------------------------------ 10 2.88 1.97 1.35 2.17 20 1.99 2.39 2.89 40 1.37 1.18 2.88 80 3.02 1.18 1.22 3.02 160 2.12 0.82 1.10 2.12 320 1.75 ``` So my best hypothesis is that ChosenOne was somehow still using foolscap 0.4.2 when he did the second set of experiments and he thought he was using foolscap 0.5.1. However, I asked him several times to check for that when he was running those experiments and he did check and he was pretty sure the storage servers were running 0.5.1. So, I think we need someone else to try to reproduce this. I guess it is possible that the foolscap-0.5.1 package from Ubuntu (which is what ChosenOne was testing) has some terrible performance flaw in it but foolscap-0.5.1 upstream doesn't. Note that there is a lot of variance. In my experiments (which were performed under not-really-controlled conditions where I was using my laptop for other things at the same time as running the benchmarks) there was large variance -- 2 x or 3 x between successive runs at the same file size. So another next step would be for ChosenOne to try to reproduce his own experiment and run the 200 MiB mutable file upload several times with foolscap-0.5.1 and several times with foolscap-0.4.2 and see if there is a pattern after, say, half-a-dozen runs each. Oh, and one time I accidentally left off the "mutable" checkbox and uploaded a 40 MB file as an immutable file. Look what happened! ``` # Encode And Push: 3 minutes (216.7kBps) * Cumulative Encoding: 6.31s (6.34MBps) * Cumulative Pushing: 2 minutes (224.4kBps) * Send Hashes And Close: 928ms ``` With foolscap-0.5.1, Tahoe-LAFS v1.6.1 uploads mutable files much faster than immutable files. It's kind of disappointing how slow Tahoe-LAFS is at immutable file upload (and nobody knows why! #320, #392, #809). On the other hand, the slowness of uploading immutable files is probably mostly due to waiting unnecessarily for round trips, so it is "network nice" -- uploading a large immutable file probably won't slam your network and interfere with your web browsing as much as uploading a large mutable file will. Also, the behavior will be about the same for a file of any size. The slowdown that we had with large mutable files (the subject of this ticket) was due to burning up the CPU on the receiver's side, which is definitely not nice and which got less nice the larger your file was, so I'm very glad this ticket has been fixed. If it has. Assigning to ChosenOne to try to reproduce it.

zooko commented

2010-04-09 16:06:24 +00:00

Author

Note that my attempts to reproduce this in comment:376958 are on my Macbook Pro running Mac OS 10.4, not on Ubuntu.

Note that my attempts to reproduce this in [comment:376958](/tahoe-lafs/trac/issues/983#issuecomment-376958) are on my Macbook Pro running Mac OS 10.4, not on Ubuntu.

zooko commented

2010-04-13 04:38:22 +00:00

Author

400 MB	

real	23m3.963s
user	0m0.030s
sys	0m0.930s

# Pushing: 16 minutes (412.1kBps)

http://pastie.org/private/c8zkyjea2ogn5so6dlxq

## 400MB
   real	15m55.535s
   user	0m0.070s
   sys	0m0.510s
   # Pushing: 7 minutes (923.1kBps)

## 200MB
1
   real	1m58.554s
   user	0m0.020s
   sys	0m0.400s
   # Pushing: 37 seconds (5.57MBps)

2
   real	1m22.431s
   user	0m0.030s
   sys	0m0.400s
   # Pushing: 26 seconds (7.80MBps)
3:
   real	1m2.264s
   user	0m0.020s
   sys	0m0.390s
   # Pushing: 15 seconds (13.65MBps)
4:
   real	0m59.669s
   user	0m0.050s
   sys	0m0.320s
   # Pushing: 16 seconds (12.44MBps)
5:
   real	1m3.264s
   user	0m0.020s
   sys	0m0.320s
   # Pushing: 18 seconds (11.15MBps)
6:
   real	0m56.371s
   user	0m0.020s
   sys	0m0.340s
   # Pushing: 17 seconds (12.07MBps)
7:
   real	1m4.337s
   user	0m0.060s
   sys	0m0.310s
   # Pushing: 21 seconds (9.85MBps)  
8:
   real	0m52.630s
   user	0m0.020s
   sys	0m0.350s
   # Pushing: 18 seconds (11.60MBps)
9:
   real	0m49.644s
   user	0m0.000s
   sys	0m0.330s
   # Pushing: 17 seconds (11.88MBps)
10:
   real	0m47.338s
   user	0m0.000s
   sys	0m0.310s
   # Pushing: 13 seconds (16.04MBps)

ChosenOne reproduced this problem on his Ubuntu Lucid (alpha) at my request. It really seems like on his system there is a superlinear cost (whether CPU cost or some other time-sink I'm not sure) to uploading mutable files. <http://pastie.org/914448> ``` 400 MB real 23m3.963s user 0m0.030s sys 0m0.930s # Pushing: 16 minutes (412.1kBps) ``` <http://pastie.org/private/c8zkyjea2ogn5so6dlxq> ``` ## 400MB real 15m55.535s user 0m0.070s sys 0m0.510s # Pushing: 7 minutes (923.1kBps) ## 200MB 1 real 1m58.554s user 0m0.020s sys 0m0.400s # Pushing: 37 seconds (5.57MBps) 2 real 1m22.431s user 0m0.030s sys 0m0.400s # Pushing: 26 seconds (7.80MBps) 3: real 1m2.264s user 0m0.020s sys 0m0.390s # Pushing: 15 seconds (13.65MBps) 4: real 0m59.669s user 0m0.050s sys 0m0.320s # Pushing: 16 seconds (12.44MBps) 5: real 1m3.264s user 0m0.020s sys 0m0.320s # Pushing: 18 seconds (11.15MBps) 6: real 0m56.371s user 0m0.020s sys 0m0.340s # Pushing: 17 seconds (12.07MBps) 7: real 1m4.337s user 0m0.060s sys 0m0.310s # Pushing: 21 seconds (9.85MBps) 8: real 0m52.630s user 0m0.020s sys 0m0.350s # Pushing: 18 seconds (11.60MBps) 9: real 0m49.644s user 0m0.000s sys 0m0.330s # Pushing: 17 seconds (11.88MBps) 10: real 0m47.338s user 0m0.000s sys 0m0.310s # Pushing: 13 seconds (16.04MBps) ```

zooko commented

2010-04-13 04:42:06 +00:00

Author

ChosenOne: please give us the following information:

The set of storage servers connected to your web gateway (this set is visible on the Welcome Page of your web gateway).
The output of tahoe --version-and-path
The output of apt-cache policy python-foolscap
The output of apt-cache policy tahoe-lafs
The output of python -c 'import pkg_resources;print pkg_resources.require("foolscap")'
The output of python -c 'import foolscap;print foolscap;print foolscap.*version*'
Thanks!

ChosenOne: please give us the following information: 1. The set of storage servers connected to your web gateway (this set is visible on the Welcome Page of your web gateway). 2. The output of `tahoe --version-and-path` 3. The output of `apt-cache policy python-foolscap` 4. The output of `apt-cache policy tahoe-lafs` 5. The output of `python -c 'import pkg_resources;print pkg_resources.require("foolscap")'` 6. The output of `python -c 'import foolscap;print foolscap;print foolscap.*version*'` Thanks!

ChosenOne commented

2010-04-13 16:02:21 +00:00

Owner

There is just one storage server on my local test box, called "test1 (uydf5ds4zxp4d2xvstcklra2nhmbk2nt)"
(There were some deprecationwarnings from popen and hashlib that I cut out)

allmydata-tahoe: 1.5.0 (/usr/lib/pymodules/python2.6), foolscap: 0.5.1 (/usr/lib/pymodules/python2.6/foolscap), pycryptopp: 0.5.17 (/usr/lib/pymodules/python2.6/pycryptopp), zfec: 1.4.5 (/usr/lib/pymodules/python2.6/zfec), Twisted: 8.2.0 (/usr/lib/python2.6/dist-packages/twisted), Nevow: 0.9.31 (/usr/lib/python2.6/dist-packages/nevow), zope.interface: unknown (/usr/local/lib/python2.6/dist-packages/zope/interface), python: 2.6.4 (/usr/bin/python), platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF (None), sqlite: 3.6.16 (unknown), simplejson: 2.0.9 (/usr/local/lib/python2.6/dist-packages/simplejson-2.0.9-py2.6-linux-x86_64.egg/simplejson), pyOpenSSL: 0.9 (/usr/lib/pymodules/python2.6/OpenSSL), setuptools: 0.6c9 (/usr/lib/python2.6/dist-packages/setuptools), pysqlite: 2.4.1 (/usr/lib/python2.6/sqlite3)

(manually translated into english by myself)

 python-foolscap:
  installed: 0.5.1+dfsg-0ubuntu1
  candidate: 0.5.1+dfsg-0ubuntu1
  version table:
 *** 0.5.1+dfsg-0ubuntu1 0
        100 /var/lib/dpkg/status
     0.4.2+dfsg-1 0
        500 http://de.archive.ubuntu.com karmic/universe Packages

(see 3)

tahoe-lafs:
  installed: 1.5.0-0ubuntu1
  candidate: 1.5.0-0ubuntu1
  version table:
 *** 1.5.0-0ubuntu1 0
        500 http://de.archive.ubuntu.com karmic/universe Packages
        100 /var/lib/dpkg/status

[foolscap 0.5.1 (/usr/lib/pymodules/python2.6), Twisted 8.2.0 (/usr/lib/python2.6/dist-packages)]

 <module 'foolscap' from '/usr/lib/pymodules/python2.6/foolscap/__init__.py'>
0.5.1

1. There is just one storage server on my local test box, called "test1 (uydf5ds4zxp4d2xvstcklra2nhmbk2nt)" 2. (There were some deprecationwarnings from popen and hashlib that I cut out) ``` allmydata-tahoe: 1.5.0 (/usr/lib/pymodules/python2.6), foolscap: 0.5.1 (/usr/lib/pymodules/python2.6/foolscap), pycryptopp: 0.5.17 (/usr/lib/pymodules/python2.6/pycryptopp), zfec: 1.4.5 (/usr/lib/pymodules/python2.6/zfec), Twisted: 8.2.0 (/usr/lib/python2.6/dist-packages/twisted), Nevow: 0.9.31 (/usr/lib/python2.6/dist-packages/nevow), zope.interface: unknown (/usr/local/lib/python2.6/dist-packages/zope/interface), python: 2.6.4 (/usr/bin/python), platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF (None), sqlite: 3.6.16 (unknown), simplejson: 2.0.9 (/usr/local/lib/python2.6/dist-packages/simplejson-2.0.9-py2.6-linux-x86_64.egg/simplejson), pyOpenSSL: 0.9 (/usr/lib/pymodules/python2.6/OpenSSL), setuptools: 0.6c9 (/usr/lib/python2.6/dist-packages/setuptools), pysqlite: 2.4.1 (/usr/lib/python2.6/sqlite3) ``` 3. (manually translated into english by myself) ``` python-foolscap: installed: 0.5.1+dfsg-0ubuntu1 candidate: 0.5.1+dfsg-0ubuntu1 version table: *** 0.5.1+dfsg-0ubuntu1 0 100 /var/lib/dpkg/status 0.4.2+dfsg-1 0 500 http://de.archive.ubuntu.com karmic/universe Packages ``` 4. (see 3) ``` tahoe-lafs: installed: 1.5.0-0ubuntu1 candidate: 1.5.0-0ubuntu1 version table: *** 1.5.0-0ubuntu1 0 500 http://de.archive.ubuntu.com karmic/universe Packages 100 /var/lib/dpkg/status ``` 5. ``` [foolscap 0.5.1 (/usr/lib/pymodules/python2.6), Twisted 8.2.0 (/usr/lib/python2.6/dist-packages)] ``` 6. ``` <module 'foolscap' from '/usr/lib/pymodules/python2.6/foolscap/__init__.py'> 0.5.1 ```

zooko commented

2010-04-13 16:12:42 +00:00

Author

Thanks! In regards to your answer to my question 1, though, did you look at the gateway Welcome Page to make sure that it is connecting to only that one storage server?

If you get a chance I would appreciate it if you would upgrade to Tahoe-LAFS v1.6.1 (from Ubuntu Lucid) and try your ten 200 MB tests again! Thank you.

Thanks! In regards to your answer to my question 1, though, did you look at the gateway Welcome Page to make sure that it is connecting to only that one storage server? If you get a chance I would appreciate it if you would upgrade to Tahoe-LAFS v1.6.1 (from Ubuntu Lucid) and try your ten 200 MB tests again! Thank you.

daira commented

2010-04-13 18:13:02 +00:00

Could be virtual memory thrashing, maybe? What are the page-fault rates for various sizes of file?

zooko commented

2010-04-14 03:27:36 +00:00

Author

If anyone wants to try to reproduce this on Ubuntu Lucid here's the process:

sudo apt-get install tahoe-lafs
mkdir introducer
tahoe create-introducer -C introducer
tahoe start introducer
mkdir server
tahoe create-node -C server --introducer=`cat introducer/introducer.furl`
tahoe start server
mkdir client
tahoe create-client -C client --introducer=`cat introducer/introducer.furl`

Now the client is listening on localhost port 3456. If you open a web browser to <http://localhost:3456> then you'll see the web user interface for Tahoe-LAFS. You can click on the button to select a file from your filesystem and the "upload" button to upload that file.
The issue that ChosenOne sees only applies to mutable files, so check the "mutable" checkbox.
Or you can use the command-line tool:

tahoe put --mutable $FILENAME

Please try uploading a mutable file of about 200 MB several times and then uploading a mutable file of about 400 MB a few times. The look at this list of recent uploads and downloads and how fast they went:

http://localhost:3456/status/

If the 400 MB files were substantially slower (like, half as fast in the "Pushing" measurement) then you've successfully reproduced ChosenOne's bug!

If anyone wants to try to reproduce this on Ubuntu Lucid here's the process: ``` sudo apt-get install tahoe-lafs mkdir introducer tahoe create-introducer -C introducer tahoe start introducer mkdir server tahoe create-node -C server --introducer=`cat introducer/introducer.furl` tahoe start server mkdir client tahoe create-client -C client --introducer=`cat introducer/introducer.furl` ``` Now the client is listening on localhost port 3456. If you open a web browser to `<http://localhost:3456>` then you'll see the web user interface for Tahoe-LAFS. You can click on the button to select a file from your filesystem and the "upload" button to upload that file. The issue that ChosenOne sees only applies to mutable files, so check the "mutable" checkbox. Or you can use the command-line tool: ``` tahoe put --mutable $FILENAME ``` Please try uploading a mutable file of about 200 MB several times and then uploading a mutable file of about 400 MB a few times. The look at this list of recent uploads and downloads and how fast they went: ``` http://localhost:3456/status/ ``` If the 400 MB files were substantially slower (like, half as fast in the "Pushing" measurement) then you've successfully reproduced ChosenOne's bug!

zooko commented

2010-04-14 03:29:51 +00:00

Author

Oops, after I posted those instructions I tried them myself and noticed a bug in the instructions. After tahoe create-client then you need tahoe start client. Sorry about that.

Oops, after I posted those instructions I tried them myself and noticed a bug in the instructions. After `tahoe create-client` then you need `tahoe start client`. Sorry about that.

stott commented

2010-05-07 00:54:02 +00:00

Owner

Confirmed very high load on 100M+ mutable file.

root@SM-MGMT01:~# time tahoe put --mutable ~/524stottlemyer.zip
/usr/lib/pymodules/python2.6/foolscap/banana.py:2: DeprecationWarning: the sets module is deprecated

import struct, sets, time
200 OK
URI:SSK:fynm2m23iii5eiudqdwj4n4qfe:2c7kwpuypkve7rbt62xxil3z7jsvmfdq2h6vrrxejhj7ppo3bzzq

real 2m40.807s
user 0m0.270s
sys 0m0.080s

allmydata-tahoe: 1.5.0, foolscap: 0.4.2, pycryptopp: 0.5.17, zfec: 1.4.5, Twisted: 8.2.0, Nevow: 0.9.31, zope.interface: unknown, python: 2.6.4rc2, platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF, sqlite: 3.6.16, simplejson: 2.0.9, pyOpenSSL: 0.9, setuptools: 0.6c9, pysqlite: 2.4.1

Confirmed very high load on 100M+ mutable file. root@SM-MGMT01:~# time tahoe put --mutable ~/524stottlemyer.zip /usr/lib/pymodules/python2.6/foolscap/banana.py:2: [DeprecationWarning](wiki/DeprecationWarning): the sets module is deprecated > import struct, sets, time 200 OK URI:SSK:fynm2m23iii5eiudqdwj4n4qfe:2c7kwpuypkve7rbt62xxil3z7jsvmfdq2h6vrrxejhj7ppo3bzzq real 2m40.807s user 0m0.270s sys 0m0.080s allmydata-tahoe: 1.5.0, foolscap: 0.4.2, pycryptopp: 0.5.17, zfec: 1.4.5, Twisted: 8.2.0, Nevow: 0.9.31, zope.interface: unknown, python: 2.6.4rc2, platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF, sqlite: 3.6.16, simplejson: 2.0.9, pyOpenSSL: 0.9, setuptools: 0.6c9, pysqlite: 2.4.1

stott commented

2010-05-07 01:30:57 +00:00

Owner

After upgrading to foolscap 0.5.1 performance is roughly 8X faster. CPU is a fraction of previous usage.

time tahoe put --mutable ~/524stottlemyer.zip
200 OK
URI:SSK:6mndkeskunhpm555lrxnan6qbe:eqh32z4portwuk3qsp2ltr7wknwrjbakiijzbeqdq5smknc3qzua

real 0m23.484s
user 0m0.220s
sys 0m0.100s
root@SM-MGMT01:/tahoe# tahoe -V
/usr/lib/python2.6/dist-packages/formless/annotate.py:730: DeprecationWarning: object.new() takes no parameters

rv = cls = InterfaceClass.new(cls, name, bases, dct)
/usr/lib/python2.6/dist-packages/nevow/testutil.py:7: DeprecationWarning: The popen2 module is deprecated. Use the subprocess module.
from popen2 import Popen3
/usr/lib/python2.6/dist-packages/nevow/guard.py:15: DeprecationWarning: the md5 module is deprecated; use hashlib instead
import md5
allmydata-tahoe: 1.5.0, foolscap: 0.5.1, pycryptopp: 0.5.17, zfec: 1.4.5, Twisted: 8.2.0, Nevow: 0.9.31, zope.interface: unknown, python: 2.6.4rc2, platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF, sqlite: 3.6.16, simplejson: 2.0.9, pyOpenSSL: 0.9, setuptools: 0.6c9, pysqlite: 2.4.1

After upgrading to foolscap 0.5.1 performance is roughly 8X faster. CPU is a fraction of previous usage. time tahoe put --mutable ~/524stottlemyer.zip 200 OK URI:SSK:6mndkeskunhpm555lrxnan6qbe:eqh32z4portwuk3qsp2ltr7wknwrjbakiijzbeqdq5smknc3qzua real 0m23.484s user 0m0.220s sys 0m0.100s root@SM-MGMT01:/tahoe# tahoe -V /usr/lib/python2.6/dist-packages/formless/annotate.py:730: [DeprecationWarning](wiki/DeprecationWarning): object.*new*() takes no parameters > rv = cls = [InterfaceClass](wiki/InterfaceClass).*new*(cls, name, bases, dct) /usr/lib/python2.6/dist-packages/nevow/testutil.py:7: [DeprecationWarning](wiki/DeprecationWarning): The popen2 module is deprecated. Use the subprocess module. > from popen2 import Popen3 /usr/lib/python2.6/dist-packages/nevow/guard.py:15: [DeprecationWarning](wiki/DeprecationWarning): the md5 module is deprecated; use hashlib instead > import md5 allmydata-tahoe: 1.5.0, foolscap: 0.5.1, pycryptopp: 0.5.17, zfec: 1.4.5, Twisted: 8.2.0, Nevow: 0.9.31, zope.interface: unknown, python: 2.6.4rc2, platform: Linux-Ubuntu_9.10-x86_64-64bit_ELF, sqlite: 3.6.16, simplejson: 2.0.9, pyOpenSSL: 0.9, setuptools: 0.6c9, pysqlite: 2.4.1

zooko commented

2010-05-08 04:22:56 +00:00

Author

It is good to have confirmation that foolscap-0.5.1 is much better than foolscap-0.4.2 in this respect. Note that stott is using Ubuntu 9.10 in these tests. The remaining question is whether anyone can replicate ChosenOne's results one Ubuntu 10.04 (using the Tahoe-LAFS and the foolscap that come packaged by Ubuntu). In particular, is the rate of upload slower for larger files. For example, if stott can upload a 100 MB file at a rate of about 4.2 MB/s (per his comment:376968), can he also upload a 200 MB file at about the same rate?

Be ware of memory usage effects -- swapping for example. Mutable files of that size use up substantial RAM.

It is good to have confirmation that foolscap-0.5.1 is much better than foolscap-0.4.2 in this respect. Note that stott is using Ubuntu 9.10 in these tests. The remaining question is whether anyone can replicate ChosenOne's results one Ubuntu 10.04 (using the Tahoe-LAFS and the foolscap that come packaged by Ubuntu). In particular, is the rate of upload slower for larger files. For example, if stott can upload a 100 MB file at a rate of about 4.2 MB/s (per his [comment:376968](/tahoe-lafs/trac/issues/983#issuecomment-376968)), can he also upload a 200 MB file at about the same rate? Be ware of memory usage effects -- swapping for example. Mutable files of that size use up substantial RAM.

stott commented

2010-05-18 04:24:13 +00:00

Owner

NOTE:CPU Utilization on the gateway was at 100% though the other cores still had spare cycles.

root@sm-mgmt01:~# time tahoe put --mutable 100MB.zip
200 OK
URI:SSK:j5qyjqu32gnwsdkkgoyvdfv5yu:nezeyykufmfs5cel5kdqxx62qfm5ydyaamcods3qdtzrv4xfhz4q

real    0m21.745s
user    0m0.320s
sys     0m0.090s
root@sm-mgmt01:~# time tahoe put --mutable 200MB.zip
200 OK
URI:SSK:lypkcn3sm43dul2tsj4vto3nq4:b3dvlpfbmrwr2qussaefqu6kifx575ao63wlys4exjk3m6fhutva

real    0m42.530s
user    0m0.390s
sys     0m0.210s
root@sm-mgmt01:~# time tahoe put --mutable 300MB.zip
200 OK
URI:SSK:lwpspr6yl2prrdajzcgtw77u7q:i6yor622koofviu5qn5f2kk6nszfg36anajtgho7kf4pp24ui4aa

real    1m6.338s
user    0m0.420s
sys     0m0.200s
root@sm-mgmt01:~# time tahoe put --mutable 400MB.zip
200 OK
URI:SSK:regvthmbtq7zds67qf2k72wafm:mtv5hpilg63kbeaa46bodl6xsk25eous3qctb26aydifq7un2kaq

real    1m31.576s
user    0m0.970s
sys     0m0.700s
root@sm-mgmt01:~# time tahoe put --mutable 500MB.zip 
200 OK
URI:SSK:ibqlpkk4xc5kpeosjlzxc3orsy:6zmdo5bb7mngxzjzo4zg33malvk42ycs5tuu2yznyjmalsj4syxa

real    2m37.083s
user    0m1.300s
sys     0m1.210s

Attempting to reproduce the bug, I was not able to reproduce the results. CPU utilization was linear and performance was linear until I began to use swap space. Memory consumption was not linear with size of the mutable file. NOTE:CPU Utilization on the gateway was at 100% though the other cores still had spare cycles. ``` root@sm-mgmt01:~# time tahoe put --mutable 100MB.zip 200 OK URI:SSK:j5qyjqu32gnwsdkkgoyvdfv5yu:nezeyykufmfs5cel5kdqxx62qfm5ydyaamcods3qdtzrv4xfhz4q real 0m21.745s user 0m0.320s sys 0m0.090s root@sm-mgmt01:~# time tahoe put --mutable 200MB.zip 200 OK URI:SSK:lypkcn3sm43dul2tsj4vto3nq4:b3dvlpfbmrwr2qussaefqu6kifx575ao63wlys4exjk3m6fhutva real 0m42.530s user 0m0.390s sys 0m0.210s root@sm-mgmt01:~# time tahoe put --mutable 300MB.zip 200 OK URI:SSK:lwpspr6yl2prrdajzcgtw77u7q:i6yor622koofviu5qn5f2kk6nszfg36anajtgho7kf4pp24ui4aa real 1m6.338s user 0m0.420s sys 0m0.200s root@sm-mgmt01:~# time tahoe put --mutable 400MB.zip 200 OK URI:SSK:regvthmbtq7zds67qf2k72wafm:mtv5hpilg63kbeaa46bodl6xsk25eous3qctb26aydifq7un2kaq real 1m31.576s user 0m0.970s sys 0m0.700s root@sm-mgmt01:~# time tahoe put --mutable 500MB.zip 200 OK URI:SSK:ibqlpkk4xc5kpeosjlzxc3orsy:6zmdo5bb7mngxzjzo4zg33malvk42ycs5tuu2yznyjmalsj4syxa real 2m37.083s user 0m1.300s sys 0m1.210s ```

tahoe-lafs added

v/1.6.1

and removed

v/1.6.0

labels 2010-05-18 04:24:13 +00:00

zooko commented

2010-05-19 21:44:50 +00:00

Author

Okay, I think this issue is fixed and the performance problems observed by ChosenOne probably have to do with using up too much RAM and getting into swap. ChosenOne: if you want to investigate and confirm or deny that hypothesis, that would be great. For now, closing this ticket as "fixed".

zooko added the

r/fixed

label 2010-05-19 21:44:50 +00:00

zooko modified the milestone from undecided to 1.6.1

2010-05-19 21:44:50 +00:00

zooko closed this issue

2010-05-19 21:44:50 +00:00

zooko commented

2010-05-27 21:45:48 +00:00

Author

See also #541 (foolscap 'reference'-token bug workaround in mutable publish) -- we could remove the workaround in mutable publish once we've raised the required version number of foolscap.

This was fixed in foolscap v0.5.1. I think we should bump the required version number from >= 0.4.1 to >= 0.5.1 in our [_auto_dep.py]source:_auto_deps.py@4277#L13. I don't imagine it will cause a lot of problems for people to need to upgrade to foolscap 0.5.1. See also #541 (foolscap 'reference'-token bug workaround in mutable publish) -- we could remove the workaround in mutable publish once we've raised the required version number of foolscap.

zooko removed the

r/fixed

label 2010-05-27 21:45:48 +00:00

zooko reopened this issue

2010-05-27 21:45:48 +00:00

zooko modified the milestone from 1.6.1 to 1.7.0

2010-05-27 21:46:05 +00:00

daira commented

2010-05-27 22:04:24 +00:00

Replying to zooko:

This was fixed in foolscap v0.5.1. I think we should bump the required version number from >= 0.4.1 to >= 0.5.1 in our [_auto_dep.py]source:_auto_deps.py@4277#L13. I don't imagine it will cause a lot of problems for people to need to upgrade to foolscap 0.5.1.

See also #541 (foolscap 'reference'-token bug workaround in mutable publish) -- we could remove the workaround in mutable publish once we've raised the required version number of foolscap.

According to http://foolscap.lothar.com/trac/ticket/104 , that bug was fixed in foolscap 0.4.0, which was required by Tahoe r3870 (2009-05-22). The next Tahoe release after that was v1.5.0 (2009-08-02). So we cannot remove the workaround until we no longer care about interoperating with servers prior to v1.5.0.

Replying to [zooko](/tahoe-lafs/trac/issues/983#issuecomment-376977): > This was fixed in foolscap v0.5.1. I think we should bump the required version number from >= 0.4.1 to >= 0.5.1 in our [_auto_dep.py]source:_auto_deps.py@4277#L13. I don't imagine it will cause a lot of problems for people to need to upgrade to foolscap 0.5.1. > > See also #541 (foolscap 'reference'-token bug workaround in mutable publish) -- we could remove the workaround in mutable publish once we've raised the required version number of foolscap. According to <http://foolscap.lothar.com/trac/ticket/104> , that bug was fixed in foolscap 0.4.0, which was required by Tahoe r3870 (2009-05-22). The next Tahoe release after that was v1.5.0 (2009-08-02). So we cannot remove the workaround until we no longer care about interoperating with servers prior to v1.5.0.

zooko commented

2010-06-17 04:20:18 +00:00

Author

So just to summarize, the performance issue in foolscap is fixed, and the only question is whether to raise the requirement that Tahoe-LAFS imposes on which version of foolscap it needs.

zooko modified the milestone from 1.7.0 to soon

2010-06-17 04:20:18 +00:00

zooko commented

2010-07-21 15:59:04 +00:00

Author

I think we should raise the requirement on the version of foolscap so that Tahoe-LAFS users will not encounter this performance issue.

zooko modified the milestone from soon to 1.8β

2010-07-21 15:59:04 +00:00

zooko commented

2010-08-02 07:35:40 +00:00

Author

Attachment increase-foolscap-version-requirement.dpatch.txt (5351 bytes) added