Big file uploads and "Out of memory!"

[isync]

I've noticed that Dancer severely eats up resources when it processes large file uploads, and even sometimes exits with "Out of memory!". What is going on in Dancer's file uploads? Isn't it processing uploads chunk-wise, as per common-sense/best practice?

Can somebody try/reproduce this, please? (...although it's probably me doing something wrong):
Clone the Dancer-devel branch, edit file t/02_request/14_uploads.t and append this as test no. 23:

## test #23
# create a file, 256MB of zeros
system("dd if=/dev/zero of=$dest_dir/zeros count=250000 bs=1024");

my $resp =
  dancer_response( 'POST', '/upload',
    { files => [ { name => 'test', filename => $dest_dir .'/zeros' } ] } );
is $resp->content, $content;

I'm on a machine with 2,7 GiB memory.

$ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 21761
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 21761
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

[bigpresh]

I can confirm that I, also, get an "Out of memory!" error with the test above, on a box with 4GB RAM total, just under 3GB currently free.

[bigpresh]

Having looked into this a bit more, it looks like the problem is in Dancer::Request's parsing of HTTP bodies - in Dancer::Request->_read_to_end it appears to append the entire HTTP request body to a HTTP::Body object (Dancer::Request->{_http_body}), and also stores the raw body as Dancer::Request->{body}, which would seem to account for the dreadful memory usage.

I'm not sure yet how much work would be involved in avoiding this, or even how feasible it is without breaking a lot of things, but I have a feeling it would be a very big undertaking.

[bigpresh]

I'm thinking of attempting to remove the unparsed body from Dancer::Request - searching the core codebase for usages of it, I only see Dancer::Serializer and some tests. I think it may even be possible to replace the existing request->body which is an accessor for the raw unparsed body with e.g. sub body { shift->{_http_body}->body } so that we return just the request body (without file uploads etc) that is in the HTTP::Body object.

This is a fairly big change, but if the above idea works, the risk of breakage for end users should be fairly limited, and it would make our file upload handling much saner - I'd be willing to consider storing the entire request body (including file uploads) in RAM unnecessarily a bug worth fixing.

So - I'm looking in to a fix for this.

[isync]

Really great to see progress on this!
Cheers, David! 👍

[bigpresh]

Right, I've a few test failures within the test suite to fix, but my changes mostly seem to be working, and do significantly reduce the memory usage of a Dancer process handling a large file upload.

The output below is two runs of a simple test script which creates and uploads a 256MB file based on the code in this issue, with Memory::Usage used to show the memory used by the process. The first run is with the latest Dancer version from CPAN, the second run is with my modified version in my git checkout.

The resident sizes at end of execution show the difference - CPAN version: 2,260,084 bytes, my version 510,056 bytes.

[davidp@supernova:~/dev/github/Dancer]$ prove -vm ~/tmp/upload-test
/home/davidp/tmp/upload-test .. 
1..1
# Testing with Dancer 1.3142
250000+0 records in
250000+0 records out
256000000 bytes (256 MB) copied, 1.80278 s, 142 MB/s
ok 1 - Got expected response
  time    vsz (  diff)    rss (  diff) shared (  diff)   code (  diff)   data (  diff)
     0  13684 ( 13684)   9848 (  9848)   2136 (  2136)   1444 (  1444)   7872 (  7872) Ready to upload
     5  2447328 ( 2433644)  2260076 ( 2250228)   2168 (    32)   1444 (     0)  2441496 ( 2433624) Route executed
     5  2447328 (     0)  2260076 (     0)   2168 (     0)   1444 (     0)  2441496 (     0) Uploaded and fetched response
     5  2447328 (     0)  2260084 (     8)   2176 (     8)   1444 (     0)  2441496 (     0) End of testing
ok
All tests successful.
Files=1, Tests=1, 10 wallclock secs ( 0.07 usr  0.00 sys +  2.75 cusr  2.66 csys =  5.48 CPU)
Result: PASS
[davidp@supernova:~/dev/github/Dancer]$ prove -Ilib -vm ~/tmp/upload-test
/home/davidp/tmp/upload-test .. 
1..1
Use of uninitialized value $Dancer::VERSION in concatenation (.) or string at /home/davidp/tmp/upload-test line 16, <DATA> line 1000.
# Testing with Dancer 
250000+0 records in
250000+0 records out
256000000 bytes (256 MB) copied, 1.81067 s, 141 MB/s
Use of uninitialized value in concatenation (.) or string at /home/davidp/dev/github/Dancer/lib/Dancer/Renderer.pm line 63.
ok 1 - Got expected response
  time    vsz (  diff)    rss (  diff) shared (  diff)   code (  diff)   data (  diff)
     0  13680 ( 13680)   9856 (  9856)   2136 (  2136)   1444 (  1444)   7868 (  7868) Ready to upload
     5  576404 ( 562724)  510048 ( 500192)   2164 (    28)   1444 (     0)  570572 ( 562704) Route executed
     5  576404 (     0)  510048 (     0)   2164 (     0)   1444 (     0)  570572 (     0) Uploaded and fetched response
     5  576404 (     0)  510056 (     8)   2172 (     8)   1444 (     0)  570572 (     0) End of testing
ok
All tests successful.
Files=1, Tests=1,  9 wallclock secs ( 0.02 usr  0.01 sys +  3.19 cusr  1.85 csys =  5.07 CPU)
Result: PASS

[bigpresh]

And more tellingly, if I increase it to a 512MB file, on this 4GB RAM machine testing with the CPAN version explodes with an OOM error, whereas my updated version completes the test successfully, albeit using 1,010,056 RSS.

[bigpresh]

This issue should have been closed when the PR was merged - closing it now :)