Re: [squid-users] storage rebuild slow with reiserfs

Hello All
people usually say reiserfs is more suitable for Squid than ext3.
It does not seem to me, that is why I'm posting another mail.
Actually, Duane Wessels book Squid The Definitive Guide shows ext3 has
slightly higher throughput than reiserfs too.

I am still very surprised about poor reiserfs performance, very visible
especialy when Squid performs Store Rebuild at the startup.

When I had the disk cache on a ext3 partitions, the usual log
    line was:
2005/01/07 15:52:28| Took 197.0 seconds (36124.7 objects/sec).
   with reiserfs I see:
2005/02/02 01:01:22| Took 749.2 seconds ( 3738.1 objects/sec).

reiserf seems to be 10 times slower than ext3 for store rebuilding!
The server is dedicated to Squid, there is no other service running.

When you look at the Storage Rebuild stats below, Squid rebuilds first
25% very quickly (20 seconds) and then the rest 75% takes ages (12 min).
Why? Is it because I copied the cache content from ext3 partition to
reiserfs (squid wrote it to ext3 and now reads it from reiserfs) and
these 25% is new content which Squid has written on reiserfs itself
since it started with reiserfs partitions? I don't think so.

Squid also report strange
   Filesystem Inodes in use: 0/-1 (0%)
with reiserfs in cachemgr Store Dir Stat.

It really looks reiserfs has much lower throughput than ext3. I can see
it also during my peak times, when I have 320 requests/second.
HTTP hit service times triples, while with ext3 it only doubled. Yes, I
know I have a bottleneck, but I am still happy about the system
performance (or, more precisely, I was happy about the ext3 performance
under this load).

The system is Debian stable with kernel 2.4.25. I mentioned other
params in the original post yesterday.

reiserfs partitions are mounted as follow:

/dev/sdb1 on /cache/cache1 type reiserfs (rw,noatime,notail)
/dev/sdc1 on /cache/cache2 type reiserfs (rw,noatime,notail)

While the ext3 were as follow:
/dev/sda1 on /cache/cache1 type ext3 (rw,noatime)
/dev/sdb1 on /cache/cache2 type ext3 (rw,noatime)

I am going to use ext3 instead of reiserfs, I just thought someone might
be interested by this post.

Best regards,
Marji

----------------- STORE REBUILDING -----------------------------

