Re: [squid-users] Crashed squid 2.5.STABLE11

My guess is that, yes, you're filling the "/var" partition when you rotate
those logs.

Tim Rainier
Information Services, Kalsec, INC
trainier@kalsec.com

"Lucia Di Occhi" <saint_lucy@hotmail.com> wrote on 10/12/2005 09:12:17 AM:

> Here is the output from df -h
>
> Filesystem Size Used Avail Use% Mounted on
> /dev/sda3 7.9G 1.5G 6.1G 20% /
> /dev/sda1 99M 12M 83M 13% /boot
> /dev/sda6 109G 45G 59G 44% /cache
> none 1.8G 0 1.8G 0% /dev/shm
> /dev/sda2 16G 13G 2.6G 83% /var
>
> It looks like squid started crashing only 2 days ago after the
logrotate,
> here is the script:
>
> /var/log/squid/access.log {
> daily
> rotate 30
> copytruncate
> compress
> notifempty
> missingok
> }
> /var/log/squid/cache.log {
> daily
> rotate 30
> copytruncate
> compress
> notifempty
> missingok
> }
>
> /var/log/squid/store.log {
> daily
> rotate 30
> copytruncate
> compress
> notifempty
> missingok
> # This script asks squid to rotate its logs on its own.
> # Restarting squid is a long process and it is not worth
> # doing it just to rotate logs
> # postrotate
> # /usr/sbin/squid -k rotate
> # endscript
> }
>
> It has been working fine for a long time, so I am not quite sure why it
is
> now crashing. Could it be that our internet traffic has increased and
the
> logs are getting so large than when they are rotating and zipping there
> isn't enough space on /var?
> >From: trainier@kalsec.com
> >To: squid-users@squid-cache.org
> >Subject: Re: [squid-users] Crashed squid 2.5.STABLE11
> >Date: Tue, 11 Oct 2005 16:21:47 -0400
> >
> >Sorry. That's `df -h` as opposed to `du -h`.
> >
> >Tim Rainier
> >Information Services, Kalsec, INC
> >trainier@kalsec.com
> >
> >
> >
> >trainier@kalsec.com
> >10/11/2005 03:38 PM
> >
> >To
> >squid-users@squid-cache.org
> >cc
> >
> >Subject
> >Re: [squid-users] Crashed squid 2.5.STABLE11
> >
> >
> >
> >
> >
> >
> >First, and foremost, I would hesitate rotating the store log. Henrik
and
> >probably several others, can verify that notion.
> >Second, do a `du -h` and email the output back.
> >
> >Tim Rainier
> >Information Services, Kalsec, INC
> >trainier@kalsec.com
> >
> >
> >
> >"Lucia Di Occhi" <saint_lucy@hotmail.com>
> >10/11/2005 02:29 PM
> >
> >To
> >trainier@kalsec.com, squid-users@squid-cache.org
> >cc
> >
> >Subject
> >Re: [squid-users] Crashed squid 2.5.STABLE11
> >
> >
> >
> >
> >
> >
> >Sure it does and I keep 30 days worth of logs:
> >
> >squid[~]ls -alh /var/log/squid/
> >total 12G
> >drwxr-x--- 2 squid squid 4.0K Oct 11 04:07 .
> >drwxr-xr-x 12 root root 4.0K Oct 9 04:04 ..
> >-rw-r--r-- 1 squid squid 365M Oct 11 14:28 access.log
> >-rw-r--r-- 1 squid squid 47M Oct 2 04:02 access.log.10.gz
> >-rw-r--r-- 1 squid squid 140M Oct 1 04:04 access.log.11.gz
> >-rw-r--r-- 1 squid squid 172M Sep 30 04:04 access.log.12.gz
> >-rw-r--r-- 1 squid squid 174M Sep 29 04:04 access.log.13.gz
> >-rw-r--r-- 1 squid squid 155M Sep 28 04:04 access.log.14.gz
> >-rw-r--r-- 1 squid squid 174M Sep 27 04:04 access.log.15.gz
> >-rw-r--r-- 1 squid squid 90M Sep 26 04:03 access.log.16.gz
> >-rw-r--r-- 1 squid squid 66M Sep 25 04:03 access.log.17.gz
> >-rw-r--r-- 1 squid squid 146M Sep 24 04:04 access.log.18.gz
> >-rw-r--r-- 1 squid squid 158M Sep 23 04:04 access.log.19.gz
> >-rw-r--r-- 1 squid squid 177M Oct 11 04:04 access.log.1.gz
> >-rw-r--r-- 1 squid squid 160M Sep 22 04:04 access.log.20.gz
> >-rw-r--r-- 1 squid squid 152M Sep 21 04:04 access.log.21.gz
> >-rw-r--r-- 1 squid squid 163M Sep 20 04:04 access.log.22.gz
> >-rw-r--r-- 1 squid squid 85M Sep 19 04:09 access.log.23.gz
> >-rw-r--r-- 1 squid squid 64M Sep 18 04:02 access.log.24.gz
> >-rw-r--r-- 1 squid squid 127M Sep 17 04:04 access.log.25.gz
> >-rw-r--r-- 1 squid squid 143M Sep 16 04:04 access.log.26.gz
> >-rw-r--r-- 1 squid squid 145M Sep 15 04:04 access.log.27.gz
> >-rw-r--r-- 1 squid squid 143M Sep 14 04:04 access.log.28.gz
> >-rw-r--r-- 1 squid squid 135M Sep 13 04:03 access.log.29.gz
> >-rw-r--r-- 1 squid squid 100M Oct 10 04:03 access.log.2.gz
> >-rw-r--r-- 1 squid squid 63M Sep 12 04:03 access.log.30.gz
> >-rw-r--r-- 1 squid squid 87M Oct 9 04:03 access.log.3.gz
> >-rw-r--r-- 1 squid squid 144M Oct 8 04:04 access.log.4.gz
> >-rw-r--r-- 1 squid squid 157M Oct 7 04:04 access.log.5.gz
> >-rw-r--r-- 1 squid squid 169M Oct 6 04:05 access.log.6.gz
> >-rw-r--r-- 1 squid squid 158M Oct 5 04:04 access.log.7.gz
> >-rw-r--r-- 1 squid squid 176M Oct 4 04:04 access.log.8.gz
> >-rw-r--r-- 1 squid squid 80M Oct 3 04:03 access.log.9.gz
> >-rw-r--r-- 1 squid squid 34K Oct 11 14:08 cache.log
> >-rw-r--r-- 1 squid squid 8.5K Oct 2 04:02 cache.log.10.gz
> >-rw-r--r-- 1 squid squid 12K Oct 1 04:04 cache.log.11.gz
> >-rw-r--r-- 1 squid squid 19K Sep 30 04:04 cache.log.12.gz
> >-rw-r--r-- 1 squid squid 31K Sep 29 04:04 cache.log.13.gz
> >-rw-r--r-- 1 squid squid 17K Sep 28 04:04 cache.log.14.gz
> >-rw-r--r-- 1 squid squid 21K Sep 27 04:04 cache.log.15.gz
> >-rw-r--r-- 1 squid squid 13K Sep 26 04:03 cache.log.16.gz
> >-rw-r--r-- 1 squid squid 14K Sep 25 04:03 cache.log.17.gz
> >-rw-r--r-- 1 squid squid 27K Sep 24 04:04 cache.log.18.gz
> >-rw-r--r-- 1 squid squid 20K Sep 23 04:04 cache.log.19.gz
> >-rw-r--r-- 1 squid squid 15K Oct 11 04:04 cache.log.1.gz
> >-rw-r--r-- 1 squid squid 20K Sep 22 04:04 cache.log.20.gz
> >-rw-r--r-- 1 squid squid 18K Sep 21 04:04 cache.log.21.gz
> >-rw-r--r-- 1 squid squid 14K Sep 20 04:04 cache.log.22.gz
> >-rw-r--r-- 1 squid squid 12K Sep 19 04:09 cache.log.23.gz
> >-rw-r--r-- 1 squid squid 8.6K Sep 18 04:02 cache.log.24.gz
> >-rw-r--r-- 1 squid squid 17K Sep 17 04:04 cache.log.25.gz
> >-rw-r--r-- 1 squid squid 19K Sep 16 04:04 cache.log.26.gz
> >-rw-r--r-- 1 squid squid 22K Sep 15 04:04 cache.log.27.gz
> >-rw-r--r-- 1 squid squid 17K Sep 14 04:04 cache.log.28.gz
> >-rw-r--r-- 1 squid squid 17K Sep 13 04:03 cache.log.29.gz
> >-rw-r--r-- 1 squid squid 7.8K Oct 10 04:03 cache.log.2.gz
> >-rw-r--r-- 1 squid squid 12K Sep 12 04:03 cache.log.30.gz
> >-rw-r--r-- 1 squid squid 9.1K Oct 9 04:03 cache.log.3.gz
> >-rw-r--r-- 1 squid squid 10K Oct 8 04:04 cache.log.4.gz
> >-rw-r--r-- 1 squid squid 13K Oct 7 04:04 cache.log.5.gz
> >-rw-r--r-- 1 squid squid 16K Oct 6 04:05 cache.log.6.gz
> >-rw-r--r-- 1 squid squid 11K Oct 5 04:04 cache.log.7.gz
> >-rw-r--r-- 1 squid squid 17K Oct 4 04:04 cache.log.8.gz
> >-rw-r--r-- 1 squid squid 9.3K Oct 3 04:03 cache.log.9.gz
> >-rw-r--r-- 1 root root 2.2K Oct 11 08:08 squid.out
> >-rw-r--r-- 1 squid squid 395M Oct 11 14:28 store.log
> >-rw-r--r-- 1 squid squid 85M Oct 2 04:03 store.log.10.gz
> >-rw-r--r-- 1 squid squid 235M Oct 1 04:06 store.log.11.gz
> >-rw-r--r-- 1 squid squid 282M Sep 30 04:07 store.log.12.gz
> >-rw-r--r-- 1 squid squid 285M Sep 29 04:06 store.log.13.gz
> >-rw-r--r-- 1 squid squid 255M Sep 28 04:06 store.log.14.gz
> >-rw-r--r-- 1 squid squid 287M Sep 27 04:06 store.log.15.gz
> >-rw-r--r-- 1 squid squid 157M Sep 26 04:04 store.log.16.gz
> >-rw-r--r-- 1 squid squid 117M Sep 25 04:04 store.log.17.gz
> >-rw-r--r-- 1 squid squid 246M Sep 24 04:06 store.log.18.gz
> >-rw-r--r-- 1 squid squid 262M Sep 23 04:07 store.log.19.gz
> >-rw-r--r-- 1 squid squid 296M Oct 11 04:07 store.log.1.gz
> >-rw-r--r-- 1 squid squid 264M Sep 22 04:06 store.log.20.gz
> >-rw-r--r-- 1 squid squid 252M Sep 21 04:06 store.log.21.gz
> >-rw-r--r-- 1 squid squid 273M Sep 20 04:06 store.log.22.gz
> >-rw-r--r-- 1 squid squid 149M Sep 19 04:10 store.log.23.gz
> >-rw-r--r-- 1 squid squid 113M Sep 18 04:03 store.log.24.gz
> >-rw-r--r-- 1 squid squid 213M Sep 17 04:05 store.log.25.gz
> >-rw-r--r-- 1 squid squid 236M Sep 16 04:06 store.log.26.gz
> >-rw-r--r-- 1 squid squid 237M Sep 15 04:06 store.log.27.gz
> >-rw-r--r-- 1 squid squid 233M Sep 14 04:06 store.log.28.gz
> >-rw-r--r-- 1 squid squid 221M Sep 13 04:05 store.log.29.gz
> >-rw-r--r-- 1 squid squid 178M Oct 10 04:05 store.log.2.gz
> >-rw-r--r-- 1 squid squid 108M Sep 12 04:03 store.log.30.gz
> >-rw-r--r-- 1 squid squid 155M Oct 9 04:04 store.log.3.gz
> >-rw-r--r-- 1 squid squid 239M Oct 8 04:06 store.log.4.gz
> >-rw-r--r-- 1 squid squid 263M Oct 7 04:07 store.log.5.gz
> >-rw-r--r-- 1 squid squid 280M Oct 6 04:07 store.log.6.gz
> >-rw-r--r-- 1 squid squid 261M Oct 5 04:06 store.log.7.gz
> >-rw-r--r-- 1 squid squid 293M Oct 4 04:07 store.log.8.gz
> >-rw-r--r-- 1 squid squid 141M Oct 3 04:04 store.log.9.gz
> >
> >
> >
> > >From: trainier@kalsec.com
> > >To: squid-users@squid-cache.org
> > >Subject: Re: [squid-users] Crashed squid 2.5.STABLE11
> > >Date: Tue, 11 Oct 2005 11:28:56 -0400
> > >
> > >Does this file exist? -> /var/log/squid/store.log
> > >Does the user running squid have permission to write to it?
> > >
> > >Basically, do an ls -lah /var/log/squid
> > >and paste the output into the reply email.
> > >
> > >
> > >
> > >Tim Rainier
> > >Information Services, Kalsec, INC
> > >trainier@kalsec.com
> > >
> > >"Lucia Di Occhi" <saint_lucy@hotmail.com> wrote on 10/11/2005
10:21:52
> >AM:
> > >
> > > > Linux squid 2.6.12-1.1378_FC3smp #1 SMP Wed Sep 14 04:52:36 EDT
2005
> > >i686
> > > > i686 i386 GNU/Linux
> > > >
> > > > Squid Cache: Version 2.5.STABLE11
> > > > configure options: --program-prefix= --prefix=/usr
--exec-prefix=/usr
> > > > --bindir=/usr/bin --sbindir=/usr/sbin --sysconfdir=/etc
> > >--datadir=/usr/share
> > > > --includedir=/usr/include --libdir=/usr/lib
--libexecdir=/usr/libexec
> > > > --localstatedir=/var --sharedstatedir=/usr/com
--mandir=/usr/share/man
> > > > --infodir=/usr/share/info --exec_prefix=/usr --bindir=/usr/sbin
> > > > --libexecdir=/usr/lib/squid --localstatedir=/var
> >--sysconfdir=/etc/squid
> > >
> > > > --enable-poll --enable-removal-policies=heap,lru
> > > > --enable-storeio=aufs,coss,diskd,null,ufs --enable-linux-netfilter
> > > > --with-pthreads --enable-useragent-log --enable-referer-log
> > > > --disable-dependency-tracking --enable-cachemgr-hostname=localhost
> > > > --disable-ident-lookups --enable-truncate --enable-underscores
> > > > --datadir=/usr/share
> > > >
> > > > Reading specs from /usr/lib/gcc/i386-redhat-linux/3.4.4/specs
> > > > Configured with: ../configure --prefix=/usr
--mandir=/usr/share/man
> > > > --infodir=/usr/share/info --enable-shared --enable-threads=posix
> > > > --disable-checking --with-system-zlib --enable-__cxa_atexit
> > > > --disable-libunwind-exceptions --enable-java-awt=gtk
> > > > --host=i386-redhat-linux
> > > > Thread model: posix
> > > > gcc version 3.4.4 20050721 (Red Hat 3.4.4-2)
> > > >
> > > > From cache.log
> > > >
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {403,14,URL,/vanityParser.cfm}
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {404,*,URL,/test.htm}
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {500,100,URL,/iisHelp/common/500-100.asp}
> > > > 2005/10/11 02:31:33| ctx: exit level 0
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {403,14,URL,/vanityParser.cfm}
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {404,*,URL,/test.htm}
> > > > 2005/10/11 02:31:33| WARNING: unparseable HTTP header field
> > > > {500,100,URL,/iisHelp/common/500-100.asp}
> > > > 2005/10/11 02:49:09| httpReadReply: Excess data from "GET
> > > > http://hpdjjs.com/cgi-bin/jumpstation.py?query=overlandserver"
> > > > 2005/10/11 03:04:53| httpReadReply: Excess data from "HEAD
> > > > http://www.overture.com/"
> > > > 2005/10/11 03:23:51| ctx: enter level 0:
> > > > 'http://viewmorepics.myspace.com/index.cfm?
> > > >
> >
>
>fuseaction=viewImage&friendID=28636111&imageID=251293587&Mytoken=8B0D8DCC-7FD4-4333-991911DE8DEF62D12839554968'
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {403,14,URL,/vanityParser.cfm}
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {404,*,URL,/test.htm}
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {500,100,URL,/iisHelp/common/500-100.asp}
> > > > 2005/10/11 03:23:51| ctx: exit level 0
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {403,14,URL,/vanityParser.cfm}
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {404,*,URL,/test.htm}
> > > > 2005/10/11 03:23:51| WARNING: unparseable HTTP header field
> > > > {500,100,URL,/iisHelp/common/500-100.asp}
> > > > 2005/10/11 03:29:59| httpReadReply: Excess data from "HEAD
> > > > http://www.overture.com/"
> > > > 2005/10/11 04:02:53| storeDirWriteCleanLogs: Starting...
> > > > 2005/10/11 04:02:53| WARNING: Closing open FD 12
> > > > 2005/10/11 04:02:54| 65536 entries written so far.
> > > > 2005/10/11 04:02:54| 131072 entries written so far.
> > > > 2005/10/11 04:02:54| 196608 entries written so far.
> > > > 2005/10/11 04:02:54| 262144 entries written so far.
> > > > 2005/10/11 04:02:54| 327680 entries written so far.
> > > > 2005/10/11 04:02:54| 393216 entries written so far.
> > > > 2005/10/11 04:02:54| 458752 entries written so far.
> > > > 2005/10/11 04:02:54| 524288 entries written so far.
> > > > 2005/10/11 04:02:54| 589824 entries written so far.
> > > > 2005/10/11 04:02:54| 655360 entries written so far.
> > > > 2005/10/11 04:02:54| 720896 entries written so far.
> > > > 2005/10/11 04:02:54| 786432 entries written so far.
> > > > 2005/10/11 04:02:54| 851968 entries written so far.
> > > > 2005/10/11 04:02:54| 917504 entries written so far.
> > > > 2005/10/11 04:02:54| 983040 entries written so far.
> > > > 2005/10/11 04:02:54| 1048576 entries written so far.
> > > > 2005/10/11 04:02:54| 1114112 entries written so far.
> > > > 2005/10/11 04:02:54| 1179648 entries written so far.
> > > > 2005/10/11 04:02:54| 1245184 entries written so far.
> > > > 2005/10/11 04:02:54| 1310720 entries written so far.
> > > > 2005/10/11 04:02:55| 1376256 entries written so far.
> > > > 2005/10/11 04:02:55| 1441792 entries written so far.
> > > > 2005/10/11 04:02:55| 1507328 entries written so far.
> > > > 2005/10/11 04:02:55| 1572864 entries written so far.
> > > > 2005/10/11 04:02:55| 1638400 entries written so far.
> > > > 2005/10/11 04:02:55| 1703936 entries written so far.
> > > > 2005/10/11 04:02:55| 1769472 entries written so far.
> > > > 2005/10/11 04:02:55| 1835008 entries written so far.
> > > > 2005/10/11 04:02:55| 1900544 entries written so far.
> > > > 2005/10/11 04:02:55| 1966080 entries written so far.
> > > > 2005/10/11 04:02:55| 2031616 entries written so far.
> > > > 2005/10/11 04:02:55| 2097152 entries written so far.
> > > > 2005/10/11 04:02:55| 2162688 entries written so far.
> > > > 2005/10/11 04:02:56| 2228224 entries written so far.
> > > > 2005/10/11 04:02:56| 2293760 entries written so far.
> > > > 2005/10/11 04:02:56| 2359296 entries written so far.
> > > > 2005/10/11 04:02:56| 2424832 entries written so far.
> > > > 2005/10/11 04:02:56| 2490368 entries written so far.
> > > > 2005/10/11 04:02:56| 2555904 entries written so far.
> > > > 2005/10/11 04:02:56| 2621440 entries written so far.
> > > > 2005/10/11 04:02:56| 2686976 entries written so far.
> > > > 2005/10/11 04:02:56| 2752512 entries written so far.
> > > > 2005/10/11 04:02:57| 2818048 entries written so far.
> > > > 2005/10/11 04:02:57| 2883584 entries written so far.
> > > > 2005/10/11 04:03:00| Finished. Wrote 2885180 entries.
> > > > 2005/10/11 04:03:00| Took 6.3 seconds (459816.8 entries/sec).
> > > > FATAL: logfileWrite: /var/log/squid/store.log: (0) Success
> > > >
> > > > Squid Cache (Version 2.5.STABLE11): Terminated abnormally.
> > > > CPU Usage: 52558.798 seconds = 17715.523 user + 34843.275 sys
> > > > Maximum Resident Size: 0 KB
> > > > Page faults with physical i/o: 0
> > > > Memory usage for squid via mallinfo():
> > > > total space in arena: 1616044 KB
> > > > Ordinary blocks: 1589468 KB 289245 blks
> > > > Small blocks: 0 KB 0 blks
> > > > Holding blocks: 3284 KB 7 blks
> > > > Free Small blocks: 0 KB
> > > > Free Ordinary blocks: 26575 KB
> > > > Total in use: 1592752 KB 99%
> > > > Total free: 26575 KB 2%
> > > > 2005/10/11 04:03:07| Starting Squid Cache version 2.5.STABLE11 for
> > > > i686-pc-linux-gnu...
> > > > ...
> > > > ...
> > > > ...
> > > >
> > > > squid[/tmp]tail -10000 access.log.1 | grep overture
> > > > 1129017007.008 455 127.0.0.1 TCP_MISS/200 13106 GET
> > > > http://www.thesearchster.com/cgi-bin/overture/allsize.cgi? -
> > > > DIRECT/209.225.11.243 img/png
> > > > 1129017563.877 222 127.0.0.1 TCP_MISS/200 3633 GET
> > > > http://cmhtml.vendare.overture.com/d/search/p/vendare/js/ctxt/? -
> > > > DIRECT/64.209.232.207 application/x-javascript
> > > > 1129017763.617 384 127.0.0.1 TCP_MISS/200 5845 GET
> > > > http://ypn-js.overture.com/partner/js/ypn.js -
DIRECT/63.163.102.61
> > > > application/x-javascript
> > > > 1129017764.139 441 127.0.0.1 TCP_MISS/200 4021 GET
> > > > http://ypn-js.overture.com/d/search/p/ypn/jsads/? -
> >DIRECT/63.163.102.61
> > >
> > > > text/html
> > > > 1129017764.548 595 127.0.0.1 TCP_MISS/200 6987 GET
> > > > http://ypn-js.overture.com/d/search/p/ypn/jsads/? -
> >DIRECT/63.163.102.61
> > >
> > > > text/html
> > > >
> > > >
> > > > I hope this helps.
> > > >
> > > > _________________________________________________________________
> > > > Express yourself instantly with MSN Messenger! Download today -
it's
> > >FREE!
> > > > http://messenger.msn.click-url.com/go/onm00200471ave/direct/01/
> > > >
> > >
> >
> >_________________________________________________________________
> >Express yourself instantly with MSN Messenger! Download today - it's
FREE!
> >
> >
> >http://messenger.msn.click-url.com/go/onm00200471ave/direct/01/
> >
> >
> >
> >
> >
>
> _________________________________________________________________
> Is your PC infected? Get a FREE online computer virus scan from McAfee®
> Security. http://clinic.mcafee.com/clinic/ibuy/campaign.asp?cid=3963
>
Received on Wed Oct 12 2005 - 07:58:17 MDT