RE: [squid-users] Logging problem

Thanks Henrik and Marc for the quick reply.

I previously forgot to mention that the OS is Linux RedHat 7.3. I
examined the cache.log those entries where generated at the time the
cache crashed.

Henrik I guess your recommendation of using File::Tail perl module will
improve the script performance and make the code cleaner - thanks for
that

Regards,

Ramzi

2003/05/06 11:46:00| clientSendMoreData: Deferring
http://www.aclenglish.com/common/buttons/custom/acl_rollover/square/staf
finformation.gif
2003/05/06 11:46:00| clientKeepaliveNextRequest: FD 121 Sending next
2003/05/06 11:46:01| clientSendMoreData: Deferring
http://www.aclenglish.com/common/buttons/custom/acl_rollover/square/staf
finformation_o.gif
2003/05/06 11:46:02| clientKeepaliveNextRequest: FD 121 Sending next
2003/05/06 11:50:31| storeDirWriteCleanLogs: Starting...
2003/05/06 11:50:31| WARNING: Closing open FD 13
2003/05/06 11:50:31| WARNING: Closing open FD 14
2003/05/06 11:50:31| 65536 entries written so far.
2003/05/06 11:50:31| 131072 entries written so far.
2003/05/06 11:50:31| 196608 entries written so far.
2003/05/06 11:50:31| 262144 entries written so far.
2003/05/06 11:50:31| 327680 entries written so far.
2003/05/06 11:50:31| 393216 entries written so far.
2003/05/06 11:50:31| 458752 entries written so far.
2003/05/06 11:50:31| 524288 entries written so far.
2003/05/06 11:50:31| 589824 entries written so far.
2003/05/06 11:50:32| 655360 entries written so far.
2003/05/06 11:50:32| 720896 entries written so far.
2003/05/06 11:50:32| 786432 entries written so far.
2003/05/06 11:50:32| 851968 entries written so far.
2003/05/06 11:50:32| 917504 entries written so far.
2003/05/06 11:50:32| 983040 entries written so far.
2003/05/06 11:50:32| 1048576 entries written so far.
2003/05/06 11:50:32| 1114112 entries written so far.
2003/05/06 11:50:32| 1179648 entries written so far.
2003/05/06 11:50:32| 1245184 entries written so far.
2003/05/06 11:50:32| 1310720 entries written so far.
2003/05/06 11:50:32| 1376256 entries written so far.
2003/05/06 11:50:32| 1441792 entries written so far.
2003/05/06 11:50:32| 1507328 entries written so far.
2003/05/06 11:50:33| 1572864 entries written so far.
2003/05/06 11:50:33| 1638400 entries written so far.
2003/05/06 11:50:33| 1703936 entries written so far.
2003/05/06 11:50:33| 1769472 entries written so far.
2003/05/06 11:50:33| 1835008 entries written so far.
2003/05/06 11:50:33| 1900544 entries written so far.
2003/05/06 11:50:33| 1966080 entries written so far.
2003/05/06 11:50:33| 2031616 entries written so far.
2003/05/06 11:50:43| 2097152 entries written so far.
2003/05/06 11:50:43| 2162688 entries written so far.
2003/05/06 11:50:43| 2228224 entries written so far.
2003/05/06 11:50:43| 2293760 entries written so far.
2003/05/06 11:50:43| 2359296 entries written so far.
2003/05/06 11:50:43| 2424832 entries written so far.
2003/05/06 11:50:43| 2490368 entries written so far.
2003/05/06 11:50:43| 2555904 entries written so far.
2003/05/06 11:50:44| 2621440 entries written so far.
2003/05/06 11:50:44| 2686976 entries written so far.
2003/05/06 11:50:44| 2752512 entries written so far.
2003/05/06 11:50:44| 2818048 entries written so far.
2003/05/06 11:50:45| 2883584 entries written so far.
2003/05/06 11:50:45| 2949120 entries written so far.
2003/05/06 11:50:45| 3014656 entries written so far.
2003/05/06 11:50:45| 3080192 entries written so far.
2003/05/06 11:50:45| 3080192 entries written so far.
2003/05/06 11:50:45| 3145728 entries written so far.
2003/05/06 11:50:45| 3211264 entries written so far.
2003/05/06 11:50:45| 3276800 entries written so far.
2003/05/06 11:50:45| 3342336 entries written so far.
2003/05/06 11:50:46| 3407872 entries written so far.
2003/05/06 11:50:46| 3473408 entries written so far.
2003/05/06 11:50:46| 3538944 entries written so far.
2003/05/06 11:50:46| 3604480 entries written so far.
2003/05/06 11:50:46| 3670016 entries written so far.
2003/05/06 11:50:46| 3735552 entries written so far.
2003/05/06 11:50:46| 3801088 entries written so far.
2003/05/06 11:50:46| 3866624 entries written so far.
2003/05/06 11:50:46| 3932160 entries written so far.
2003/05/06 11:50:46| 3997696 entries written so far.
2003/05/06 11:50:46| 4063232 entries written so far.
2003/05/06 11:50:46| 4128768 entries written so far.
2003/05/06 11:50:46| 4194304 entries written so far.
2003/05/06 11:50:49| 4259840 entries written so far.
2003/05/06 11:50:49| 4325376 entries written so far.
2003/05/06 11:50:49| 4390912 entries written so far.
2003/05/06 11:50:49| 4456448 entries written so far.
2003/05/06 11:50:49| 4521984 entries written so far.
2003/05/06 11:50:49| 4587520 entries written so far.
2003/05/06 11:50:49| 4653056 entries written so far.
2003/05/06 11:50:49| Finished. Wrote 4691754 entries.
2003/05/06 11:50:49| Took 18.5 seconds (253523.6 entries/sec).
2003/05/06 11:50:53| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 11:50:53| Process ID 8834
2003/05/06 11:50:53| With 1024 file descriptors available
2003/05/06 11:50:53| DNS Socket created on FD 4
2003/05/06 11:50:53| Adding nameserver 192.168.100.30 from
/etc/resolv.conf
2003/05/06 11:50:53| Adding nameserver 203.202.108.115 from
/etc/resolv.conf
2003/05/06 11:50:53| logfileOpen: /var/log/squid/squidlogs.log: (6) No
such device or address
2003/05/06 11:50:53| Unlinkd pipe opened on FD 8
2003/05/06 11:50:53| Swap maxSize 61440000 KB, estimated 4726153 objects
2003/05/06 11:50:53| Target number of buckets: 236307
2003/05/06 11:50:53| Using 262144 Store buckets
2003/05/06 11:50:53| Max Mem size: 8192 KB
2003/05/06 11:50:53| Max Swap size: 61440000 KB
2003/05/06 11:50:53| Rebuilding storage in /squid (CLEAN)
2003/05/06 11:50:53| Rebuilding storage in /squid1 (CLEAN)
2003/05/06 11:50:53| Using Least Load store dir selection
2003/05/06 11:50:53| Set Current Directory to /squid
2003/05/06 11:50:53| Loaded Icons.
2003/05/06 11:50:53| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2003/05/06 11:50:53| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:50:53| WCCP Disabled.
2003/05/06 11:50:53| Ready to serve requests.
2003/05/06 11:50:53| Not currently OK to rewrite swap log.
2003/05/06 11:50:53| storeDirWriteCleanLogs: Operation aborted.
2003/05/06 11:50:56| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 11:50:56| Process ID 8837
2003/05/06 11:50:56| With 1024 file descriptors available
2003/05/06 11:50:56| DNS Socket created on FD 4
2003/05/06 11:50:56| Adding nameserver 192.168.100.30 from
/etc/resolv.conf
2003/05/06 11:50:56| Adding nameserver 203.202.108.115 from
/etc/resolv.conf
2003/05/06 11:50:56| logfileOpen: /var/log/squid/squidlogs.log: (6) No
such device or address
2003/05/06 11:50:56| Unlinkd pipe opened on FD 8
2003/05/06 11:50:56| Swap maxSize 61440000 KB, estimated 4726153 objects
2003/05/06 11:50:56| Target number of buckets: 236307
2003/05/06 11:50:56| Using 262144 Store buckets
2003/05/06 11:50:56| Max Mem size: 8192 KB
2003/05/06 11:50:56| Max Swap size: 61440000 KB
2003/05/06 11:50:56| Rebuilding storage in /squid (DIRTY)
2003/05/06 11:50:56| Rebuilding storage in /squid1 (DIRTY)
2003/05/06 11:50:56| Using Least Load store dir selection
2003/05/06 11:50:56| Set Current Directory to /squid
2003/05/06 11:50:56| Loaded Icons.
2003/05/06 11:50:57| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2003/05/06 11:50:57| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:50:57| WCCP Disabled.
2003/05/06 11:50:57| Ready to serve requests.
2003/05/06 11:50:57| Store rebuilding is 0.2% complete
2003/05/06 11:50:57| Not currently OK to rewrite swap log.
2003/05/06 11:50:57| storeDirWriteCleanLogs: Operation aborted.
2003/05/06 11:51:00| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 11:51:00| Process ID 8840
2003/05/06 11:51:00| With 1024 file descriptors available
2003/05/06 11:51:00| DNS Socket created on FD 4
2003/05/06 11:51:00| Adding nameserver 192.168.100.30 from
/etc/resolv.conf
2003/05/06 11:51:00| Adding nameserver 203.202.108.115 from
/etc/resolv.conf
2003/05/06 11:51:00| logfileOpen: /var/log/squid/squidlogs.log: (6) No
such device or address
2003/05/06 11:51:00| Unlinkd pipe opened on FD 8
2003/05/06 11:51:00| Swap maxSize 61440000 KB, estimated 4726153 objects
2003/05/06 11:51:00| Target number of buckets: 236307
2003/05/06 11:51:00| Using 262144 Store buckets
2003/05/06 11:51:00| Max Mem size: 8192 KB
2003/05/06 11:51:00| Max Swap size: 61440000 KB
2003/05/06 11:51:00| Rebuilding storage in /squid (DIRTY)
2003/05/06 11:51:00| Rebuilding storage in /squid1 (DIRTY)
2003/05/06 11:51:00| Using Least Load store dir selection
2003/05/06 11:51:00| Set Current Directory to /squid
2003/05/06 11:51:00| Loaded Icons.
2003/05/06 11:51:00| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2003/05/06 11:51:00| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:51:00| WCCP Disabled.
2003/05/06 11:51:00| Ready to serve requests.
2003/05/06 11:51:00| Store rebuilding is 0.2% complete
2003/05/06 11:51:01| Not currently OK to rewrite swap log.
2003/05/06 11:51:01| storeDirWriteCleanLogs: Operation aborted.
2003/05/06 11:51:04| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 11:51:04| Process ID 8843
2003/05/06 11:51:04| With 1024 file descriptors available
2003/05/06 11:51:04| DNS Socket created on FD 4
2003/05/06 11:51:04| Adding nameserver 192.168.100.30 from
/etc/resolv.conf
2003/05/06 11:51:04| Adding nameserver 203.202.108.115 from
/etc/resolv.conf
2003/05/06 11:51:04| logfileOpen: /var/log/squid/squidlogs.log: (6) No
such device or address
2003/05/06 11:51:04| Unlinkd pipe opened on FD 8
2003/05/06 11:51:04| Swap maxSize 61440000 KB, estimated 4726153 objects
2003/05/06 11:51:04| Target number of buckets: 236307
2003/05/06 11:51:04| Using 262144 Store buckets
2003/05/06 11:51:04| Max Mem size: 8192 KB
2003/05/06 11:51:04| Max Swap size: 61440000 KB
2003/05/06 11:51:04| Rebuilding storage in /squid (DIRTY)
2003/05/06 11:51:04| Rebuilding storage in /squid1 (DIRTY)
2003/05/06 11:51:04| Using Least Load store dir selection
2003/05/06 11:51:04| Set Current Directory to /squid
2003/05/06 11:51:04| Loaded Icons.
2003/05/06 11:51:04| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2003/05/06 11:51:04| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:51:04| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:51:04| WCCP Disabled.
2003/05/06 11:51:04| Ready to serve requests.
2003/05/06 11:51:04| Not currently OK to rewrite swap log.
2003/05/06 11:51:04| storeDirWriteCleanLogs: Operation aborted.
2003/05/06 11:51:07| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 11:51:07| Process ID 8846
2003/05/06 11:51:07| With 1024 file descriptors available
2003/05/06 11:51:07| DNS Socket created on FD 4
2003/05/06 11:51:07| Adding nameserver 192.168.100.30 from
/etc/resolv.conf
2003/05/06 11:51:07| Adding nameserver 203.202.108.115 from
/etc/resolv.conf
2003/05/06 11:51:07| logfileOpen: /var/log/squid/squidlogs.log: (6) No
such device or address
2003/05/06 11:51:07| Unlinkd pipe opened on FD 8
2003/05/06 11:51:07| Swap maxSize 61440000 KB, estimated 4726153 objects
2003/05/06 11:51:07| Target number of buckets: 236307
2003/05/06 11:51:07| Using 262144 Store buckets
2003/05/06 11:51:07| Max Mem size: 8192 KB
2003/05/06 11:51:07| Max Swap size: 61440000 KB
2003/05/06 11:51:07| Rebuilding storage in /squid (DIRTY)
2003/05/06 11:51:07| Rebuilding storage in /squid1 (DIRTY)
2003/05/06 11:51:07| Using Least Load store dir selection
2003/05/06 11:51:07| Set Current Directory to /squid
2003/05/06 11:51:07| Loaded Icons.
2003/05/06 11:51:08| Accepting HTTP connections at 0.0.0.0, port 3128,
FD 12.
2003/05/06 11:51:08| Accepting ICP messages at 0.0.0.0, port 3130, FD
13.
2003/05/06 11:51:08| WCCP Disabled.
2003/05/06 11:51:08| Ready to serve requests.
2003/05/06 11:51:08| Store rebuilding is 0.2% complete
2003/05/06 11:51:08| Not currently OK to rewrite swap log.
2003/05/06 11:51:08| storeDirWriteCleanLogs: Operation aborted.
2003/05/06 12:01:11| Starting Squid Cache version 2.4.STABLE6 for
i386-redhat-linux-gnu...
2003/05/06 12:01:11| Process ID 8963

