Re: [squid-users] basic authenticator hangs when squid often receive logrotate

On Mon, 10 Jan 2005, Anton Golubev wrote:

> Hello, colleagues!
>
> I have trouble with basic authenticator daemons. They are hanging and
> use can't authenticate himself anymore. After a while I have this in my
> statistics:
>
> Basic Authenticator Statistics:
> program: /usr/local/bin/user_auth
> number running: 11 of 5

It may be this:

http://www.squid-cache.org/Versions/v2/2.5/bugs/#squid-2.5.STABLE7-helper_shutdown

but it doesn't exacly match your description.

> # FD PID # Requests Flags Time Offset Request
> 2 33 90292 2 AB S 130031.644 0
> nsokolova2 xxxx\n
> 2 36 90615 2 AB S 123530.990 0 mknyish
> xxxx\n
> 1 26 93367 5 AB S 66203.355 0 stepa
> xxxx\n
> 1 29 93656 3 AB S 58148.235 0 stepa
> xxxx\n
> 1 28 94210 2 AB S 45955.031 0
> ibarabash xxxx\n
> 1 34 94701 22 AB S 35611.662 0
> ibarabash xxxx\n
> 1 41 96230 57 A 0.097 0 (none)
> 2 42 96231 0 A 0.000 0 (none)
> 3 43 96232 0 A 0.000 0 (none)
> 4 44 96233 0 A 0.000 0 (none)
> 5 48 96234 0 A 0.000 0 (none)

This helper usage statistics indicates your helper is hanging, never
returning the results to Squid.

> Debug 84, 5 in squid.conf shows:
>
> 2005/01/09 02:00:00| helperShutdown: basicauthenticator #2 is BUSY.
> 2005/01/09 02:00:00| helperShutdown: basicauthenticator #2 is BUSY.
> 2005/01/09 02:00:00| storeDirWriteCleanLogs: Starting...
>
> 2005/01/09 04:00:00| helperShutdown: basicauthenticator #2 isBUSY.
> 2005/01/09 04:00:00| helperShutdown: basicauthenticator #2 is BUSY.
> 2005/01/09 04:00:00| storeDirWriteCleanLogs: Starting...
>
> 2005/01/09 06:00:01| helperShutdown: basicauthenticator #2 is BUSY.
> 2005/01/09 06:00:01| helperShutdown: basicauthenticator #2 is BUSY.
> 2005/01/09 06:00:01| helperShutdown: basicauthenticator #1 is BUSY.
> 2005/01/09 06:00:01| storeDirWriteCleanLogs: Starting...

This is consistent with the helper usage statistics above.

> My opinion is has "hanging" of authenticator occurs just after receiving
> "squid logrotate" signal (which is done each 2 hours via cron for rapid
> log processing).

The time column in the statistics indicates how long ago the request was
sent to the helper. This does not support your opinion. If this was the
case then the time differences between the different hanging requests
should be close to multiples of 2 hours, but this is not the case.

    108 minutes / 1 hour 48 minutes
    955 minutes / 15 hours 55 minutes
    134 minutes / 2 hours 14 minutes
    203 minutes / 3 hours 23 minutes
    172 minutes / 2 hours 52 minutes

> Please, don't suspect authenticator itself. It exists more then 2 years
> already without single problem (simple SELECT -> compare c-program).

But I do suspect the authenticator given your problem description.

Regards
Henrik
Received on Sun Jan 09 2005 - 17:19:34 MST