minify icon indicating copy to clipboard operation
minify copied to clipboard

Bad performance on cloud servers

Open gwillem opened this issue 7 years ago • 7 comments

Am debugging performance issues with this library. Have pinpointed it down to a specific testcase (below) which produces wildly different results on different servers.

In the worst case, minifying a 1.5MB JS file takes nearly 2 minutes while the same operation takes 4 seconds and 12 seconds on different servers. The PHP version and module list (php -m) and OS (Ubuntu 16.04) is the same everywhere. The CPUs are comparable. Other load is negligible.

# php --version
PHP 7.0.22-0ubuntu0.16.04.1 (cli) ( NTS )
Copyright (c) 1997-2017 The PHP Group
Zend Engine v3.0.0, Copyright (c) 1998-2017 Zend Technologies
    with Zend OPcache v7.0.22-0ubuntu0.16.04.1, Copyright (c) 1999-2017, by Zend Technologies

# time php test.php 
real	1m47.851s
user	0m5.116s
sys	1m42.564s

Test results across different servers:

CPU Kernel Test-time (elapsed)
E5-2687W v4 @ 3.00GHz 4.4.0-87-generic 4s
E5-2687W v3 @ 3.10GHz 4.4.0-75-generic 1m47
AMD Ryzen 7 1700 4.4.0-101-generic 12s

One clue: for the test case that takes the longest, I took random stacktraces (using the FPM slow-log feature) at 5, 10 and 30 seconds. This would consistenly point to:

[0x00007fecd2015e70] substr() /public/vendor/matthiasmullie/minify/src/Minify.php:285
[0x00007fecd2015d00] replace() /public/vendor/matthiasmullie/minify/src/JS.php:637
[0x00007fecd2015c80] replace() /public/vendor/matthiasmullie/minify/src/JS.php:179

Another clue: the used system time is very high. I would expect this library to be mostly run in userspace, given the amount of substr and preg_replaces.

Reproduce test setup:

composer require matthiasmullie/minify
cat >test.php<<'EOM'
<?php
require_once 'vendor/autoload.php';
use MatthiasMullie\Minify;
$minifier = new Minify\JS('flarum.js');
$minifier->minify('flarum.min.js');
?>
EOM
wget https://www.freeflarum.com/flarum.js
time php test.php

gwillem avatar Dec 14 '17 21:12 gwillem

Rebooted the slow server with a newer kernel (4.4.0-103-generic) and now the problem is gone. Argh. Ok, closing this.

gwillem avatar Dec 14 '17 22:12 gwillem

Reopening this, as I see the same erratic delay on different servers/providers.

Sometimes the benchmark takes up to two minutes.

Possibly related, strace shows a high amount of mmap/munmap syscalls:

# egrep -c 'mmap|madvice|munmap' strace.log 
91479

Tested with PHP 7.0.22-0ubuntu0.16.04.1

Any ideas how to debug further?

gwillem avatar Dec 23 '17 19:12 gwillem

That's odd - I have no theory on why execution time could differ so wildly. Did you notice other similarities between the servers or providers where processing is this inefficient? Or any particular input where Minify.php:285 seems to be struggling with consistently?

matthiasmullie avatar Feb 02 '18 10:02 matthiasmullie

Thanks for your reply. Other than the reported architectures, I do not have any additional info. My hypothesis is that many small mmaps cause a significant overhead on cloud platforms. However, I didn't have the resources for further analysis, so I switched to the Golang minifier elsewhere on Github. Feel free to close this issue if nobody else reported it.

gwillem avatar Feb 03 '18 19:02 gwillem

I'm not sure if this could be related, but I have PHP Minify integrated on my wordpress plugin and I've seen reports from people, showing that the max execution time of 30 seconds has been exceeded on Minify.php line 323.

Unfortunately, they are not able to provide me with more info than that, but they say that an older version that uses PHP Minify 1.3.60 works fine.

peixotorms avatar Dec 13 '18 11:12 peixotorms

Same here. I've got max execution time error on line 255. I try to minify 10-12 files with weight ca. 1.7mb.

if (preg_match($pattern, $content, $match, PREG_OFFSET_CAPTURE)) {

sabat24 avatar Feb 07 '19 11:02 sabat24

I filed a seperate issue about CSS Minification (#280), but on the server that shows the issue for CSS minification, I can recreate the test script given here and see a massive slowdown, with the same feature as noted in the first comment, that the extra time seems spent in sys.

davidscotson avatar Apr 01 '19 11:04 davidscotson