-----Original Message-----
From: Henrik Nordstrom [mailto:hno@squid-cache.org]
Sent: Tuesday, 6 May 2003 7:28 PM
To: rsa@acl.edu.au
Cc: squid-users@squid-cache.org
Subject: Re: [squid-users] Logging problem

tis 2003-05-06 klockan 10.49 skrev Ramzi S. Abdallah:
> I am running squid-2.4.STABLE6 that serves approximately 400 users.
> The server has been running stably for almost 2 years with no problems

> until I recently changed the cache_access_log entry in squid.conf to
> log into a block special files which I created using the command mknod

> /var/log/squid/squidacct.log p
>
> Now when the server is in high usage it crash with the following
> errors:
>
> May 6 11:50:49 proxy (squid): logfileWrite:
> /var/log/squid/squidlogs.log: (11) Resource temporarily unavailable
> May 6 11:50:50 proxy squid[894]: Squid Parent: child process 1027
> exited due to signal 6

cache.log should have more information on what the reason to the abot
is, but I think the reason is that your log processing script cannot
keep up with the rate of log entries sent by Squid.

I would recommend using the File::Tail perl module to monitor the log
file rather than logging via a pipe. This allows your log processor to
process the log when it can with no impact on Squid.

    http://search.cpan.org/search?module=File::Tail

Regards
Henrik

-- 
Donations welcome if you consider my Free Squid support helpful.
https://www.paypal.com/xclick/business=hno%40squid-cache.org
Please consult the Squid FAQ and other available documentation before
asking Squid questions, and use the squid-users mailing-list when no
answer can be found. Private support questions is only answered for a
fee or as part of a commercial Squid support contract.
If you need commercial Squid support or cost effective Squid and
firewall appliances please refer to MARA Systems AB, Sweden
http://www.marasystems.com/, info@marasystems.com