Re: [squid-users] Restarts without any apparent reason

Ralf Hildebrandt wrote:
> Squid 3.1.5 is stopping (and being restarted by runit) for no apparent
> reason. From the cache.log:
>
> 2010/07/29 14:55:39| could not parse headers from on disk structure!
> 2010/07/29 14:55:39| could not parse headers from on disk structure!
> 2010/07/29 14:57:39| could not parse headers from on disk structure!
> 2010/07/29 14:58:29| could not parse headers from on disk structure!
> 2010/07/29 14:58:52| could not parse headers from on disk structure!
> 2010/07/29 15:00:22| could not parse headers from on disk structure!
> 2010/07/29 15:00:22| could not parse headers from on disk structure!
> 2010/07/29 15:00:30| could not parse headers from on disk structure!
> 2010/07/29 15:00:57| could not parse headers from on disk structure!
> 2010/07/29 15:02:34| could not parse headers from on disk structure!
> 2010/07/29 15:02:52| could not parse headers from on disk structure!
>
> 2010/07/29 15:02:57| Starting Squid Cache version 3.1.5 for i686-pc-linux-gnu...
> 2010/07/29 15:02:57| Process ID 8888
> 2010/07/29 15:02:57| With 4096 file descriptors available
> 2010/07/29 15:02:57| Initializing IP Cache...
> 2010/07/29 15:02:57| DNS Socket created at [::], FD 5
> 2010/07/29 15:02:57| Adding domain charite.de from /etc/resolv.conf
> 2010/07/29 15:02:57| Adding nameserver 127.0.0.1 from /etc/resolv.conf
> 2010/07/29 15:02:57| Adding nameserver 141.42.2.22 from /etc/resolv.conf
> 2010/07/29 15:02:57| Adding nameserver 141.42.3.33 from /etc/resolv.conf
> 2010/07/29 15:02:57| Unlinkd pipe opened on FD 10
> 2010/07/29 15:02:57| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
> 2010/07/29 15:02:57| Store logging disabled
> 2010/07/29 15:02:57| Swap maxSize 15360000 + 8192 KB, estimated 1921024 objects
> 2010/07/29 15:02:57| Target number of buckets: 96051
> 2010/07/29 15:02:57| Using 131072 Store buckets
> 2010/07/29 15:02:57| Max Mem size: 8192 KB
> 2010/07/29 15:02:57| Max Swap size: 15360000 KB
> 2010/07/29 15:02:57| Version 1 of swap file with LFS support detected...
> 2010/07/29 15:02:57| Rebuilding storage in /squid-cache (DIRTY)
> 2010/07/29 15:02:57| Using Least Load store dir selection
> 2010/07/29 15:02:57| Set Current Directory to /tmp
> 2010/07/29 15:02:57| Loaded Icons.
> 2010/07/29 15:02:57| Accepting HTTP connections at [::]:8080, FD 15.
> 2010/07/29 15:02:57| Accepting ICP messages at [::]:3130, FD 16.
> 2010/07/29 15:02:57| Accepting HTCP messages on port 4827, FD 17.
> 2010/07/29 15:02:57| Accepting SNMP messages on [::]:3401, FD 18.
> 2010/07/29 15:02:57| WARNING: Peer looks like this host
> 2010/07/29 15:02:57| Ignoring Sibling proxy-cvk-1.charite.de/8080/3130
> 2010/07/29 15:02:57| Squid modules loaded: 0
> 2010/07/29 15:02:57| Adaptation support is on
> 2010/07/29 15:02:57| Ready to serve requests.
> 2010/07/29 15:02:57| Store rebuilding is 0.87% complete
> 2010/07/29 15:03:01| Done reading /squid-cache swaplog (472746 entries)
> 2010/07/29 15:03:01| Finished rebuilding storage from disk.
> 2010/07/29 15:03:01| 468209 Entries scanned
> 2010/07/29 15:03:01| 0 Invalid entries.
> 2010/07/29 15:03:01| 0 With invalid flags.
> 2010/07/29 15:03:01| 463707 Objects loaded.
> 2010/07/29 15:03:01| 0 Objects expired.
> 2010/07/29 15:03:01| 4502 Objects cancelled.

I'd hazard a guess that these 4502 objects were the ones with "could not
parse headers from on disk structure!" which may not have had time to be
erased between detection and crash.

> 2010/07/29 15:03:01| 0 Duplicate URLs purged.
> 2010/07/29 15:03:01| 0 Swapfile clashes avoided.
> 2010/07/29 15:03:01| Took 4.46 seconds (103937.58 objects/sec).
> 2010/07/29 15:03:01| Beginning Validation Procedure
> 2010/07/29 15:03:02| Completed Validation Procedure
> 2010/07/29 15:03:02| Validated 927437 Entries
> 2010/07/29 15:03:02| store_swap_size = 9418360
> 2010/07/29 15:03:02| storeLateRelease: released 0 objects
> 2010/07/29 15:03:02| Configuring Sibling proxy-cbf-1.charite.de/8080/3130
> 2010/07/29 15:03:02| Configuring Sibling proxy-cbf-2.charite.de/8080/3130
> 2010/07/29 15:03:02| Configuring Sibling proxy-cvk-2.charite.de/8080/3130
>
> Where can I find the reason?

Um. Maybe syslog or wherever the runit script 2>&1 sent it.

> Squid3 runs as the user "proxy":
>
> proxy 8888 38.9 5.2 126356 108980 ? S 15:02 1:26 /usr/sbin/squid3 -N
>
> The runit script is this:
>
> cd /etc/service/squid3
> echo 128 > /proc/sys/kernel/msgmni
> ulimit -n 4096 -c unlimited
> exec 2>&1
> exec /usr/sbin/squid3 -N

Any particular reason why you are running as a runit daemon with
no-daemon mode (-N) enabled?

The little script above is essentially identical to what deamon mode in
Squid does internally, but without a config re-parse on each loop due to
not needing to start from scratch.

>
> The config file specifies:
>
> coredump_dir /tmp
> cache_effective_user proxy
> cache_effective_group proxy
> cache_dir diskd /squid-cache 15000 32 32
>
> Yet I don't see a corefile in /tmp or /squid-cache
>
> # ls -ld /squid-cache/
> drwx------ 35 proxy proxy 4096 2010-07-29 15:03 /squid-cache/
>
> Right now I'm running it in the debugger
>

Amos

-- 
Please be using
   Current Stable Squid 2.7.STABLE9 or 3.1.5