php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #61415 zend_alter_ini_entry failuers
Submitted: 2012-03-16 11:38 UTC Modified: 2021-05-30 04:22 UTC
From: info at simonecaruso dot com Assigned: cmb (profile)
Status: No Feedback Package: Safe Mode/open_basedir
PHP Version: 5.3.10 OS: Linux
Private report: No CVE-ID: None
 [2012-03-16 11:38 UTC] info at simonecaruso dot com
Description:
------------
I wrote an apache2.2 module that changs open_basedir and php_includepath 
dynamically into translatename hook with zend_alter_ini_entry.

This works perfectly but for about 5% of requests i get a PHP Warning with a 
wrong open_basedir.

From my debug logs i get a FAILURE on zend_alter_ini_entry("open_basedir",...)
with the rate of about 5 requests over 100; this never happen for 'includepath' 
ini entry. For any call to zend_alter_ini_entry i submit always the same string 
for each virtualhost, i can't understand why the function output change without 
a input values change.

(gdb) bt full
#0  zend_alter_ini_entry_ex (name=0x7fff3913b4b0 "ø>\026\002", name_length=1, 
new_value=0x7fea30fa4250 "/home/www-data/gamerinside.it/html/",
    new_value_length=957592432, modify_type=31715296, stage=32746, 
force_change=0) at /root/php53/php-5.3.3/Zend/zend_ini.c:254
        ini_entry = (zend_ini_entry *) 0x7fea30fa40e8
        modified = 224 'à'
#1  0x00007fea2a670530 in zend_alter_ini_entry (name=0x7fea290e3f39 
"open_basedir", name_length=13,
    new_value=0x23e89e8 "/tmp/:/usr/share/php/:.:/home/www-
data/gamerinside.it/html/", new_value_length=59, modify_type=4, stage=16)
    at /root/php53/php-5.3.3/Zend/zend_ini.c:249
No locals.
#2  0x00007fea290e29d0 in mod_vhost_ldap_translate_name (r=0x23e71c8) at 
mod_vhost_ldap_ng.c:862
        reqc = (mod_vhost_ldap_request_t *) 0x7fea30fa4070
        conf = (mod_vhost_ldap_config_t *) 0x1d047f8
        core = (core_server_config *) 0x1e3e680
        ld = (LDAP *) 0x0
        realfile = 0x0
        alias = (alias_t *) 0x0
        i = 0
        ret = 0
        str = {0x0, 0x0, 0x0}
        ldapmsg = (LDAPMessage *) 0x0
        vhostentry = (LDAPMessage *) 0x0
        openbasedir = 0x23e89e8 "/tmp/:/usr/share/php/:.:/home/www-
data/gamerinside.it/html/"
        include = 0x23e89a8 "/tmp/:/usr/share/php/:.:/home/www-
data/gamerinside.it/html/"
#3  0x0000000000433de3 in ap_run_translate_name ()
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#4  0x000000000043601e in ap_process_request_internal ()
No symbol table info available.
#5  0x0000000000449718 in ap_process_request ()
No symbol table info available.
#6  0x0000000000446858 in ?? ()
No symbol table info available.
#7  0x0000000000440493 in ap_run_process_connection ()

Actual result:
--------------
if(zend_alter_ini_entry("open_basedir", strlen("open_basedir") + 1,
        (void *)openbasedir, strlen(openbasedir), PHP_INI_SYSTEM, 
PHP_INI_STAGE_RUNTIME) != 0)
ap_log_rerror(APLOG_MARK, APLOG_ERR|APLOG_NOERRNO, 0, r, "zend_alter_ini_entry 
failed, open_basedir: %s", openbasedir);
ap_log_rerror(APLOG_MARK, APLOG_INFO|APLOG_NOERRNO, 0, r, "PhpIncludePath: %s, 
PhpOpenBasedir %s", include, openbasedir);
[Fri Mar 16 00:00:47 2012] [error] [client 2.38.136.113] zend_alter_ini_entry 
failed, open_basedir: /tmp/:/usr/share/php/:.:/home/www-data/pescasud.it/html/, 
referer: http://pescasud.it/CacciaSud/administrator/index.php?
option=com_modules&view=module&layout=edit&id=117
[Fri Mar 16 00:00:47 2012] [info] [client 2.38.136.113] PhpIncludePath: 
/tmp/:/usr/share/php/:.:/home/www-data/pescasud.it/html/, PhpOpenBasedir 
/tmp/:/usr/share/php/:.:/home/www-data/pescasud.it/html/, referer: 
http://pescasud.it/CacciaSud/administrator/index.php?
option=com_modules&view=module&layout=edit&id=117

Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2012-03-16 14:25 UTC] cataphract@php.net
-Status: Open +Status: Feedback
 [2012-03-16 14:25 UTC] cataphract@php.net
zend_alter_ini_entry_ex has several failure paths. It would be helpful to know which one is being triggered. Can you investigate this? You can try first by starting apache under gdb with the -X option.
 [2012-03-16 15:59 UTC] info at simonecaruso dot com
It will take some time for me to debug into php code, even because the problem 
happen only on the ~5% of requests, my users notice the problem only with my 
server are under load.

For now, I can add this: we have this problem since migrated from 5.2.6 to 5.3.10.
 [2012-03-16 18:07 UTC] info at simonecaruso dot com
It breaks always at zend_ini.c:300

The data i pass is always correct, but sometimes i get a FAILURE.

Breakpoint 3, zend_alter_ini_entry_ex (name=0x7f2de6128199 "open_basedir", 
name_length=13,
    new_value=0x7f2debd02e48 "/tmp/:/usr/share/php/:.:/home/www-
data/musitalia.com/html/", new_value_length=58, modify_type=4, 
stage=16, 
force_change=0)
    at /root/php-5.3.10/Zend/zend_ini.c:300
300                     return FAILURE;
(gdb) bt full
#0  zend_alter_ini_entry_ex (name=0x7f2de6128199 "open_basedir", name_length=13,
    new_value=0x7f2debd02e48 "/tmp/:/usr/share/php/:.:/home/www-
data/musitalia.com/html/", new_value_length=58, modify_type=4, 
stage=16, 
force_change=0)
    at /root/php-5.3.10/Zend/zend_ini.c:300
        ini_entry = 0x7f2debb35d30
        duplicate = 0x7f2debaf3140 'Z' <repeats 59 times>, "N\230D\300ZQ\twe-
