Squid stops every day --> same time !

Hi all,

we have a very strange squid behaviour:

Squid stops answering requests everyday at exact the same time: 14:41
h ± 1/2 min.

Then, users get time-out errors and in the access.log there are no
requests coming up anymore.

Unfortunatly, there are no log-entries to point out the error.
If i look in /var/log/syslog at this time ± 10 min, there is no
suspicious process, which could cause to stop squid, nor an error
message from squid nor any other error messages.

The /var/log/squid/cache.log has no error messages, too.
Logrotating is made at 6.30 around, but no error-indication by this
time.

If i make:

# /etc/init.d/squid stop
# /etc/init.d/squid start

then squid comes up again and working 100% - till next day...


Without any log-errors i´m blind to see anything, what´s going there.

Has anybody any hint or idea, how to investigate the error or maybe a
solution for that ?

Currently my approach is making a cron-job at 14:44 to restart squid,
but that shouldn´t be the real solution.

Many Thanks and see cache-log above (manually restarting at 15:03:54)

Regards,

Harald Jung


------------------------------------------------------------------------------
/var/log/squid/cache.log
------------------------------------------------------------------------------
2004/05/29 06:27:42| storeDirWriteCleanLogs: Starting...
2004/05/29 06:27:45| 65536 entries written so far.
2004/05/29 06:27:46| Finished. Wrote 130175 entries.
2004/05/29 06:27:46| Took 2.7 seconds (48105.3 entries/sec).
2004/05/29 06:27:46| logfileRotate: /var/log/squid/store.log
2004/05/29 06:27:46| logfileRotate: /var/log/squid/access.log
2004/05/29 15:03:54| Preparing for shutdown after 7979 requests
2004/05/29 15:03:54| Waiting 30 seconds for active connections to
finish
2004/05/29 15:03:54| FD 12 Closing HTTP connection
2004/05/29 15:04:26| Shutting down...
2004/05/29 15:04:26| Closing unlinkd pipe on FD 10
2004/05/29 15:04:26| storeDirWriteCleanLogs: Starting...
2004/05/29 15:04:26| 65536 entries written so far.
2004/05/29 15:04:26| Finished. Wrote 130399 entries.
2004/05/29 15:04:26| Took 0.1 seconds (1800817.6 entries/sec).
CPU Usage: 21.690 seconds = 12.220 user + 9.470 sys
Maximum Resident Size: 0 KB
Page faults with physical i/o: 605
Memory usage for squid via mallinfo():
total space in arena: 21244 KB
Ordinary blocks: 21103 KB 414 blks
Small blocks: 0 KB 0 blks
Holding blocks: 904 KB 2 blks
Free Small blocks: 0 KB
Free Ordinary blocks: 140 KB
Total in use: 22007 KB 104%
Total free: 140 KB 1%
2004/05/29 15:04:26| Squid Cache (Version 2.5.STABLE5): Exiting
normally.
2004/05/29 15:04:31| Starting Squid Cache version 2.5.STABLE5 for
i386-debian-linux-gnu...
2004/05/29 15:04:31| Process ID 7406
2004/05/29 15:04:31| With 1024 file descriptors available
2004/05/29 15:04:31| DNS Socket created at 0.0.0.0, port 38951, FD 5
2004/05/29 15:04:31| Adding nameserver 194.25.2.129 from
/etc/resolv.conf
2004/05/29 15:04:31| User-Agent logging is disabled.
2004/05/29 15:04:31| Referer logging is disabled.
2004/05/29 15:04:31| Unlinkd pipe opened on FD 10
2004/05/29 15:04:31| Swap maxSize 1945600 KB, estimated 149661 objects
2004/05/29 15:04:31| Target number of buckets: 7483
2004/05/29 15:04:31| Using 8192 Store buckets
2004/05/29 15:04:31| Max Mem size: 131072 KB
2004/05/29 15:04:31| Max Swap size: 1945600 KB
2004/05/29 15:04:31| Local cache digest enabled; rebuild/rewrite every
3600/3600 sec
2004/05/29 15:04:31| Rebuilding storage in /var/spool/squid (CLEAN)
2004/05/29 15:04:31| Using Least Load store dir selection
2004/05/29 15:04:31| Current Directory is /
2004/05/29 15:04:31| Loaded Icons.
2004/05/29 15:04:31| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2004/05/29 15:04:31| HTCP Disabled.
2004/05/29 15:04:31| WCCP Disabled.
Memory usage for squid via mallinfo():
total space in arena: 21244 KB
Ordinary blocks: 21103 KB 414 blks
Small blocks: 0 KB 0 blks
Holding blocks: 904 KB 2 blks
Free Small blocks: 0 KB
Free Ordinary blocks: 140 KB
Total in use: 22007 KB 104%
Total free: 140 KB 1%
2004/05/29 15:04:26| Squid Cache (Version 2.5.STABLE5): Exiting
normally.
2004/05/29 15:04:31| Starting Squid Cache version 2.5.STABLE5 for
i386-debian-linux-gnu...
2004/05/29 15:04:31| Process ID 7406
2004/05/29 15:04:31| With 1024 file descriptors available
2004/05/29 15:04:31| DNS Socket created at 0.0.0.0, port 38951, FD 5
2004/05/29 15:04:31| Adding nameserver 194.25.2.129 from
/etc/resolv.conf
2004/05/29 15:04:31| User-Agent logging is disabled.
2004/05/29 15:04:31| Referer logging is disabled.
2004/05/29 15:04:31| Unlinkd pipe opened on FD 10
2004/05/29 15:04:31| Swap maxSize 1945600 KB, estimated 149661 objects
2004/05/29 15:04:31| Target number of buckets: 7483
2004/05/29 15:04:31| Using 8192 Store buckets
2004/05/29 15:04:31| Max Mem size: 131072 KB
2004/05/29 15:04:31| Max Swap size: 1945600 KB
2004/05/29 15:04:31| Local cache digest enabled; rebuild/rewrite every
3600/3600 sec
2004/05/29 15:04:31| Rebuilding storage in /var/spool/squid (CLEAN)
2004/05/29 15:04:31| Using Least Load store dir selection
2004/05/29 15:04:31| Current Directory is /
2004/05/29 15:04:31| Loaded Icons.
2004/05/29 15:04:31| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2004/05/29 15:04:31| HTCP Disabled.
2004/05/29 15:04:31| WCCP Disabled.
2004/05/29 15:04:31| Ready to serve requests.
2004/05/29 15:04:31| Store rebuilding is 3.1% complete
2004/05/29 15:04:33| Done reading /var/spool/squid swaplog (130399
entries)
2004/05/29 15:04:33| Finished rebuilding storage from disk.
2004/05/29 15:04:33| 130399 Entries scanned
2004/05/29 15:04:33| 0 Invalid entries.
2004/05/29 15:04:33| 0 With invalid flags.
2004/05/29 15:04:33| 130399 Objects loaded.
2004/05/29 15:04:33| 0 Objects expired.
2004/05/29 15:04:33| 0 Objects cancelled.
2004/05/29 15:04:33| 0 Duplicate URLs purged.
2004/05/29 15:04:33| 0 Swapfile clashes avoided.
2004/05/29 15:04:33| Took 2.2 seconds (58914.5 objects/sec).
2004/05/29 15:04:33| Beginning Validation Procedure
2004/05/29 15:04:33| Completed Validation Procedure
2004/05/29 15:04:33| Validated 130399 Entries
2004/05/29 15:04:33| store_swap_size = 1677000k
2004/05/29 15:04:34| storeLateRelease: released 0 objects
------------------------------------------------------------------------------

