Hi,
some days ago Squid proxy began to crash periodically (NOT every day) somewhere about after 1 AM with next entries in cache.log:
2016/08/24 00:01:11 kid1| WARNING: basicauthenticator #Hlpr1334 exited
2016/08/24 00:01:11 kid1| Too few basicauthenticator processes are running (need 1/20)
2016/08/24 00:01:11 kid1| Starting new helpers
2016/08/24 00:01:11 kid1| helperOpenServers: Starting 1/20 'squid.auth-user.php' processes
2016/08/24 00:01:12 kid1| helperHandleRead: unexpected read from basicauthenticator #Hlpr1335, 325 bytes '
Warning: require_once(script/load_phalcon.php): failed to open stream: No such file or directory in /usr/local/etc/inc/legacy_bindings.inc on line 30
Fatal error: require_once(): Failed opening required 'script/load_phalcon.php' (include_path='.:/usr/local/share/pear') in /usr/local/etc/inc/legacy_bindings.inc on line 30
'
2016/08/24 00:01:12 kid1| WARNING: basicauthenticator #Hlpr1335 exited
2016/08/24 00:01:12 kid1| Too few basicauthenticator processes are running (need 1/20)
2016/08/24 00:01:12 kid1| Starting new helpers
2016/08/24 00:01:12 kid1| helperOpenServers: Starting 1/20 'squid.auth-user.php' processes
2016/08/24 00:01:12 kid1| helperHandleRead: unexpected read from basicauthenticator #Hlpr1336, 325 bytes '
Warning: require_once(script/load_phalcon.php): failed to open stream: No such file or directory in /usr/local/etc/inc/legacy_bindings.inc on line 30
Fatal error: require_once(): Failed opening required 'script/load_phalcon.php' (include_path='.:/usr/local/share/pear') in /usr/local/etc/inc/legacy_bindings.inc on line 30
'
...and entries repeating indefinitely. What could be the problem??
Thanks!
The include path for PHP is incomplete. Is this 16.7.2 or lower? Any modifications?
# pkg query %v php56
If this returns "5.6.24_1" then you can try to run:
# /usr/local/etc/rc.php_ini_setup
I'm running 16.7.2-amd64 release, w/o any modifications.
pkg query %v php56
returns "5.6.24_1" and I run
# /usr/local/etc/rc.php_ini_setup
as you advised. This command doesn't return anything, all works normally so far :)
Today, all night long, same error with authenticator module appears again, squid crashed with auth.
There is example of error message (same as previous):
2016/08/31 03:24:05 kid1| WARNING: basicauthenticator #Hlpr200888 exited
2016/08/31 03:24:05 kid1| Too few basicauthenticator processes are running (need 1/20)
2016/08/31 03:24:05 kid1| Starting new helpers
2016/08/31 03:24:05 kid1| helperOpenServers: Starting 1/20 'squid.auth-user.php' processes
2016/08/31 03:24:05 kid1| helperHandleRead: unexpected read from basicauthenticator #Hlpr200889, 325 bytes '
Warning: require_once(script/load_phalcon.php): failed to open stream: No such file or directory in /usr/local/etc/inc/legacy_bindings.inc on line 30
Fatal error: require_once(): Failed opening required 'script/load_phalcon.php' (include_path='.:/usr/local/share/pear') in /usr/local/etc/inc/legacy_bindings.inc on line 30
How I can fix it??
It's the same problem and the fix should work again.
Something clobbers your /usr/local/etc/php.ini -- do you have any modifications, plugins or other packages installed?
No additional packages are installed. No modifications and plugins.
This is my /usr/local/etc/php.ini
; File generated via rc.php_ini_setup
output_buffering = "0"
expose_php = Off
implicit_flush = true
magic_quotes_gpc = Off
max_execution_time = 900
max_input_time = 1800
max_input_vars = 5000
memory_limit = 256M
register_argc_argv = On
register_long_arrays = Off
variables_order = "GPCS"
file_uploads = On
upload_tmp_dir = /tmp
upload_max_filesize = 200M
post_max_size = 200M
html_errors = Off
zlib.output_compression = Off
zlib.output_compression_level = 1
include_path = ".:/usr/local/etc/inc:/usr/local/www:/usr/local/opnsense/mvc:/usr/local/share/pear:/usr/local/opnsense/contrib"
ignore_repeated_errors = on
error_reporting = E_ALL ^ (E_NOTICE | E_DEPRECATED | E_STRICT)
display_errors=on
log_errors=on
error_log=/tmp/PHP_errors.log
extension_dir=/usr/local/lib/php/20131226/
date.timezone="Europe/Moscow"
[suhosin]
suhosin.get.max_array_depth = 5000
suhosin.get.max_array_index_length = 256
suhosin.get.max_vars = 5000
suhosin.get.max_value_length = 500000
suhosin.post.max_array_depth = 5000
suhosin.post.max_array_index_length = 256
suhosin.post.max_vars = 5000
suhosin.post.max_value_length = 9000000
suhosin.request.max_array_depth = 5000
suhosin.request.max_array_index_length = 256
suhosin.request.max_vars = 5000
suhosin.request.max_value_length = 9000000
suhosin.memory_limit = 512435456
suhosin.session.cryptdocroot=Off
So strange, but this error with squid at same time with period in some days, the reason of his behavior is unknown. What app or service can modify php.ini?
In general this only happens when a firmware update is run, the box reboots or the web interface restart is forced.
Do you have a cron job for firmware updates?
Quote from: franco on August 31, 2016, 04:31:52 PM
Do you have a cron job for firmware updates?
Yes, I tuned it to update automatically at 4:00AM every 2-nd day of week, but Squid crashed today (3-rd day, Wedn.) and near midhight; here is screenshot.
P.S. Server was rebooted at 10 AM manually.
It's definitely something that happens within your system. How do other graphs look, especially memory graph?
Here is CPU and RAM graphs (31.08.2016, 0:00 AM - 31.08.2016, 9:30 AM, till reboot) (during Squid errors and writing it to cache.log)
Up! Release 16.7.3, and error appeared again today at 0 AM... Or 'm really need to add cron task
/usr/local/etc/rc.php_ini_setup
to run every day??
Someone can help me?
Can you post the contents of /usr/local/lib/php.ini and /usr/local/etc/php.ini right after the crash?
I understand that this is annoying, but it's also highly unusual and hard to debug remotely.
I can reproduce something similar now and will provide a test patch soon, but other than guessing that this might be it, I have no idea why it's being triggered. Be right back...
Ok, I will post php.ini files after next crashing... Thanks for your help!
I could reproduce the faulty include path by forcefully flushing php.ini files (empty) and there is one spot in that script that does that. It's been like this for years and I can't make out whether that's the problem or how it is triggered, but I tightened the code as there is no downside from doing so.
To get this new file, run these commands:
# cd /usr/local/etc
# mv rc.php_ini_setup rc.php_ini_setup.bak
# fetch https://raw.githubusercontent.com/opnsense/core/bd66467db/src/etc/rc.php_ini_setup
And the respective commit for information:
https://github.com/opnsense/core/commit/bd66467db8df7
Cheers,
Franco
It is need to run new rc.php_ini_setup?
No, if it works right now it's ok to wait and see. :)
Applied your patch, will inform you later about the results! Very thanks for your help! :-)
Hi,
want to tell, that squid no more crashing like previous... All works fine!
Great to hear, thanks! It will be in 16.7.4.
Cheers,
Franco