[squid-users] More access.log questions
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 013B, 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=} 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 10240 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: 10240 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 0062 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0132 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0135 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
Re: [squid-users] More access.log questions
w...@msdrd.com wrote: 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 013B, 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. Well for starters. The access.log does not contain that kind of info. That stuff should be in the cache.log with the rest of the debug and administration information. The FAQ has a good detailed explanation of what the logs do and contain... http://wiki.squid-cache.org/SquidFaq/SquidLogs Thanks in advanced. 2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches Some data received does not match a validity check that it should. Probably corrupted data in the disk cache attempting to load. 2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters A client sent Squid an invalid HTTP request. It's being dropped. {Host: digdug.divxnetworks.com responseType: text/xml User-Agent: DivX Player 2.0 Cookie: GUID=} 2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches A total of 10 objects have now found to be corrupt. 2008/12/15 22:06:28| assertion failed: client_side.cc:2479: "conn->in.abortedSize == (size_t)conn->bodySizeLeft()" Squid crashing with received data causing memory or state corruption somewhere. 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 10240 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: 10240 KB 2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY) Squid crashed earlier before completing its slow cache validation check. That caused the swap.state journal to be out of sync with the cache, corrupt or missing. Turning to paranoid and re-building indexes from a full raw object scan. 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 0062 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0132 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0135 3 files have been found to differ between the journal and whats actually in cache. 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_tl5i
Re: [squid-users] More access.log questions
Amos. Thanks for replying. After reviewing this access.log file section, is sqid working correctly or are there any adjustments I need to make to make run more smoothly? Amos Jeffries wrote: w...@msdrd.com wrote: 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 013B, 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. Well for starters. The access.log does not contain that kind of info. That stuff should be in the cache.log with the rest of the debug and administration information. The FAQ has a good detailed explanation of what the logs do and contain... http://wiki.squid-cache.org/SquidFaq/SquidLogs Thanks in advanced. 2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches Some data received does not match a validity check that it should. Probably corrupted data in the disk cache attempting to load. 2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters A client sent Squid an invalid HTTP request. It's being dropped. {Host: digdug.divxnetworks.com responseType: text/xml User-Agent: DivX Player 2.0 Cookie: GUID=} 2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches A total of 10 objects have now found to be corrupt. 2008/12/15 22:06:28| assertion failed: client_side.cc:2479: "conn->in.abortedSize == (size_t)conn->bodySizeLeft()" Squid crashing with received data causing memory or state corruption somewhere. 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 10240 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: 10240 KB 2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY) Squid crashed earlier before completing its slow cache validation check. That caused the swap.state journal to be out of sync with the cache, corrupt or missing. Turning to paranoid and re-building indexes from a full raw object scan. 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 0062 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0132 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0135 3 files have been found to differ between the journal and whats actually in cache. 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:
Re: [squid-users] More access.log questions
> Amos. > > Thanks for replying. After reviewing this access.log file section, is > sqid working correctly or are there any adjustments I need to make to > make run more smoothly? Did you even read that page on the logs? access.log has nothing to do with what you are talking about. If your squid.conf names them wrongly please correct that. Using the correct names for logs is important for communication. Your squid is dying regularly on some very fatal errors. You can do one of two things to fix it: The previous behavior of blocking 'NICK' requests. (remove extension_methods again) Or stop doing transparent interception of traffic. Amos > > > > Amos Jeffries wrote: >> w...@msdrd.com wrote: >>> 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 013B, 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. >> >> Well for starters. The access.log does not contain that kind of info. >> That stuff should be in the cache.log with the rest of the debug and >> administration information. >> >> The FAQ has a good detailed explanation of what the logs do and >> contain... >> http://wiki.squid-cache.org/SquidFaq/SquidLogs >> >>> >>> Thanks in advanced. >>> >>> >>> >>> 2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches >> >> Some data received does not match a validity check that it should. >> Probably corrupted data in the disk cache attempting to load. >> >> >>> 2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters >> >> A client sent Squid an invalid HTTP request. It's being dropped. >> >>> {Host: digdug.divxnetworks.com >>> responseType: text/xml >>> User-Agent: DivX Player 2.0 >>> Cookie: >>> GUID=} >>> 2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches >> >> A total of 10 objects have now found to be corrupt. >> >>> 2008/12/15 22:06:28| assertion failed: client_side.cc:2479: >>> "conn->in.abortedSize == (size_t)conn->bodySizeLeft()" >> >> Squid crashing with received data causing memory or state corruption >> somewhere. >> >>> 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 10240 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: 10240 KB >>> 2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY) >> >> Squid crashed earlier before completing its slow cache validation check. >> That caused the swap.state journal to be out of sync with the cache, >> corrupt or missing. Turning to paranoid and re-building indexes from a >> full raw object scan. >> >>> 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 >>> 0062 >>> 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno >>> 0132 >>> 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno >>> 0135 >> >> 3 files have been found to differ between the journal and whats actually >> in cache. >> >>> 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 >
Re: [squid-users] More access.log questions
Amos. Yes, I meant cache.log NOT access.log sorry for the confusion. I will remove extension_methods from squid.conf I won't be able to stop transparent interception because I don't want to go to every clients' sites to change their configurations. Will this keep the cache "CLEAN"? Hope it works. Amos Jeffries wrote: Amos. Thanks for replying. After reviewing this access.log file section, is sqid working correctly or are there any adjustments I need to make to make run more smoothly? Did you even read that page on the logs? access.log has nothing to do with what you are talking about. If your squid.conf names them wrongly please correct that. Using the correct names for logs is important for communication. Your squid is dying regularly on some very fatal errors. You can do one of two things to fix it: The previous behavior of blocking 'NICK' requests. (remove extension_methods again) Or stop doing transparent interception of traffic. Amos Amos Jeffries wrote: w...@msdrd.com wrote: 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 013B, 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. Well for starters. The access.log does not contain that kind of info. That stuff should be in the cache.log with the rest of the debug and administration information. The FAQ has a good detailed explanation of what the logs do and contain... http://wiki.squid-cache.org/SquidFaq/SquidLogs Thanks in advanced. 2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches Some data received does not match a validity check that it should. Probably corrupted data in the disk cache attempting to load. 2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters A client sent Squid an invalid HTTP request. It's being dropped. {Host: digdug.divxnetworks.com responseType: text/xml User-Agent: DivX Player 2.0 Cookie: GUID=} 2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches A total of 10 objects have now found to be corrupt. 2008/12/15 22:06:28| assertion failed: client_side.cc:2479: "conn->in.abortedSize == (size_t)conn->bodySizeLeft()" Squid crashing with received data causing memory or state corruption somewhere. 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 10240 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: 10240 KB 2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY) Squid crashed earlier before completing its slow cache validation check. That caused the swap.state journal to be out of sync with the cache, corrupt or missing. Turning to paranoid and re-building indexes from a full raw object scan. 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 0062 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0132 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0135 3 files have been found to differ between the journal and whats actually in cache. 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
Re: [squid-users] More access.log questions
Wilson Hernandez - MSD, S. A. wrote: Amos. Yes, I meant cache.log NOT access.log sorry for the confusion. I will remove extension_methods from squid.conf I won't be able to stop transparent interception because I don't want to go to every clients' sites to change their configurations. Will this keep the cache "CLEAN"? CLEAN/DIRTY doesn't matter normally. It's just a fast/slow startup. The real issue was that crash, but your squid version is too old for a meaningful fix to be tried. Leaving the NICK requests on unknown and dropped, bypasses the crash. Amos Hope it works. Amos Jeffries wrote: Amos. Thanks for replying. After reviewing this access.log file section, is sqid working correctly or are there any adjustments I need to make to make run more smoothly? Did you even read that page on the logs? access.log has nothing to do with what you are talking about. If your squid.conf names them wrongly please correct that. Using the correct names for logs is important for communication. Your squid is dying regularly on some very fatal errors. You can do one of two things to fix it: The previous behavior of blocking 'NICK' requests. (remove extension_methods again) Or stop doing transparent interception of traffic. Amos Amos Jeffries wrote: w...@msdrd.com wrote: 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 013B, 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. Well for starters. The access.log does not contain that kind of info. That stuff should be in the cache.log with the rest of the debug and administration information. The FAQ has a good detailed explanation of what the logs do and contain... http://wiki.squid-cache.org/SquidFaq/SquidLogs Thanks in advanced. 2008/12/15 19:26:19| WARNING: 1 swapin MD5 mismatches Some data received does not match a validity check that it should. Probably corrupted data in the disk cache attempting to load. 2008/12/15 21:16:13| WARNING: HTTP header contains NULL characters A client sent Squid an invalid HTTP request. It's being dropped. {Host: digdug.divxnetworks.com responseType: text/xml User-Agent: DivX Player 2.0 Cookie: GUID=} 2008/12/15 21:41:20| WARNING: 10 swapin MD5 mismatches A total of 10 objects have now found to be corrupt. 2008/12/15 22:06:28| assertion failed: client_side.cc:2479: "conn->in.abortedSize == (size_t)conn->bodySizeLeft()" Squid crashing with received data causing memory or state corruption somewhere. 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 10240 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: 10240 KB 2008/12/15 22:06:31| Rebuilding storage in /var/log/squid/cache (DIRTY) Squid crashed earlier before completing its slow cache validation check. That caused the swap.state journal to be out of sync with the cache, corrupt or missing. Turning to paranoid and re-building indexes from a full raw object scan. 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 0062 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0132 2008/12/15 22:06:55| WARNING: newer swaplog entry for dirno 0, fileno 0135 3 files have been found to differ between the journal and whats actu