php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #72720 PHP7: opcache.interned_strings_buffer = 8 crashs
Submitted: 2016-07-31 11:48 UTC Modified: 2016-08-01 12:21 UTC
From: spam2 at rhsoft dot net Assigned: laruence (profile)
Status: Not a bug Package: opcache
PHP Version: 7.0.9 OS: Linux
Private report: No CVE-ID: None
 [2016-07-31 11:48 UTC] spam2 at rhsoft dot net
Description:
------------
a hardened build of PHP7 with "opcache.interned_strings_buffer = 8" crashs terrible 

Sun Jul 31 13:40:26 2016 (11663): Fatal Error Zend OPcache cannot allocate buffer for interned strings

https://bugs.php.net/bug.php?id=70428 suggests there was something similar in the past, but with PHP 5.6 this problem don't exist the whole last year while PHP as mod_php crashs from beta to 7.0.9, i just gave up trying get the beta running a year ago with "hmm apache module obviously broken" and now started real testing of a migration
_______________________________________

optflags: x86_64 -m64 -O2 -g0 -march=sandybridge -mtune=sandybridge -mavx -fopenmp -mfpmath=sse -pipe -fno-strict-aliasing -fomit-frame-pointer -finline-functions -fexceptions -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security

export CFLAGS="%{optflags} -O3 -fPIC -funroll-loops -funswitch-loops -Wno-pointer-sign -minline-all-stringops"
export CXXFLAGS="$CFLAGS"
export LDFLAGS="-Wl,-z,now -Wl,-z,relro,-z,noexecstack -pie %{optflags} -O3 -funroll-loops -funswitch-loops -Wno-pointer-sign -minline-all-stringops"
export SH_LDFLAGS="-Wl,-z,now -Wl,-z,relro,-z,noexecstack %{optflags} -O3 -funroll-loops -funswitch-loops -Wno-pointer-sign -minline-all-stringops"
_______________________________________

