OPNsense Forum

Archive => 16.7 Legacy Series => Topic started by: denmmx on August 24, 2016, 09:03:05 am

Title: [SOLVED] Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on August 24, 2016, 09:03:05 am
Hi,
some days ago Squid proxy began to crash periodically (NOT every day) somewhere about after 1 AM with next entries in cache.log:

Code: [Select]
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!
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on August 25, 2016, 09:04:30 am
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
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on August 28, 2016, 11:17:37 pm
I'm running 16.7.2-amd64 release, w/o any modifications.
Code: [Select]
pkg query %v php56 returns "5.6.24_1" and I run
Code: [Select]
# /usr/local/etc/rc.php_ini_setup
as you advised. This command doesn't return anything, all works normally so far :)
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on August 31, 2016, 11:36:36 am
Today, all night long, same error with authenticator module appears again, squid crashed with auth.
There is example of error message (same as previous):

Code: [Select]
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??
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on August 31, 2016, 01:51:39 pm
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?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on August 31, 2016, 03:03:44 pm
No additional packages are installed. No modifications and plugins.

This is my  /usr/local/etc/php.ini
Code: [Select]
; 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?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on August 31, 2016, 04:31:52 pm
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?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on August 31, 2016, 05:49:19 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.
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on August 31, 2016, 11:56:10 pm
It's definitely something that happens within your system. How do other graphs look, especially memory graph?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 01, 2016, 06:41:05 am
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)
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 01, 2016, 11:08:51 pm
Up! Release 16.7.3, and error appeared again today at 0 AM... Or 'm really need to add cron task
Code: [Select]
/usr/local/etc/rc.php_ini_setupto run every day??

Someone can help me?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on September 02, 2016, 08:22:42 am
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...
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 02, 2016, 08:25:06 am
Ok, I will post php.ini files after next crashing... Thanks for your help!
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on September 02, 2016, 08:45:07 am
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
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 02, 2016, 09:02:45 am
It is need to run new rc.php_ini_setup?
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on September 02, 2016, 09:15:42 am
No, if it works right now it's ok to wait and see. :)
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 02, 2016, 03:54:41 pm
Applied your patch, will inform you later about the results! Very thanks for your help! :-)
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: denmmx on September 09, 2016, 07:34:37 pm
Hi,
want to tell, that squid no more crashing like previous... All works fine!
Title: Re: Squid proxy crashing (unexpected read from basicauthenticator)
Post by: franco on September 18, 2016, 11:39:20 pm
Great to hear, thanks! It will be in 16.7.4.


Cheers,
Franco