php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #76867 Extremely slow performance
Submitted: 2018-09-12 08:11 UTC Modified: 2019-05-09 08:40 UTC
Votes:2
Avg. Score:4.0 ± 1.0
Reproduced:1 of 2 (50.0%)
Same Version:1 (100.0%)
Same OS:0 (0.0%)
From: ivokund at gmail dot com Assigned:
Status: Open Package: Performance problem
PHP Version: 7.2.9 OS: Ubuntu 18.04.1 LTS
Private report: No CVE-ID: None
Have you experienced this issue?
Rate the importance of this bug to you:

 [2018-09-12 08:11 UTC] ivokund at gmail dot com
Description:
------------
Both CLI and web requests are extremely slow. The smallest isolated example I can think of is below. The slow time varies apparently by random.

Test script:
---------------
No problem here:
___________________________
time php -n --version
PHP 7.2.9-1+ubuntu18.04.1+deb.sury.org+1 (cli) (built: Aug 19 2018 07:16:54) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies

real    0m0,009s
user    0m0,004s
sys     0m0,004s


Second try half a second later takes 8 sec
____________________________
time php -n --version
PHP 7.2.9-1+ubuntu18.04.1+deb.sury.org+1 (cli) (built: Aug 19 2018 07:16:54) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies

real    0m8,440s
user    0m0,001s
sys     0m0,264s




Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2018-09-12 08:24 UTC] spam2 at rhsoft dot net
very unlikely a php problem

look at your system load and check if the machine runs out of random (google for haveged)
 [2018-09-12 08:29 UTC] requinix@php.net
-Status: Open +Status: Feedback
 [2018-09-12 08:29 UTC] requinix@php.net
Simply saying it's slow doesn't help us identify the problem, let alone fix it.
If you can reproduce it on the command line then it shouldn't be hard to trace the process to see where the time is being spent.
 [2018-09-12 08:36 UTC] ivokund at gmail dot com
-Status: Feedback +Status: Open
 [2018-09-12 08:36 UTC] ivokund at gmail dot com
Sure! Any ideas on what to look for or what approach to use are welcome!
I'll do some more investigation.
 [2018-09-12 08:38 UTC] spam2 at rhsoft dot net
[root@rh:~]$ strace php -v
execve("/usr/bin/php", ["php", "-v"], 0x7ffd1f12fe58 /* 32 vars */) = 0
brk(NULL)                               = 0x55ef8e731000
brk(0x55ef8e731026)                     = 0x55ef8e731026
brk(NULL)                               = 0x55ef8e731026
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=111591, ...}) = 0
mmap(NULL, 111591, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f89b25eb000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0Pb\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=154128, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89b25e9000
mmap(NULL, 2221184, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f89b21c2000
mprotect(0x7f89b21db000, 2097152, PROT_NONE) = 0
mmap(0x7f89b23db000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7f89b23db000
mmap(0x7f89b23dd000, 13440, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f89b23dd000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@8\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=98144, ...}) = 0
mmap(NULL, 2189952, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f89b1fab000
mprotect(0x7f89b1fbe000, 2097152, PROT_NONE) = 0
................
 [2018-09-12 08:40 UTC] requinix@php.net
-Status: Open +Status: Feedback
 [2018-09-12 08:40 UTC] requinix@php.net
My go-to tool is strace. Tee the (preferably timestamp-prefixed) output to a log you can review, but when it's running you can watch the output go past and it should be obvious when it stalls.
 [2018-09-12 08:40 UTC] ivokund at gmail dot com
-Status: Feedback +Status: Open
 [2018-09-12 08:40 UTC] ivokund at gmail dot com
Ok, strace seems to tell me that process seems to hang at:

madvise(0x7f70efe00000, 2097152, MADV_HUGEPAGE) = 0

Any ideas?
Thanks!
 [2018-09-12 13:33 UTC] sjon at hortensius dot net
Huge pages should be disabled by default, see also #70984 Did you or your distro enable it? Can you try with USE_ZEND_ALLOC_HUGE_PAGES=0
 [2018-09-13 06:22 UTC] ivokund at gmail dot com
The manifestation of this problem apparently also varies daily, as I'm having trouble reproducing it today (although, there have been no reboots). 

I'll continue debugging as soon as the problem returns and will get back to you. 

Thanks for your help so far!
 [2018-09-13 15:02 UTC] ivokund at gmail dot com
Ok, got some new information. This is the first time I hear about huge pages, so pretty sure, I haven't configured anything on purpose.

Setting USE_ZEND_ALLOC_HUGE_PAGES=0 in environment does not seem to have any effect.

_______________

$ export USE_ZEND_ALLOC_HUGE_PAGES=0
$ echo $USE_ZEND_ALLOC_HUGE_PAGES
0
$ time php -n --version
PHP 7.2.9-1+ubuntu18.04.1+deb.sury.org+1 (cli) (built: Aug 19 2018 07:16:54) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies

real    0m10,453s
user    0m0,049s
sys     0m0,024s

_______________

Here is a complete output from "strace php -n --version" with USE_ZEND_ALLOC_HUGE_PAGES=0

https://pastebin.com/raw/Cnmvarqd


Any further ideas would be greatly appreciated!
 [2018-09-13 15:17 UTC] requinix@php.net
I don't believe USE_ZEND_ALLOC_HUGE_PAGES will control PHP's use of madvise. Try disabling transparent huge pages in your kernel.
 [2018-09-13 15:52 UTC] ivokund at gmail dot com
I disabled huge pages with "hugeadm --thp-never" and the problem disappeared instantly. I'm happy now, so if this is not a PHP issue then please close the issue.

Thanks for your help everyone!
 [2018-09-20 12:51 UTC] lyrixx at lyrixx dot info
Hello,

I got the same problem. I don't know why since I just update PHP to 7.2.10

Anyway, I executed `hugeadm --thp-never` and the issue seems to be fixed.
 [2018-09-20 12:57 UTC] spam2 at rhsoft dot net
i don't get the impact completly

huge pages are assumed to be faster and PHP also has --enable-huge-code-pages for opcache - would it be better to change that also to --disable-huge-code-pages while not sure if that is using transparent or "dedicated" huge-pages which won't work anyways without epxlicit admin dance (see mysql and huge pages)
 [2018-10-03 08:53 UTC] sjon at hortensius dot net
@requinix - USE_ZEND_ALLOC_HUGE_PAGES should control Zend's core allocation, see https://github.com/php/php-src/commit/945a661912612cdecd221cd126feda7d4335c33c. Since that doesn't work, this issue might be caused by the opcache which has a separate setting (opcache.enable_huge_code_pages), see https://github.com/php/php-src/commit/669f0b39b184593e01e677360fd79b2b63058ca0

@rhsoft - while hugepages are faster, misses are costly (again, see https://bugs.php.net/70984 )
 [2019-05-09 08:21 UTC] nivetha0728 at gmail dot com
Get the PHP support
 [2019-05-09 08:40 UTC] nikic@php.net
We changed USE_ZEND_ALLOC_HUGE_PAGES to control the use of transparent huge pages as well at some point (it's disabled by default now), so I'm closing this issue.
 
PHP Copyright © 2001-2019 The PHP Group
All rights reserved.
Last updated: Fri Nov 22 04:01:26 2019 UTC