open("/lib64/liblber-2.4.so.2", O_RDONLY|O_CLOEXEC) = 6
read(6, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p3\0\0\0\0\0\0"..., 832) = 832
fstat(6, {st_mode=S_IFREG|0755, st_size=60816, ...}) = 0
mmap(NULL, 2154984, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 6, 0) = 0x7f3137b9a000
mprotect(0x7f3137ba8000, 2093056, PROT_NONE) = 0
mmap(0x7f3137da7000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 6, 0xd000) = 0x7f3137da7000
close(6)                                = 0
open("/lib64/libldap-2.4.so.2", O_RDONLY|O_CLOEXEC) = 6
read(6, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\343\0\0\0\0\0\0"..., 832) = 832
fstat(6, {st_mode=S_IFREG|0755, st_size=333496, ...}) = 0
mmap(NULL, 2426232, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 6, 0) = 0x7f3137949000
mprotect(0x7f3137997000, 2093056, PROT_NONE) = 0
mmap(0x7f3137b96000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 6, 0x4d000) = 0x7f3137b96000
close(6)                                = 0
open("/lib64/libunistring.so.2", O_RDONLY|O_CLOEXEC) = 6
read(6, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\374\0\0\0\0\0\0"..., 832) = 832
fstat(6, {st_mode=S_IFREG|0755, st_size=1240184, ...}) = 0
mmap(NULL, 3338504, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 6, 0) = 0x7f3137619000
mprotect(0x7f3137744000, 2097152, PROT_NONE) = 0
mmap(0x7f3137944000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 6, 0x12b000) = 0x7f3137944000
mmap(0x7f3137948000, 264, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f3137948000
close(6)                                = 0
open("/lib64/libsasl2.so.3", O_RDONLY|O_CLOEXEC) = 6
read(6, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`H\0\0\0\0\0\0"..., 832) = 832
fstat(6, {st_mode=S_IFREG|0755, st_size=120136, ...}) = 0
mmap(NULL, 2213768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 6, 0) = 0x7f3136cdd000
mprotect(0x7f3136cf9000, 2093056, PROT_NONE) = 0
mmap(0x7f3136ef8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 6, 0x1b000) = 0x7f3136ef8000
close(6)                                = 0
mprotect(0x7f3136ef8000, 4096, PROT_READ) = 0
mprotect(0x7f3137944000, 12288, PROT_READ) = 0
mprotect(0x7f3137fe3000, 4096, PROT_READ) = 0
mprotect(0x7f31383ef000, 4096, PROT_READ) = 0
mprotect(0x7f31381eb000, 4096, PROT_READ) = 0
mprotect(0x7f3138617000, 28672, PROT_READ) = 0
mprotect(0x7f313893f000, 20480, PROT_READ) = 0
mprotect(0x7f3138db1000, 16384, PROT_READ) = 0
mprotect(0x7f3138b6b000, 12288, PROT_READ) = 0
mprotect(0x7f3137da7000, 4096, PROT_READ) = 0
mprotect(0x7f3137b96000, 12288, PROT_READ) = 0
mprotect(0x7f3139424000, 4096, PROT_READ) = 0
mprotect(0x7f3138fc2000, 4096, PROT_READ) = 0
mprotect(0x7f31391f0000, 4096, PROT_READ) = 0
mprotect(0x7f3139645000, 4096, PROT_READ) = 0
mprotect(0x7f313985c000, 4096, PROT_READ) = 0
mprotect(0x7f3139c8e000, 4096, PROT_READ) = 0
mprotect(0x7f313a115000, 12288, PROT_READ) = 0
mprotect(0x7f313a321000, 4096, PROT_READ) = 0
mprotect(0x7f313aacb000, 8192, PROT_READ) = 0
mprotect(0x7f313acfb000, 16384, PROT_READ) = 0
mprotect(0x7f313af27000, 4096, PROT_READ) = 0
mprotect(0x7f313b15a000, 8192, PROT_READ) = 0
mprotect(0x7f313bd1f000, 602112, PROT_READ) = 0
munmap(0x7f313b160000, 73824)           = 0
read(5, "", 4096)                       = 0
close(5)                                = 0
rt_sigaction(SIGSEGV, {0x561fab022810, [], SA_RESTORER|SA_RESETHAND, 0x7f313ec33c30}, NULL, 8) = 0
rt_sigaction(SIGBUS, {0x561fab022810, [], SA_RESTORER|SA_RESETHAND, 0x7f313ec33c30}, NULL, 8) = 0
rt_sigaction(SIGABRT, {0x561fab022810, [], SA_RESTORER|SA_RESETHAND, 0x7f313ec33c30}, NULL, 8) = 0
rt_sigaction(SIGILL, {0x561fab022810, [], SA_RESTORER|SA_RESETHAND, 0x7f313ec33c30}, NULL, 8) = 0
rt_sigaction(SIGFPE, {0x561fab022810, [], SA_RESTORER|SA_RESETHAND, 0x7f313ec33c30}, NULL, 8) = 0
chdir("/")                              = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f313f8bca90) = 11663
exit_group(0)                           = ?
+++ exited with 0 +++




Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2016-07-31 11:50 UTC] spam2 at rhsoft dot net
[zend]
zend_extension                            = "/usr/lib64/php/modules/opcache.so"
opcache.enable                            = 1
opcache.enable_cli                        = 0
opcache.load_comments                     = 0
opcache.save_comments                     = 0
opcache.use_cwd                           = 1
opcache.validate_timestamps               = 1
opcache.revalidate_freq                   = 15
opcache.revalidate_path                   = 0
opcache.max_accelerated_files             = 200
opcache.memory_consumption                = 16
opcache.max_file_size                     = 262144
opcache.enable_file_override              = 1
opcache.optimization_level                = 0xfffffbbf
opcache.fast_shutdown                     = 1
opcache.error_log                         = "/var/log/php_error.log"
opcache.log_verbosity_level               = 1
opcache.interned_strings_buffer           = 8
 [2016-07-31 13:23 UTC] nikic@php.net
-Status: Open +Status: Feedback
 [2016-07-31 13:23 UTC] nikic@php.net
When you say "crash", do you mean an actual crash (segfault or similar)? Your strace does not indicate a crash to me.

Or do you refer to that fatal error as a "crash"? If so, as the error message indicates, the SHM allocator failed to allocate an 8MB interned string buffer given a total 16MB SHM area. You should be able to resolve this by either decreasing the interned string buffer size or increasing the SHM size.

As to why that allocation fails, I can't tell at this point -- not familiar with what else gets allocated there this early on.
 [2016-07-31 13:33 UTC] spam2 at rhsoft dot net
with crash i just mean that the whole httpd crashs, long before you call any website and since with the identical environment including "php.ini" PHP 5.4/5.5/5.6 just works fine in production and PHP7.0 even don't start proper it's a regression

[root@testserver:~]$ cat messages
Jul 31 15:31:16 testserver systemd: Stopping Apache Webserver...
Jul 31 15:31:16 testserver systemd: Stopped Apache Webserver.
Jul 31 15:31:16 testserver systemd: Started Apache Webserver.
Jul 31 15:31:18 testserver systemd: httpd.service: Main process exited, code=exited, status=254/n/a
Jul 31 15:31:18 testserver systemd: httpd.service: Unit entered failed state.
Jul 31 15:31:18 testserver systemd: httpd.service: Failed with result 'exit-code'.
Jul 31 15:31:19 testserver systemd: httpd.service: Service hold-off time over, scheduling restart.
Jul 31 15:31:19 testserver systemd: Stopped Apache Webserver.
Jul 31 15:31:19 testserver systemd: Started Apache Webserver.
Jul 31 15:31:21 testserver systemd: httpd.service: Main process exited, code=exited, status=254/n/a
Jul 31 15:31:21 testserver systemd: httpd.service: Unit entered failed state.
Jul 31 15:31:21 testserver systemd: httpd.service: Failed with result 'exit-code'.
Jul 31 15:31:22 testserver systemd: httpd.service: Service hold-off time over, scheduling restart.
Jul 31 15:31:22 testserver systemd: Stopped Apache Webserver.
Jul 31 15:31:22 testserver systemd: Started Apache Webserver.
Jul 31 15:31:24 testserver systemd: httpd.service: Main process exited, code=exited, status=254/n/a
Jul 31 15:31:24 testserver systemd: httpd.service: Unit entered failed state.
Jul 31 15:31:24 testserver systemd: httpd.service: Failed with result 'exit-code'.
Jul 31 15:31:25 testserver systemd: httpd.service: Service hold-off time over, scheduling restart.
Jul 31 15:31:25 testserver systemd: Stopped Apache Webserver.
Jul 31 15:31:25 testserver systemd: Started Apache Webserver.
 [2016-07-31 14:49 UTC] nikic@php.net
-Status: Feedback +Status: Assigned -Assigned To: +Assigned To: laruence
 [2016-07-31 14:49 UTC] nikic@php.net
The reason why we fail to allocate an 8MB interned string buffer with 16MB SHM is that next to the 8MB buffer, we also allocate an ~9MB hashtable. The number of elements in the HT is computed as

    interned_strings_buffer * 1024 * 1024 / (sizeof(Bucket) + sizeof(Bucket*) + 8 /* average string length */)

This expression doesn't make a whole lot of sense, it's likely a leftover from the previous implementation. More reasonable would be

    interned_strings_buffer * 1024 * 1024 / _ZSTR_STRUCT_SIZE(8 /* average string length */)

This is more semantically accurate, but does not solve the problem of too much memory being allocated. (I also wonder if that average is still current.)

@laruence: What do you think, should this code be changed so that interned_string_buffer is (approximately) the size of the hashtable and the string buffer *combined*? A good approximation would be to cut the specified size in half before going the allocations, as the HT takes about as much memory as the buffer.
 [2016-08-01 04:40 UTC] laruence@php.net
@nikic 

I think use  _ZSTR_STRUCT_SIZE(8 /* average string length */) is better.

@spma2, the new implementation of interned_strings in opcache, requires more memory than 5.6, thus that makes 16M/8M is not enough. 

I don't think this is a regression,  you should increase opcache.memory_consumption, or decrease opcache.interned_strings_buffer

thanks
 [2016-08-01 12:20 UTC] laruence@php.net
-Status: Assigned +Status: Not a bug
 [2016-08-01 12:20 UTC] laruence@php.net
Thank you for taking the time to write to us, but this is not
a bug. Please double-check the documentation available at
http://www.php.net/manual/ and the instructions on how to report
a bug at http://bugs.php.net/how-to-report.php


 [2016-08-01 12:21 UTC] laruence@php.net
@nikic your idea is committed here: https://github.com/php/php-src/commit/f93061471b5541525a39821da70b674b830284df

thanks ;)
 
PHP Copyright © 2001-2020 The PHP Group
All rights reserved.
Last updated: Fri Aug 14 21:01:24 2020 UTC