Bug #73262 [Com]: 8192 CHUNK_SIZE and PHP_SOCK_CHUNK_SIZE makes copy() slow

From: Date: Wed, 12 Oct 2016 23:30:18 +0000
Subject: Bug #73262 [Com]: 8192 CHUNK_SIZE and PHP_SOCK_CHUNK_SIZE makes copy() slow
References: 1  Groups: php.bugs 
Request: Send a blank email to php-bugs+get-204653@lists.php.net to get a copy of this message
Edit report at https://bugs.php.net/bug.php?id=73262&edit=1

 ID:                 73262
 Comment by:         jeffreydwalter at gmail dot com
 Reported by:        jeffreydwalter at gmail dot com
 Summary:            8192 CHUNK_SIZE and PHP_SOCK_CHUNK_SIZE makes copy()
                     slow
 Status:             Open
 Type:               Bug
 Package:            Performance problem
 Operating System:   Irrelevant
 PHP Version:        Irrelevant
 Block user comment: N
 Private report:     N

 New Comment:

Here's a little better version of my original test script:

<?php

define('FILE_SIZE_IN_MB', 100);
foreach([1,2,5,10,15, 19, 20,50,100,250,350,400,500,1000] as $file_size) {

    printf('Generating %sMB dummy file.'.PHP_EOL, $file_size);
    if(!file_exists("dummy.$file_size.txt")) {
        echo shell_exec('dd if=/dev/urandom of=dummy.'.$file_size.'.txt bs=1048576
count='.$file_size.' 2>&1 | grep -v records');
    }

    $copy_start = time();
    copy("dummy.$file_size.txt", "copied_with_php_copy.$file_size.txt");
    $copy_done = time();

    $cp_start = time();
    exec("cp dummy.$file_size.txt copied_with_cp.$file_size.txt");
    $cp_done = time();

    echo 'copy() took: '.($copy_done-$copy_start).'s'.PHP_EOL;
    echo 'cp took: '.($cp_done-$cp_start).'s'.PHP_EOL;

    echo 'Removing test files.'.PHP_EOL;
    if(isset($argv[1]) and $argv[1] == 'clean') {
        exec('rm -rf dummy.*.txt ');
    }
    exec('rm -rf copied_with_php_copy.*.txt copied_with_cp.*.txt');
    echo '----------------------------------------------------------------------'.PHP_EOL;
}

echo shell_exec('ls -al dummy.*.txt copied_with_php_copy.*.txt
copied_with_cp.*.txt').PHP_EOL;


Previous Comments:
------------------------------------------------------------------------
[2016-10-12 22:09:43] jeffreydwalter at gmail dot com

Thanks for the reply. I'm running FreeBSD 10.3 on a VM that's lacking resources, so
that's probably why I/O is slow. I have tried running my tests with many different file sizes
with the default buffer size and without. In very small file sizes both copy and exec(cp...) were
too fast to really tell anything useful. But, copy() is definitely several orders of magnitude
slower with larger files. As file size grows, the disparity does too.

If we could come up with a sane way of dynamically scaling the buffer, that would be cool. One
simplistic way to do that would be to step up the buffer in size as the number of writes passes
certain thresholds. That is to say, as we write x amount of data. This is a naive, but simple
approach that would keep the buffer small for smaller streams of data and large for larger streams
of data.

I did a little testing with this approach and it seems write speeds are relatively comparable below
10MB files (on this system). Once I get above 10MB, I start to see an increasing disparity between
the time copy() and exec('cp ...').

I'm attaching a patch that scales the stream->chunk_size = 8192*24 once 10MB has been read.
This gives relatively comparable performance between copy() and exec('cp ...'). This patch
does NOT contain the whole solution, as I believe there are several other places that would still
need to be modified.


I've updated the test program to run multiple tests on a range of file sizes. Here's a
sample of the test program output:

php blah.php (UNMODIFIED streams.c):

Generating 1MB dummy file.
1048576 bytes transferred in 0.017906 secs (58560197 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   1048576 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   1048576 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   1048576 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 2MB dummy file.
2097152 bytes transferred in 0.034607 secs (60599186 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   2097152 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   2097152 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   2097152 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 5MB dummy file.
5242880 bytes transferred in 0.084276 secs (62210860 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   5242880 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   5242880 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   5242880 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 10MB dummy file.
10485760 bytes transferred in 0.163251 secs (64230938 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   10485760 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   10485760 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   10485760 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 15MB dummy file.
15728640 bytes transferred in 0.247797 secs (63473889 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   15728640 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   15728640 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   15728640 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 19MB dummy file.
19922944 bytes transferred in 0.308225 secs (64637632 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   19922944 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   19922944 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   19922944 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 20MB dummy file.
20971520 bytes transferred in 0.324176 secs (64691758 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   20971520 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   20971520 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   20971520 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 50MB dummy file.
52428800 bytes transferred in 0.832661 secs (62965367 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   52428800 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   52428800 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   52428800 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 100MB dummy file.
104857600 bytes transferred in 1.651604 secs (63488345 bytes/sec)
copy() took: 2s
cp took: 0s
-rw-r--r--  1   104857600 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   104857600 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   104857600 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 250MB dummy file.
262144000 bytes transferred in 4.271219 secs (61374516 bytes/sec)
copy() took: 7s
cp took: 1s
-rw-r--r--  1   262144000 Oct 12 16:59 copied_with_cp.txt
-rw-r--r--  1   262144000 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   262144000 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 350MB dummy file.
367001600 bytes transferred in 5.770454 secs (63600127 bytes/sec)
copy() took: 10s
cp took: 0s
-rw-r--r--  1   367001600 Oct 12 16:59 copied_with_cp.txt
-rw-r--r--  1   367001600 Oct 12 16:59 copied_with_php_copy.txt
-rw-r--r--  1   367001600 Oct 12 16:59 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 400MB dummy file.
419430400 bytes transferred in 7.365670 secs (56943956 bytes/sec)
copy() took: 11s
cp took: 1s
-rw-r--r--  1   419430400 Oct 12 16:59 copied_with_cp.txt
-rw-r--r--  1   419430400 Oct 12 16:59 copied_with_php_copy.txt
-rw-r--r--  1   419430400 Oct 12 16:59 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 500MB dummy file.
524288000 bytes transferred in 8.256745 secs (63498145 bytes/sec)
copy() took: 14s
cp took: 1s
-rw-r--r--  1   524288000 Oct 12 16:59 copied_with_cp.txt
-rw-r--r--  1   524288000 Oct 12 16:59 copied_with_php_copy.txt
-rw-r--r--  1   524288000 Oct 12 16:59 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 1000MB dummy file.
1048576000 bytes transferred in 25.389519 secs (41299561 bytes/sec)
copy() took: 18s
cp took: 2s
-rw-r--r--  1   1048576000 Oct 12 17:00 copied_with_cp.txt
-rw-r--r--  1   1048576000 Oct 12 17:00 copied_with_php_copy.txt
-rw-r--r--  1   1048576000 Oct 12 17:00 dummy.txt

Removing test files.
----------------------------------------------------------------------



sapi/cli/php blah.php (MODIFIED streams.c): 

Generating 1MB dummy file.
1048576 bytes transferred in 0.018799 secs (55778089 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   1048576 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   1048576 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   1048576 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 2MB dummy file.
2097152 bytes transferred in 0.039626 secs (52923792 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   2097152 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   2097152 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   2097152 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 5MB dummy file.
5242880 bytes transferred in 0.088615 secs (59164582 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   5242880 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   5242880 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   5242880 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 10MB dummy file.
10485760 bytes transferred in 0.165203 secs (63471935 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   10485760 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   10485760 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   10485760 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 15MB dummy file.
15728640 bytes transferred in 0.253879 secs (61953334 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   15728640 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   15728640 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   15728640 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 19MB dummy file.
19922944 bytes transferred in 0.316122 secs (63022949 bytes/sec)
copy() took: 0s
cp took: 0s
-rw-r--r--  1   19922944 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   19922944 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   19922944 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 20MB dummy file.
20971520 bytes transferred in 0.326075 secs (64315004 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   20971520 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   20971520 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   20971520 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 50MB dummy file.
52428800 bytes transferred in 0.813434 secs (64453671 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   52428800 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   52428800 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   52428800 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 100MB dummy file.
104857600 bytes transferred in 1.612340 secs (65034423 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   104857600 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   104857600 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   104857600 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 250MB dummy file.
262144000 bytes transferred in 4.026581 secs (65103371 bytes/sec)
copy() took: 1s
cp took: 0s
-rw-r--r--  1   262144000 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   262144000 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   262144000 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 350MB dummy file.
367001600 bytes transferred in 5.656869 secs (64877162 bytes/sec)
copy() took: 1s
cp took: 1s
-rw-r--r--  1   367001600 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   367001600 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   367001600 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 400MB dummy file.
419430400 bytes transferred in 6.443685 secs (65091700 bytes/sec)
copy() took: 2s
cp took: 0s
-rw-r--r--  1   419430400 Oct 12 16:57 copied_with_cp.txt
-rw-r--r--  1   419430400 Oct 12 16:57 copied_with_php_copy.txt
-rw-r--r--  1   419430400 Oct 12 16:57 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 500MB dummy file.
524288000 bytes transferred in 8.896159 secs (58934199 bytes/sec)
copy() took: 2s
cp took: 1s
-rw-r--r--  1   524288000 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   524288000 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   524288000 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------
Generating 1000MB dummy file.
1048576000 bytes transferred in 16.196600 secs (64740501 bytes/sec)
copy() took: 6s
cp took: 3s
-rw-r--r--  1   1048576000 Oct 12 16:58 copied_with_cp.txt
-rw-r--r--  1   1048576000 Oct 12 16:58 copied_with_php_copy.txt
-rw-r--r--  1   1048576000 Oct 12 16:58 dummy.txt

Removing test files.
----------------------------------------------------------------------

------------------------------------------------------------------------


The remainder of the comments for this report are too long. To view
the rest of the comments, please view the bug report online at

    https://bugs.php.net/bug.php?id=73262


--
Edit this bug report at https://bugs.php.net/bug.php?id=73262&edit=1


Thread (7 messages)

« previous php.bugs (#204653) next »