2005/02/02 00:48:53| Starting Squid Cache version 2.5.STABLE7 for
i686-pc-linux-gnu...
2005/02/02 00:48:53| Process ID 7944
2005/02/02 00:48:53| With 8192 file descriptors available
2005/02/02 00:48:53| Performing DNS Tests...
2005/02/02 00:48:53| Successful DNS name lookup tests...
2005/02/02 00:48:53| DNS Socket created at 0.0.0.0, port 1025, FD 4
2005/02/02 00:48:53| Swap maxSize 57344000 KB, estimated 2867200 objects
2005/02/02 00:48:53| Target number of buckets: 143360
2005/02/02 00:48:53| Using 262144 Store buckets
2005/02/02 00:48:53| Max Mem size: 1024000 KB
2005/02/02 00:48:53| Max Swap size: 57344000 KB
2005/02/02 00:48:53| Store logging disabled
2005/02/02 00:48:53| Rebuilding storage in /cache/cache1 (CLEAN)
2005/02/02 00:48:53| Rebuilding storage in /cache/cache2 (CLEAN)
2005/02/02 00:48:53| Using Least Load store dir selection
2005/02/02 00:48:53| Set Current Directory to /cache
2005/02/02 00:48:53| Loaded Icons.
2005/02/02 00:48:53| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2005/02/02 00:48:53| Accepting SNMP messages on port 3401, FD 13.
2005/02/02 00:48:53| WCCP Disabled.
2005/02/02 00:48:53| wccp2ConnectionOpen: Accepting WCCPv2 messages on
port 2048, FD 14.
2005/02/02 00:48:53| Ready to serve requests.
2005/02/02 00:48:54| Store rebuilding is 0.3% complete
2005/02/02 00:49:13| Store rebuilding is 24.4% complete
2005/02/02 00:49:29| Store rebuilding is 25.6% complete
2005/02/02 00:49:45| Store rebuilding is 26.8% complete
2005/02/02 00:50:00| Store rebuilding is 27.9% complete
2005/02/02 00:50:17| Store rebuilding is 29.1% complete
2005/02/02 00:50:32| Store rebuilding is 30.3% complete
2005/02/02 00:50:47| Store rebuilding is 44.6% complete
2005/02/02 00:51:04| Store rebuilding is 50.5% complete
2005/02/02 00:51:19| Store rebuilding is 51.6% complete
2005/02/02 00:51:37| Store rebuilding is 53.1% complete
2005/02/02 00:51:52| Store rebuilding is 54.3% complete
2005/02/02 00:52:09| Store rebuilding is 55.7% complete
2005/02/02 00:52:27| Store rebuilding is 57.2% complete
2005/02/02 00:52:44| Store rebuilding is 58.6% complete
2005/02/02 00:53:01| Store rebuilding is 60.1% complete
2005/02/02 00:53:16| Store rebuilding is 61.3% complete
2005/02/02 00:53:34| Store rebuilding is 62.7% complete
2005/02/02 00:53:49| Store rebuilding is 63.9% complete
2005/02/02 00:54:06| Store rebuilding is 65.4% complete
2005/02/02 00:54:21| Store rebuilding is 66.5% complete
2005/02/02 00:54:37| Store rebuilding is 68.0% complete
2005/02/02 00:54:55| Store rebuilding is 69.5% complete
2005/02/02 00:55:10| Store rebuilding is 70.9% complete
2005/02/02 00:55:29| Store rebuilding is 72.4% complete
2005/02/02 00:55:44| Store rebuilding is 73.6% complete
2005/02/02 00:55:59| Store rebuilding is 74.7% complete
2005/02/02 00:56:15| Store rebuilding is 75.9% complete
2005/02/02 00:56:33| Store rebuilding is 77.4% complete
2005/02/02 00:56:49| Store rebuilding is 78.5% complete
2005/02/02 00:57:07| Store rebuilding is 80.0% complete
2005/02/02 00:57:22| Store rebuilding is 81.2% complete
2005/02/02 00:57:40| Store rebuilding is 82.6% complete
2005/02/02 00:57:55| Store rebuilding is 83.8% complete
2005/02/02 00:58:13| Store rebuilding is 85.3% complete
2005/02/02 00:58:28| Store rebuilding is 86.4% complete
2005/02/02 00:58:46| Store rebuilding is 87.9% complete
2005/02/02 00:59:03| Store rebuilding is 89.4% complete
2005/02/02 00:59:19| Store rebuilding is 90.5% complete
2005/02/02 00:59:34| Store rebuilding is 91.7% complete
2005/02/02 00:59:50| Store rebuilding is 92.9% complete
2005/02/02 01:00:07| Store rebuilding is 94.3% complete
2005/02/02 01:00:24| Store rebuilding is 95.5% complete
2005/02/02 01:00:39| Store rebuilding is 96.7% complete
2005/02/02 01:00:56| Store rebuilding is 97.8% complete
2005/02/02 01:01:11| Store rebuilding is 99.0% complete
2005/02/02 01:01:22| Done reading /cache/cache1 swaplog (1399689 entries)
2005/02/02 01:01:22| Done reading /cache/cache2 swaplog (1400972 entries)
2005/02/02 01:01:22| Finished rebuilding storage from disk.
2005/02/02 01:01:22| 2800661 Entries scanned
2005/02/02 01:01:22| 0 Invalid entries.
2005/02/02 01:01:22| 0 With invalid flags.
2005/02/02 01:01:22| 2800661 Objects loaded.
2005/02/02 01:01:22| 0 Objects expired.
2005/02/02 01:01:22| 0 Objects cancelled.
2005/02/02 01:01:22| 0 Duplicate URLs purged.
2005/02/02 01:01:22| 0 Swapfile clashes avoided.
2005/02/02 01:01:22| Took 749.2 seconds (3738.1 objects/sec).
2005/02/02 01:01:22| Beginning Validation Procedure
2005/02/02 01:01:23| 262144 Entries Validated so far.
2005/02/02 01:01:23| 524288 Entries Validated so far.
2005/02/02 01:01:23| 786432 Entries Validated so far.
2005/02/02 01:01:23| 1048576 Entries Validated so far.
2005/02/02 01:01:23| 1310720 Entries Validated so far.
2005/02/02 01:01:23| 1572864 Entries Validated so far.
2005/02/02 01:01:23| 1835008 Entries Validated so far.
2005/02/02 01:01:23| 2097152 Entries Validated so far.
2005/02/02 01:01:23| 2359296 Entries Validated so far.
2005/02/02 01:01:23| 2621440 Entries Validated so far.
2005/02/02 01:01:23| Completed Validation Procedure
2005/02/02 01:01:23| Validated 2800661 Entries
2005/02/02 01:01:23| store_swap_size = 53893052k
2005/02/02 01:01:24| storeLateRelease: released 0 objects
Received on Tue Feb 01 2005 - 20:26:42 MST