Re: [squid-users] More access.log questions

From: Amos Jeffries <squid3_at_treenet.co.nz>
Date: Thu, 18 Dec 2008 23:51:01 +1300

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:
>>>> wh_at_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 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.
>>>> 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=FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF}
>>>>> 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 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)
>>>> 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
>>>>> 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
>>>> 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_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()"
>>>> Squid crashes again on same invalid request received causing memory
>>>> corruption.
>>>>
>>>> ... and the cycle continues.
>>>>
>>>> Amos
>>> --
>>> *Wilson Hernandez*
>>> Presidente
>>> 829.848.9595
>>> 809.766.0441
>>> www.msdrd.com <http://www.msdrd.com>
>>> Conservando el medio ambiente
>>>
>>
>>
>>
>>
>

-- 
Please be using
   Current Stable Squid 2.7.STABLE5 or 3.0.STABLE10
   Current Beta Squid 3.1.0.3 or 3.0.STABLE11-RC1
Received on Thu Dec 18 2008 - 10:51:08 MST

This archive was generated by hypermail 2.2.0 : Thu Dec 18 2008 - 12:00:03 MST