[squid-users] More access.log questions

From: <wh_at_msdrd.com>
Date: Tue, 16 Dec 2008 07:43:50 -0700

Hello.

Guys, sorry to post so many questions regarding access.log but, I'm
trying to understand what is squid actually doing and if is working
correctly. I don't understand what all the stuff in the access.log file
are. I check the log everyday. I see something different every time I
check. Below is the latest on access.log and I don't understand why the
cache now is "DIRTY", what is assertion failed, 1 swapin MD5 mismatches,
WARNING: newer swaplog entry for dirno 0, fileno 0000013B, and all those
weird characters at the end of the log:
008.LMP%C2%BB%C2%A6%C2%AB_A.zip?Cache'
Ì«* 2008 14:02:37 GMT}ARNING: suspicious CR characters in HTTP header
{Date: Tue, 16 ð@

Please help me understand what's going on.

Thanks in advanced.

2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches
2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters
{Host: digdug.divxnetworks.com
responseType: text/xml
User-Agent: DivX Player 2.0
Cookie:
GUID=FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF}
2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches
2008/12/15 22:06:28| assertion failed: client_side.cc:2479:
"conn->in.abortedSize == (size_t)conn->bodySizeLeft()"
2008/12/15 22:06:31| Extension method 'NICK' added, enum=27
2008/12/15 22:06:31| Starting Squid Cache version 3.0.PRE5 for
i486-pc-linux-gnu...
2008/12/15 22:06:31| Process ID 5075
2008/12/15 22:06:31| With 1024 file descriptors available
2008/12/15 22:06:31| DNS Socket created at 0.0.0.0, port 38826, FD 8
2008/12/15 22:06:31| Adding nameserver 200.42.213.11 from squid.conf
2008/12/15 22:06:31| Adding nameserver 200.42.213.21 from squid.conf
2008/12/15 22:06:31| Unlinkd pipe opened on FD 13
2008/12/15 22:06:31| Swap maxSize 102400000 KB, estimated 7876923
objects
2008/12/15 22:06:31| Target number of buckets: 393846
2008/12/15 22:06:31| Using 524288 Store buckets
2008/12/15 22:06:31| Max Mem size: 102400 KB
2008/12/15 22:06:31| Max Swap size: 102400000 KB
2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY)
2008/12/15 22:06:31| Using Least Load store dir selection
2008/12/15 22:06:31| Current Directory is /
2008/12/15 22:06:31| Loaded Icons.
2008/12/15 22:06:31| Accepting transparently proxied HTTP connections at
192.168.2.1, port 3128, FD 15.
2008/12/15 22:06:31| HTCP Disabled.
2008/12/15 22:06:31| WCCP Disabled.
2008/12/15 22:06:31| Ready to serve requests.
2008/12/15 22:06:32| Store rebuilding is 1.5% complete
2008/12/15 22:06:47| Store rebuilding is 30.2% complete
2008/12/15 22:06:50| WARNING: newer swaplog entry for dirno 0, fileno
00000062
2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno
00000132
2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno
00000135
2008/12/15 22:07:02| Store rebuilding is 74.0% complete
2008/12/15 22:07:13| Done reading /var/log/squid/cache swaplog (271062
entries)
2008/12/15 22:07:13| Finished rebuilding storage from disk.
2008/12/15 22:07:13| 268975 Entries scanned
2008/12/15 22:07:13| 0 Invalid entries.
2008/12/15 22:07:13| 0 With invalid flags.
2008/12/15 22:07:13| 268719 Objects loaded.
2008/12/15 22:07:13| 0 Objects expired.
2008/12/15 22:07:13| 185 Objects cancelled.
2008/12/15 22:07:13| 1788 Duplicate URLs purged.
2008/12/15 22:07:13| 26 Swapfile clashes avoided.
2008/12/15 22:07:13| Took 41.2 seconds (6517.7 objects/sec).
2008/12/15 22:07:13| Beginning Validation Procedure
2008/12/15 22:07:13| 262144 Entries Validated so far.
2008/12/15 22:07:13| storeLateRelease: released 2 objects
2008/12/15 22:07:14| 524288 Entries Validated so far.
2008/12/15 22:07:14| Completed Validation Procedure
2008/12/15 22:07:14| Validated 533992 Entries
2008/12/15 22:07:14| store_swap_size = 15636412
2008/12/15 22:14:36| WARNING: 1 swapin MD5 mismatches
2008/12/15 22:18:39| ctx: enter level 0:
'http://74.125.93.104/translate_c?hl=es&sl=en&u=http://nov1.m.yahoo.net/nov0/Gftp6CpGg29dN5ckuR3PK
Q__/1228216588/nov_ses_id033_tl5iz1xll0pimbet/www.kqzyfj.com/click-886648-2202641&prev=/search%3Fq%3Dwww.ebey.com%26hl%3Des%26lr%3D%26client
%3Dfirefox-a%26channel%3Ds%26rls%3Dorg.mozilla:es-ES:official%26hs%3DTNk%26sa%3DG&usg=ALkJrhjCucbvExTxNxW7LnRua07fpKTBmg'
2008/12/15 22:18:39| ctx: enter level 1:
'http://74.125.93.104/translate_c?hl=es&sl=en&u=http://nov1.m.yahoo.net/nov0/Gftp6CpGg29dN5ckuR3PK
Q__/1228216588/nov_ses_id033_tl5iz1xll0pimbet/www.kqzyfj.com/click-886648-2202641&prev=/search%3Fq%3Dwww.ebey.com%26hl%3Des%26lr%3D%26client
%3Dfirefox-a%26channel%3Ds%26rls%3Dorg.mozilla:es-ES:official%26hs%3DTNk%26sa%3DG&usg=ALkJrhjCucbvExTxNxW7LnRua07fpKTBmg'
2008/12/15 22:18:39| HttpStateData::cacheableReply: unknown http status
code in reply
2008/12/15 23:14:48| ctx: exit levels from 1 down to 0
2008/12/15 23:14:48| WARNING: 10 swapin MD5 mismatches
2008/12/15 23:14:58| assertion failed: client_side.cc:2479:
"conn->in.abortedSize == (size_t)conn->bodySizeLeft()"
2008/12/15 23:15:01| Extension method 'NICK' added, enum=27
2008/12/15 23:15:01| Starting Squid Cache version 3.0.PRE5 for
i486-pc-linux-gnu...
2008/12/15 23:15:01| Process ID 5143
2008/12/15 23:15:01| With 1024 file descriptors available
2008/12/15 23:15:01| DNS Socket created at 0.0.0.0, port 38948, FD 8
2008/12/15 23:15:01| Adding nameserver 200.42.213.11 from squid.conf
2008/12/15 23:15:01| Adding nameserver 200.42.213.21 from squid.conf
2008/12/15 23:15:01| Unlinkd pipe opened on FD 13
2008/12/15 23:15:01| Swap maxSize 102400000 KB, estimated 7876923
objects
2008/12/15 23:15:01| Target number of buckets: 393846
2008/12/15 23:15:01| Using 524288 Store buckets
2008/12/15 23:15:01| Max Mem size: 102400 KB
2008/12/15 23:15:01| Max Swap size: 102400000 KB
2008/12/15 23:15:01| Rebuilding storage in /var/log/squid/cache (DIRTY)
2008/12/15 23:15:01| Using Least Load store dir selection
2008/12/15 23:15:01| Current Directory is /
2008/12/15 23:15:01| Loaded Icons.
2008/12/15 23:15:01| Accepting transparently proxied HTTP connections at
192.168.2.1, port 3128, FD 15.
2008/12/15 23:15:01| HTCP Disabled.
2008/12/15 23:15:01| WCCP Disabled.
2008/12/15 23:15:01| Ready to serve requests.
2008/12/15 23:15:02| Store rebuilding is 1.5% complete
2008/12/15 23:15:17| Store rebuilding is 52.1% complete
2008/12/15 23:15:20| WARNING: newer swaplog entry for dirno 0, fileno
0000013B
2008/12/15 23:15:20| WARNING: newer swaplog entry for dirno 0, fileno
00000144
2008/12/15 23:15:21| WARNING: newer swaplog entry for dirno 0, fileno
00000149
2008/12/15 23:15:22| WARNING: newer swaplog entry for dirno 0, fileno
0000015D
2008/12/15 23:15:22| WARNING: newer swaplog entry for dirno 0, fileno
00000163
2008/12/15 23:15:25| WARNING: newer swaplog entry for dirno 0, fileno
0000017C
2008/12/15 23:15:26| WARNING: newer swaplog entry for dirno 0, fileno
000003AE
2008/12/15 23:15:27| WARNING: newer swaplog entry for dirno 0, fileno
000003AF
2008/12/15 23:15:27| WARNING: newer swaplog entry for dirno 0, fileno
00011628
2008/12/15 23:15:28| Done reading /var/log/squid/cache swaplog (274930
entries)
2008/12/15 23:15:28| Finished rebuilding storage from disk.
2008/12/15 23:15:28| 272635 Entries scanned
2008/12/15 23:15:28| 0 Invalid entries.
2008/12/15 23:15:28| 0 With invalid flags.
2008/12/15 23:15:28| 272297 Objects loaded.
2008/12/15 23:15:28| 0 Objects expired.
2008/12/15 23:15:28| 235 Objects cancelled.
2008/12/15 23:15:28| 2003 Duplicate URLs purged.
2008/12/15 23:15:28| 68 Swapfile clashes avoided.
2008/12/15 23:15:28| Took 26.3 seconds (10343.1 objects/sec).
2008/12/15 23:15:28| Beginning Validation Procedure
2008/12/15 23:15:28| storeLateRelease: released 18 objects
2008/12/15 23:15:29| Completed Validation Procedure
2008/12/15 23:15:29| Validated 540718 Entries
2008/12/15 23:15:29| store_swap_size = 15821416
2008/12/15 23:22:59| http.cc(1920) sendRequestEntity body_reader became
NULL, aborting transaction
2008/12/15 23:24:50| WARNING: 1 swapin MD5 mismatches
2008/12/15 23:51:06| WARNING: 10 swapin MD5 mismatches
2008/12/15 23:55:05| http.cc(1920) sendRequestEntity body_reader became
NULL, aborting transaction
2008/12/15 23:55:05| http.cc(1920) sendRequestEntity body_reader became
NULL, aborting transaction
2008/12/16 10:02:38| ctx: enter level 0:
'http://download153.mediafire.com/y7t4tdgbzrmg/mzcynty23ek/%C2%BB%C2%A6%C2%ABMerengue.Top.30.Dec.2
008.LMP%C2%BB%C2%A6%C2%AB_A.zip?Cache'
Ì«* 2008 14:02:37 GMT}ARNING: suspicious CR characters in HTTP header
{Date: Tue, 16 ð@
Received on Tue Dec 16 2008 - 14:43:59 MST

This archive was generated by hypermail 2.2.0 : Wed Dec 17 2008 - 12:00:03 MST