\177"
        modifiable = 7 '\a'
        modified = 1 '\001'
#1  0x00007f2de77f00d0 in zend_alter_ini_entry (name=0x7f2de6128199 
"open_basedir", name_length=13,
    new_value=0x7f2debd02e48 "/tmp/:/usr/share/php/:.:/home/www-
data/musitalia.com/html/", new_value_length=58, modify_type=4, 
stage=16)
    at /root/php-5.3.10/Zend/zend_ini.c:249
No locals.
#2  0x00007f2de6126c1d in mod_vhost_ldap_translate_name (r=0x7f2debd01570) at 
mod_vhost_ldap_ng.c:862
        reqc = 0x7f2deb4b0510
        conf = 0x7f2deba31038
        core = 0x7f2deb9695e8
        ld = 0x0
        realfile = 0x0
        alias = 0x0
        i = 0
        ret = 0
        str = {0x0, 0x0, 0x0}
        ldapmsg = 0x0
        vhostentry = 0x0
        openbasedir = 0x7f2debd02e48 "/tmp/:/usr/share/php/:.:/home/www-
data/musitalia.com/html/"
        include = 0x7f2debd02e08 "/tmp/:/usr/share/php/:.:/home/www-
data/musitalia.com/html/"
 [2012-03-16 18:07 UTC] info at simonecaruso dot com
-Status: Feedback +Status: Open
 [2012-03-16 21:41 UTC] cataphract@php.net
I assume you're using the prefork SAPI, as the stack trace shows you're not using ZTS. In that case, I find strange your claim this is a concurrency issue. More likely, the problem would be in your module and I don't know anything about Apache modules lifecycle to even guess where the problem could be.

You could try passing another value for stage as the ini update handler for open_basedir can never fail for stages PHP_INI_STAGE_STARTUP, PHP_INI_STAGE_SHUTDOWN, PHP_INI_STAGE_ACTIVATE,PHP_INI_STAGE_DEACTIVATE, but this would most likely just mask the underlying problem. You can also try running Apache under valgrind with --trace-children and see if you get something.
 [2012-03-16 23:27 UTC] info at simonecaruso dot com
I don't think it's a my  module problem because with 5.2 i dont have this problem 
(i did the sames tests for 5.3, same apache, same config), i moved to 5.3 from less 
than one month. I don't think it's a concurrency related issue too, the failure are 
too much rare i think.

I did a diff between 5.2 and 5.3 and saw there are major changes to 
fopen_wrapper.c, and i have this problem only for open_basedir, that's why i opened 
the bug.

I'll try with other stages in the hope this can help.
 [2012-03-17 18:43 UTC] cataphract@php.net
The fact it worked in 5.2 doesn't imply your code had no bug. It may mean that a bug has always existed, but by luck it wasn't triggered by 5.2. Of course, if you could identify the specific commit that triggers the problem, it could shed light on this problem. If you can automate the tests, you can easily run something a bisection procedure to find such commit.
 [2012-03-19 11:18 UTC] info at simonecaruso dot com
I really would like debug php and find what's wrong.

For now i moved from PHP_INI_STAGE_RUNTIME to PHP_INI_STAGE_ACTIVATE and the 
problem disappeared.

But now i get this in logs when apache stops:
[]/Zend/zend_ini.c(278) :  Freeing 0x7F63E5BB4908 (72 bytes), script=/home/www-
data/mesogeamag.it/html/index.php
[]/Zend/zend_ini.c(279) :  Freeing 0x7F63E5BB49A8 (64 bytes), script=/home/www-
data/mesogeamag.it/html/index.php
[]/Zend/zend_alloc.c(2454) : Actual location (location was relayed)
[]/Zend/zend_hash.c(250) :  Freeing 0x7F63E5BB4A40 (84 bytes), script=/home/www-
data/mesogeamag.it/html/index.php
[]/Zend/zend_ini.c(289) :  Freeing 0x7F63E5BB4AE8 (64 bytes), script=/home/www-
data/mesogeamag.it/html/index.php


Thank you for help
 [2021-05-20 15:24 UTC] cmb@php.net
-Status: Open +Status: Feedback -Assigned To: +Assigned To: cmb
 [2021-05-20 15:24 UTC] cmb@php.net
Is this still an issue with any of the actively supported PHP
versions[1]?

[1] <https://www.php.net/supported-versions.php>
 [2021-05-30 04:22 UTC] php-bugs at lists dot php dot net
No feedback was provided. The bug is being suspended because
we assume that you are no longer experiencing the problem.
If this is not the case and you are able to provide the
information that was requested earlier, please do so and
change the status of the bug back to "Re-Opened". Thank you.
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Wed Dec 11 16:01:28 2024 UTC