Very odd. I'd fire up top or check your processes at that time to see what's
happening since you say that you've got no indicators in logs. Also you
might think about uplugging your network cable at that time and see what
happens. It really would child's play to have a scheduled job (from another
machine) that kills your squid process. If they're both locked to a ntp
server then it'll happen at the same time every day.

good luck.

Have you tried
"Harald Jung" <papaya74@web.de> wrote in message
news:1763c134.0406010535.43c9cf3b@posting.google.c om...
> Hi all,
>
> we have a very strange squid behaviour:
>
> Squid stops answering requests everyday at exact the same time: 14:41
> h ± 1/2 min.
>
> Then, users get time-out errors and in the access.log there are no
> requests coming up anymore.
>
> Unfortunatly, there are no log-entries to point out the error.
> If i look in /var/log/syslog at this time ± 10 min, there is no
> suspicious process, which could cause to stop squid, nor an error
> message from squid nor any other error messages.
>
> The /var/log/squid/cache.log has no error messages, too.
> Logrotating is made at 6.30 around, but no error-indication by this
> time.
>
> If i make:
>
> # /etc/init.d/squid stop
> # /etc/init.d/squid start
>
> then squid comes up again and working 100% - till next day...
>
>
> Without any log-errors i´m blind to see anything, what´s going there.
>
> Has anybody any hint or idea, how to investigate the error or maybe a
> solution for that ?
>
> Currently my approach is making a cron-job at 14:44 to restart squid,
> but that shouldn´t be the real solution.
>
> Many Thanks and see cache-log above (manually restarting at 15:03:54)
>
> Regards,
>
> Harald Jung
>
>
> --------------------------------------------------------------------------
----
> /var/log/squid/cache.log
> --------------------------------------------------------------------------
----
> 2004/05/29 06:27:42| storeDirWriteCleanLogs: Starting...
> 2004/05/29 06:27:45| 65536 entries written so far.
> 2004/05/29 06:27:46| Finished. Wrote 130175 entries.
> 2004/05/29 06:27:46| Took 2.7 seconds (48105.3 entries/sec).
> 2004/05/29 06:27:46| logfileRotate: /var/log/squid/store.log
> 2004/05/29 06:27:46| logfileRotate: /var/log/squid/access.log
> 2004/05/29 15:03:54| Preparing for shutdown after 7979 requests
> 2004/05/29 15:03:54| Waiting 30 seconds for active connections to
> finish
> 2004/05/29 15:03:54| FD 12 Closing HTTP connection
> 2004/05/29 15:04:26| Shutting down...
> 2004/05/29 15:04:26| Closing unlinkd pipe on FD 10
> 2004/05/29 15:04:26| storeDirWriteCleanLogs: Starting...
> 2004/05/29 15:04:26| 65536 entries written so far.
> 2004/05/29 15:04:26| Finished. Wrote 130399 entries.
> 2004/05/29 15:04:26| Took 0.1 seconds (1800817.6 entries/sec).
> CPU Usage: 21.690 seconds = 12.220 user + 9.470 sys
> Maximum Resident Size: 0 KB
> Page faults with physical i/o: 605
> Memory usage for squid via mallinfo():
> total space in arena: 21244 KB
> Ordinary blocks: 21103 KB 414 blks
> Small blocks: 0 KB 0 blks
> Holding blocks: 904 KB 2 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 140 KB
> Total in use: 22007 KB 104%
> Total free: 140 KB 1%
> 2004/05/29 15:04:26| Squid Cache (Version 2.5.STABLE5): Exiting
> normally.
> 2004/05/29 15:04:31| Starting Squid Cache version 2.5.STABLE5 for
> i386-debian-linux-gnu...
> 2004/05/29 15:04:31| Process ID 7406
> 2004/05/29 15:04:31| With 1024 file descriptors available
> 2004/05/29 15:04:31| DNS Socket created at 0.0.0.0, port 38951, FD 5
> 2004/05/29 15:04:31| Adding nameserver 194.25.2.129 from
> /etc/resolv.conf
> 2004/05/29 15:04:31| User-Agent logging is disabled.
> 2004/05/29 15:04:31| Referer logging is disabled.
> 2004/05/29 15:04:31| Unlinkd pipe opened on FD 10
> 2004/05/29 15:04:31| Swap maxSize 1945600 KB, estimated 149661 objects
> 2004/05/29 15:04:31| Target number of buckets: 7483
> 2004/05/29 15:04:31| Using 8192 Store buckets
> 2004/05/29 15:04:31| Max Mem size: 131072 KB
> 2004/05/29 15:04:31| Max Swap size: 1945600 KB
> 2004/05/29 15:04:31| Local cache digest enabled; rebuild/rewrite every
> 3600/3600 sec
> 2004/05/29 15:04:31| Rebuilding storage in /var/spool/squid (CLEAN)
> 2004/05/29 15:04:31| Using Least Load store dir selection
> 2004/05/29 15:04:31| Current Directory is /
> 2004/05/29 15:04:31| Loaded Icons.
> 2004/05/29 15:04:31| Accepting HTTP connections at 0.0.0.0, port 3128,
> FD 12.
> 2004/05/29 15:04:31| HTCP Disabled.
> 2004/05/29 15:04:31| WCCP Disabled.
> Memory usage for squid via mallinfo():
> total space in arena: 21244 KB
> Ordinary blocks: 21103 KB 414 blks
> Small blocks: 0 KB 0 blks
> Holding blocks: 904 KB 2 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 140 KB
> Total in use: 22007 KB 104%
> Total free: 140 KB 1%
> 2004/05/29 15:04:26| Squid Cache (Version 2.5.STABLE5): Exiting
> normally.
> 2004/05/29 15:04:31| Starting Squid Cache version 2.5.STABLE5 for
> i386-debian-linux-gnu...
> 2004/05/29 15:04:31| Process ID 7406
> 2004/05/29 15:04:31| With 1024 file descriptors available
> 2004/05/29 15:04:31| DNS Socket created at 0.0.0.0, port 38951, FD 5
> 2004/05/29 15:04:31| Adding nameserver 194.25.2.129 from
> /etc/resolv.conf
> 2004/05/29 15:04:31| User-Agent logging is disabled.
> 2004/05/29 15:04:31| Referer logging is disabled.
> 2004/05/29 15:04:31| Unlinkd pipe opened on FD 10
> 2004/05/29 15:04:31| Swap maxSize 1945600 KB, estimated 149661 objects
> 2004/05/29 15:04:31| Target number of buckets: 7483
> 2004/05/29 15:04:31| Using 8192 Store buckets
> 2004/05/29 15:04:31| Max Mem size: 131072 KB
> 2004/05/29 15:04:31| Max Swap size: 1945600 KB
> 2004/05/29 15:04:31| Local cache digest enabled; rebuild/rewrite every
> 3600/3600 sec
> 2004/05/29 15:04:31| Rebuilding storage in /var/spool/squid (CLEAN)
> 2004/05/29 15:04:31| Using Least Load store dir selection
> 2004/05/29 15:04:31| Current Directory is /
> 2004/05/29 15:04:31| Loaded Icons.
> 2004/05/29 15:04:31| Accepting HTTP connections at 0.0.0.0, port 3128,
> FD 12.
> 2004/05/29 15:04:31| HTCP Disabled.
> 2004/05/29 15:04:31| WCCP Disabled.
> 2004/05/29 15:04:31| Ready to serve requests.
> 2004/05/29 15:04:31| Store rebuilding is 3.1% complete
> 2004/05/29 15:04:33| Done reading /var/spool/squid swaplog (130399
> entries)
> 2004/05/29 15:04:33| Finished rebuilding storage from disk.
> 2004/05/29 15:04:33| 130399 Entries scanned
> 2004/05/29 15:04:33| 0 Invalid entries.
> 2004/05/29 15:04:33| 0 With invalid flags.
> 2004/05/29 15:04:33| 130399 Objects loaded.
> 2004/05/29 15:04:33| 0 Objects expired.
> 2004/05/29 15:04:33| 0 Objects cancelled.
> 2004/05/29 15:04:33| 0 Duplicate URLs purged.
> 2004/05/29 15:04:33| 0 Swapfile clashes avoided.
> 2004/05/29 15:04:33| Took 2.2 seconds (58914.5 objects/sec).
> 2004/05/29 15:04:33| Beginning Validation Procedure
> 2004/05/29 15:04:33| Completed Validation Procedure
> 2004/05/29 15:04:33| Validated 130399 Entries
> 2004/05/29 15:04:33| store_swap_size = 1677000k
> 2004/05/29 15:04:34| storeLateRelease: released 0 objects
> --------------------------------------------------------------------------
----