Bug #77653 [Asn]: php-fpm, operator displayed instead of the real error message

Edit report at https://bugs.php.net/bug.php?id=77653&edit=1 ID: 77653 User updated by: claudiu_beta at yahoo dot com Reported by: claudiu_beta at yahoo dot com Summary: php-fpm, operator displayed instead of the real error message Status: Assigned Type: Bug Package: FPM related Operating System: Fedora 29 PHP Version: 7.3.3RC1 Assigned To: bukka Block user comment: N Private report: N New Comment: error_reporting = E_ALL & ~E_NOTICE & ~E_DEPRECATED Previous Comments: ------------------------------------------------------------------------ [2019-02-24 16:38:00] claudiu_beta at yahoo dot com I'm running multiple php versions using software collection from Remi repo. Similar configuration for all versions. I only have issues with 7.3. Installed packages ------------------------- php73-php-debuginfo-7.3.1~RC1-1.fc28.remi.x86_64 php73-php-mbstring-7.3.3~RC1-1.fc29.remi.x86_64 php73-runtime-2.0-1.fc29.remi.x86_64 php73-2.0-1.fc29.remi.x86_64 php73-php-gmp-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-xmlrpc-7.3.3~RC1-1.fc29.remi.x86_64 php73-build-2.0-1.fc29.remi.x86_64 php73-php-mysqlnd-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-fpm-debuginfo-7.3.1~RC1-1.fc28.remi.x86_64 php73-php-process-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-bcmath-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-soap-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-pecl-msgpack-2.0.3-1.fc29.remi.x86_64 php73-php-pecl-imagick-3.4.3-13.fc29.remi.x86_64 php73-php-pecl-igbinary-3.0.0-1.fc29.remi.x86_64 php73-php-common-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-intl-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-pear-1.10.8-1.fc29.remi.noarch php73-php-ioncube-loader-10.3.2-1.fc29.remi.x86_64 php73-php-pecl-zip-1.15.4-1.fc29.remi.x86_64 php73-php-cli-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-json-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-imap-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-pdo-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-fpm-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-pecl-memcached-3.1.3-1.fc29.remi.x86_64 php73-php-xml-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-devel-7.3.3~RC1-1.fc29.remi.x86_64 php73-php-gd-7.3.3~RC1-1.fc29.remi.x86_64 php-fpm.conf ------------------ include=/etc/opt/remi/php73/php-fpm.d/*.conf [global] pid = /var/opt/remi/php73/run/php-fpm/php-fpm.pid error_log = /var/log/php-fpm/master73.log syslog.ident = php-fpm73 daemonize = yes rlimit_files = 30000 ------------------------------------ And a pool. ------------ [poolname] user = apache group = apache listen = /var/opt/remi/php73/run/php-fpm/pool.sock listen.acl_users = apache listen.allowed_clients = 127.0.0.1 pm = ondemand pm.max_children = 20 pm.process_idle_timeout = 5s pm.max_requests = 40 pm.status_path = /fpmstats slowlog = /var/log/php-fpm/www-slow.log request_slowlog_timeout = 200 request_terminate_timeout = 203 chdir = /home/user catch_workers_output = yes security.limit_extensions = .php .phtml .phar php_admin_value[doc_root] = "/home/user" ============================================ For grep I must add -a, because that ^Q visible in console is binary content. grep -a stderr /var/log/php-fpm/master73.log ------------------ [22-Feb-2019 04:56:01] WARNING: [pool poolA] child 9662 said into stderr: "^@" [22-Feb-2019 04:57:01] WARNING: [pool poolA] child 9963 said into stderr: "^@" [22-Feb-2019 04:57:59] WARNING: [pool poolA] child 10262 said into stderr: "^@" [22-Feb-2019 05:01:02] WARNING: [pool poolA] child 11205 said into stderr: "^@" [22-Feb-2019 05:04:01] WARNING: [pool poolA] child 12168 said into stderr: "^@" [22-Feb-2019 05:17:00] WARNING: [pool poolA] child 17024 said into stderr: "^@" [22-Feb-2019 05:18:02] WARNING: [pool poolA] child 17347 said into stderr: "^@" [22-Feb-2019 05:23:00] WARNING: [pool poolA] child 19405 said into stderr: "^@" [22-Feb-2019 05:28:01] WARNING: [pool poolA] child 21458 said into stderr: "^@" [22-Feb-2019 05:46:01] WARNING: [pool poolA] child 28293 said into stderr: "^@" [22-Feb-2019 05:48:00] WARNING: [pool poolA] child 29068 said into stderr: "^@" [22-Feb-2019 05:50:59] WARNING: [pool poolA] child 30215 said into stderr: "^@" [22-Feb-2019 05:53:02] WARNING: [pool poolA] child 31052 said into stderr: "^@" [21-Feb-2019 14:19:58] WARNING: [pool poolB] child 9011 said into stderr: "ERROR: Unable to open primary script: /home/user/index.php (Permission denied)" [21-Feb-2019 15:23:34] WARNING: [pool poolC] child 4159 said into stderr: "^@" [21-Feb-2019 15:25:52] WARNING: [pool poolC] child 5151 said into stderr: "^@" [22-Feb-2019 03:34:08] WARNING: [pool poolC] child 11060 said into stderr: "^@" [22-Feb-2019 03:56:00] WARNING: [pool poolA] child 19510 said into stderr: "^@" [22-Feb-2019 04:16:01] WARNING: [pool poolA] child 26999 said into stderr: "^@" [22-Feb-2019 04:18:00] WARNING: [pool poolA] child 27707 said into stderr: "^@" [22-Feb-2019 04:30:00] WARNING: [pool poolA] child 32308 said into stderr: "^@" [22-Feb-2019 04:34:01] WARNING: [pool poolA] child 1579 said into stderr: "^@" [22-Feb-2019 04:46:02] WARNING: [pool poolA] child 6239 said into stderr: "^@" [22-Feb-2019 04:51:01] WARNING: [pool poolA] child 8030 said into stderr: "^@" [22-Feb-2019 04:56:01] WARNING: [pool poolA] child 9662 said into stderr: "^@" [22-Feb-2019 04:57:01] WARNING: [pool poolA] child 9963 said into stderr: "^@" [22-Feb-2019 04:57:59] WARNING: [pool poolA] child 10262 said into stderr: "^@" [22-Feb-2019 05:01:02] WARNING: [pool poolA] child 11205 said into stderr: "^@" [22-Feb-2019 05:04:01] WARNING: [pool poolA] child 12168 said into stderr: "^@" [22-Feb-2019 05:17:00] WARNING: [pool poolA] child 17024 said into stderr: "^@" [22-Feb-2019 05:18:02] WARNING: [pool poolA] child 17347 said into stderr: "^@" [22-Feb-2019 05:23:00] WARNING: [pool poolA] child 19405 said into stderr: "^@" [22-Feb-2019 05:28:01] WARNING: [pool poolA] child 21458 said into stderr: "^@" [22-Feb-2019 05:46:01] WARNING: [pool poolA] child 28293 said into stderr: "^@" [22-Feb-2019 05:48:00] WARNING: [pool poolA] child 29068 said into stderr: "^@" [22-Feb-2019 05:50:59] WARNING: [pool poolA] child 30215 said into stderr: "^@" [22-Feb-2019 05:53:02] WARNING: [pool poolA] child 31052 said into stderr: "^@" [22-Feb-2019 05:56:02] WARNING: [pool poolA] child 31911 said into stderr: "^@" [22-Feb-2019 05:58:01] WARNING: [pool poolA] child 32449 said into stderr: "^@" [22-Feb-2019 06:02:59] WARNING: [pool poolA] child 1854 said into stderr: "^@" [22-Feb-2019 06:05:01] WARNING: [pool poolA] child 2804 said into stderr: "^@" [22-Feb-2019 06:15:01] WARNING: [pool poolA] child 6377 said into stderr: "^@" [22-Feb-2019 06:20:02] WARNING: [pool poolA] child 8086 said into stderr: "^@" [22-Feb-2019 06:23:01] WARNING: [pool poolA] child 9356 said into stderr: "^@" [22-Feb-2019 06:44:02] WARNING: [pool poolA] child 17610 said into stderr: "^@" [22-Feb-2019 06:50:02] WARNING: [pool poolA] child 19670 said into stderr: "^@" [22-Feb-2019 06:55:01] WARNING: [pool poolA] child 21604 said into stderr: "^@" [22-Feb-2019 07:00:01] WARNING: [pool poolA] child 23429 said into stderr: "^@" [22-Feb-2019 07:04:01] WARNING: [pool poolA] child 25114 said into stderr: "^@" [22-Feb-2019 07:06:01] WARNING: [pool poolA] child 25821 said into stderr: "^@" [22-Feb-2019 07:07:01] WARNING: [pool poolA] child 26061 said into stderr: "^@" [22-Feb-2019 07:08:00] WARNING: [pool poolA] child 26293 said into stderr: "^@" [22-Feb-2019 07:13:02] WARNING: [pool poolA] child 27602 said into stderr: "^@" [22-Feb-2019 07:23:02] WARNING: [pool poolA] child 30443 said into stderr: "^@" [22-Feb-2019 07:24:03] WARNING: [pool poolA] child 30788 said into stderr: "^@" [22-Feb-2019 07:26:02] WARNING: [pool poolA] child 31286 said into stderr: "^@" [22-Feb-2019 07:34:00] WARNING: [pool poolA] child 1427 said into stderr: "^@" [22-Feb-2019 07:35:00] WARNING: [pool poolA] child 1686 said into stderr: "^@" [22-Feb-2019 07:36:02] WARNING: [pool poolA] child 2044 said into stderr: "^@" [22-Feb-2019 07:43:02] WARNING: [pool poolA] child 3962 said into stderr: "^@" [22-Feb-2019 07:44:01] WARNING: [pool poolA] child 4216 said into stderr: "^@" [22-Feb-2019 07:54:01] WARNING: [pool poolA] child 7335 said into stderr: "^@" [22-Feb-2019 07:57:01] WARNING: [pool poolA] child 8178 said into stderr: "^@" [22-Feb-2019 08:05:01] WARNING: [pool poolA] child 10447 said into stderr: "^@" [22-Feb-2019 08:06:01] WARNING: [pool poolA] child 10816 said into stderr: "^@" [22-Feb-2019 08:09:01] WARNING: [pool poolA] child 11720 said into stderr: "^@" [22-Feb-2019 08:11:05] WARNING: [pool poolA] child 12570 said into stderr: "^@" [22-Feb-2019 08:17:00] WARNING: [pool poolA] child 14056 said into stderr: "^@" [22-Feb-2019 08:25:00] WARNING: [pool poolA] child 16595 said into stderr: "^@" [22-Feb-2019 08:28:01] WARNING: [pool poolA] child 17291 said into stderr: "^@" [22-Feb-2019 08:29:00] WARNING: [pool poolA] child 17527 said into stderr: "^@" [22-Feb-2019 08:49:01] WARNING: [pool poolA] child 22856 said into stderr: "^@" [22-Feb-2019 08:52:02] WARNING: [pool poolA] child 23818 said into stderr: "^@" [22-Feb-2019 08:54:01] WARNING: [pool poolA] child 24670 said into stderr: "^@" [22-Feb-2019 09:00:01] WARNING: [pool poolA] child 26495 said into stderr: "^@" [22-Feb-2019 09:03:00] WARNING: [pool poolA] child 27733 said into stderr: "^@" [23-Feb-2019 14:34:34] WARNING: [pool poolB] child 32366 said into stderr: "ERROR: Unable to open primary script: /home/user/index.php (Permission denied)" [24-Feb-2019 01:17:10] WARNING: [pool poolB] child 13089 said into stderr: "ERROR: Unable to open primary script: /home/user/index.php (Permission denied)" [24-Feb-2019 08:27:13] WARNING: [pool poolB] child 9651 said into stderr: "ERROR: Unable to open primary script: /home/user/index.php (Permission denied)" [24-Feb-2019 17:53:02] WARNING: [pool poolB] child 30341 said into stderr: "ERROR: Unable to open primary script: /home/user/index.php (Permission denied)" ================================= Probably my "working" example including "Unable to open primary script:" was not a good one, because in this case error seems to be displayed correctly. Other errors are not displayed. ------------------------------------------------------------------------ [2019-02-24 15:48:03] bukka@php.net I just tested the "Unable to open primary script" by removing read permission for the primary script and it works fine for me with 7.3. I got fallowing: [24-Feb-2019 15:38:41] WARNING: [pool unconfined] child 28113 said into stderr: "NOTICE: PHP message: PHP Warning: Unknown: failed to open stream: Permission denied in Unknown on line 0" [24-Feb-2019 15:38:41] WARNING: [pool unconfined] child 28113 said into stderr: "Unknown(0) : Warning - Unknown: failed to open stream: Permission denied" [24-Feb-2019 15:38:41] WARNING: [pool unconfined] child 28113 said into stderr: "ERROR: Unable to open primary script: /home/jakub/prog/php/tests/fpm/log-no-script/test.php (Permission denied)" It means I need a bit more info from you. Could you pls paste your fpm config. Does it happen for all logged messages from the worker or is it just for some entries. Also can you add a bit more info about the app and what's being logged. ------------------------------------------------------------------------ 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=77653 -- Edit this bug report at https://bugs.php.net/bug.php?id=77653&edit=1