Re: [squid-users] Frequent cache rebuilding

From: Chris Robertson <crobertson_at_gci.net>
Date: Fri, 16 Jan 2009 12:30:17 -0900

Andreev Nikita wrote:
> Hi.
>
> What are the reasons of squid rebuilding it's cache? Sometimes after
> startup sometimes during work it starts to rebuild cache. I see it in
> cahce.log:
>

Squid rebuilds the swap.state file when a logrotate (and I think
reconfigure) is called for. Usually it's not a big deal. My main cache
has about 13 million objects and rebuilding the cache takes just over 10
seconds:

2009/01/15 04:02:27| storeDirWriteCleanLogs: Starting...
...
2009/01/15 04:02:39| Finished. Wrote 12918887 entries.
2009/01/15 04:02:39| Took 12.4 seconds (1044380.1 entries/sec).

and

2009/01/16 04:02:29| storeDirWriteCleanLogs: Starting...
...
2009/01/16 04:02:40| Finished. Wrote 12906114 entries.
2009/01/16 04:02:40| Took 11.3 seconds (1138371.9 entries/sec).

> 2009/01/16 09:30:24| Starting Squid Cache version 2.6.STABLE6 for x86_64-redhat-linux-gnu...
> 2009/01/16 09:30:24| Process ID 2625
> 2009/01/16 09:30:24| With 1024 file descriptors available
> 2009/01/16 09:30:24| Using epoll for the IO loop
> 2009/01/16 09:30:24| DNS Socket created at 0.0.0.0, port 60302, FD 5
> 2009/01/16 09:30:24| Adding domain mydomain.com from /etc/resolv.conf
> 2009/01/16 09:30:24| Adding nameserver 22.179.1.11 from /etc/resolv.conf
> 2009/01/16 09:30:24| Adding nameserver 22.179.1.15 from /etc/resolv.conf
> 2009/01/16 09:30:24| User-Agent logging is disabled.
> 2009/01/16 09:30:24| Referer logging is disabled.
> 2009/01/16 09:30:24| Unlinkd pipe opened on FD 10
> 2009/01/16 09:30:24| Swap maxSize 16777216 KB, estimated 1290555 objects
> 2009/01/16 09:30:24| Target number of buckets: 64527
> 2009/01/16 09:30:24| Using 65536 Store buckets
> 2009/01/16 09:30:24| Max Mem size: 393216 KB
> 2009/01/16 09:30:24| Max Swap size: 16777216 KB
> 2009/01/16 09:30:24| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
> 2009/01/16 09:30:24| Store logging disabled
> 2009/01/16 09:30:24| Rebuilding storage in /var/spool/squid (CLEAN)
> 2009/01/16 09:30:24| Using Least Load store dir selection
> 2009/01/16 09:30:24| Set Current Directory to /var/spool/squid
> 2009/01/16 09:30:24| Loaded Icons.
> 2009/01/16 09:30:26| Accepting proxy HTTP connections at 0.0.0.0, port 8080, FD 11.
> 2009/01/16 09:30:26| Accepting ICP messages at 0.0.0.0, port 3130, FD 12.
> 2009/01/16 09:30:26| WCCP Disabled.
> 2009/01/16 09:30:26| Ready to serve requests.
> 2009/01/16 09:30:35| Store rebuilding is 0.4% complete
> 2009/01/16 09:30:53| Store rebuilding is 1.1% complete
> 2009/01/16 09:31:08| Store rebuilding is 1.5% complete
> 2009/01/16 09:31:24| Store rebuilding is 2.3% complete
> 2009/01/16 09:31:44| Store rebuilding is 3.1% complete
> 2009/01/16 09:32:01| Store rebuilding is 3.4% complete
> ...
> 2009/01/16 10:32:41| Store rebuilding is 98.1% complete
> 2009/01/16 10:33:06| Store rebuilding is 98.5% complete
> 2009/01/16 10:33:26| Store rebuilding is 98.9% complete
> 2009/01/16 10:33:53| Store rebuilding is 99.6% complete
> 2009/01/16 10:34:13| Done reading /var/spool/squid swaplog (1072895 entries)
> 2009/01/16 10:34:13| Finished rebuilding storage from disk.
> 2009/01/16 10:34:13| 1072895 Entries scanned
> 2009/01/16 10:34:13| 0 Invalid entries.
> 2009/01/16 10:34:13| 0 With invalid flags.
> 2009/01/16 10:34:13| 1044791 Objects loaded.
> 2009/01/16 10:34:13| 0 Objects expired.
> 2009/01/16 10:34:13| 0 Objects cancelled.
> 2009/01/16 10:34:13| 7253 Duplicate URLs purged.
> 2009/01/16 10:34:13| 20851 Swapfile clashes avoided.
> 2009/01/16 10:34:13| Took 3829.6 seconds ( 272.8 objects/sec).
>

Yikes. That's slow...

> 2009/01/16 10:34:13| Beginning Validation Procedure
> 2009/01/16 10:35:04| 262144 Entries Validated so far.
> 2009/01/16 10:35:17| 524288 Entries Validated so far.
> 2009/01/16 10:35:25| 786432 Entries Validated so far.
> 2009/01/16 10:35:43| Completed Validation Procedure
> 2009/01/16 10:35:43| Validated 1044747 Entries
> 2009/01/16 10:35:43| store_swap_size = 15131260k
> 2009/01/16 10:37:58| storeLateRelease: released 4184 objects
>
> I never stop squid abnormally and I never restart server abnormally.
> So I don't understand why does squid do it. It takes a lot of CPU
> resources and about an hour of time.

What kind of CPU resources? Userspace, system, or wait?

> It never happened before. But now
> it happens several times a day.
>
> Could somebody help whith that?
>
> P.S. I have 18G partition with 16G granted for squid cache and 2G free
> for temporary squid files. So I hope it's enough space for squid to
> perform it's everyday tasks.
>

Ah. A lot of file systems start to perform poorly as they approach
capacity. I'd suggest setting your cache_dir to 13G and let squid clear
out the excess or grow the partition to 30G (if you have the space).

> Regards,
> LPIC-1, EMCPA
> Nikita Andreev
>

Chris
Received on Fri Jan 16 2009 - 21:27:56 MST

This archive was generated by hypermail 2.2.0 : Sat Jan 17 2009 - 12:00:03 MST