Re: [squid-users] constant high CPU (>75%) w/ Squid25-STABLE10? thought it was cache-digests, but no ...

From: OpenMacNews <OpenMacNews@dont-contact.us>
Date: Sun, 11 Sep 2005 09:40:30 -0700

hi henrik,

thx 4 the reply =)

>> cache_peer 127.0.0.1 parent 8118 7 no-netdb-exchange default
>>
>> results in my squid-related CPU util staying, now, at < 1%, except, of
>> course, when accessing a site/page ...
>
> Interesting..
>
> Can you try again, this time issuing a "squid -k debug" while experiencing
> the problem and then see cache.log for detailed output of what your squid is
> doing. (run "squid -k debug" again to stop the debug output).
>
> It is possible your parent is returning some odd response in response to the
> netdb exchange request, confusing Squid. From looking at the source I have a
> theory on what it may be.. (theory: no HTTP header found within the first
> 4096 bytes of the reply, shows up in the debug log as a high rate of
> "netdbExchangeHandleReply: start parsing loop, size = 0")
>
> If you can confirm this please file a bug report.
>
> Regards
> Henrik
>

ok.

with the cache_peer stmt change back to:

    cache_peer 127.0.0.1 parent 8118 7 no-query default

squid launched w/:

    /usr/local/squid25/sbin/squid -X -d 9 -f
/var/DarkMatter/SquidProxy/squid25.conf

and 'top' showing the problem, again, as:

      PID COMMAND %CPU TIME #TH #PRTS #MREGS RPRVT RSHRD RSIZE VSIZE
    ...
     1073 squid 83.7% 0:37.34 1 15 34 3.15M 2.66M 4.32M 40.5M
     1071 squid 0.0% 0:00.00 1 10 31 288K 2.66M 240K 37.4M
    ...

a subsequent:

    /usr/local/squid25/sbin/squid -f /var/Settings/SquidProxy/squid25.conf -k
debug

dumps the following to logs:

    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    ... (LOTS of these repeating ...)
    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:57| eventRun: RUN ID 137
    2005/09/11 09:23:57| eventRun: Running 'MaintainSwapSpace', id 136
    2005/09/11 09:23:57| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:23:57| cbdataFree: 0x11315f0
    2005/09/11 09:23:57| cbdataFree: Freeing 0x11315f0
    2005/09/11 09:23:57| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:23:57| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:23:58| comm_poll: 1+0 FDs ready
    ... (more)
    2005/09/11 09:23:58| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:58| eventRun: RUN ID 138
    2005/09/11 09:23:58| eventRun: Running 'MaintainSwapSpace', id 137
    2005/09/11 09:23:58| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:23:58| cbdataFree: 0x11315f0
    2005/09/11 09:23:58| cbdataFree: Freeing 0x11315f0
    2005/09/11 09:23:58| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:23:58| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:23:59| comm_poll: 1+0 FDs ready
    ... (more)
    2005/09/11 09:23:59| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:59| eventRun: RUN ID 139
    2005/09/11 09:23:59| eventRun: Running 'ipcache_purgelru', id 127
    2005/09/11 09:23:59| eventAdd: Adding 'ipcache_purgelru', in 10.000000
    seconds
    2005/09/11 09:23:59| ipcache_purgelru: removed 0 entries
    2005/09/11 09:23:59| comm_poll: 1+0 FDs ready
    ... (more)
    2005/09/11 09:23:59| comm_poll: 1+0 FDs ready
    2005/09/11 09:23:59| eventRun: RUN ID 140
    2005/09/11 09:23:59| eventRun: Running 'MaintainSwapSpace', id 138
    2005/09/11 09:23:59| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:23:59| cbdataFree: 0x11315f0
    2005/09/11 09:23:59| cbdataFree: Freeing 0x11315f0
    2005/09/11 09:23:59| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:23:59| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:24:00| comm_poll: 1+0 FDs ready
    ... (more)
    2005/09/11 09:24:00| comm_poll: 1+0 FDs ready
    2005/09/11 09:24:00| eventRun: RUN ID 141
    2005/09/11 09:24:00| eventRun: Running 'MaintainSwapSpace', id 140
    2005/09/11 09:24:00| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:24:00| cbdataFree: 0x11315f0
    2005/09/11 09:24:00| cbdataFree: Freeing 0x11315f0
    2005/09/11 09:24:00| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:24:00| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:24:01| comm_poll: 1+0 FDs ready
    ... (more)
    2005/09/11 09:24:01| comm_poll: 1+0 FDs ready
    2005/09/11 09:24:01| eventRun: RUN ID 142
    2005/09/11 09:24:01| eventRun: Running 'MaintainSwapSpace', id 141
    2005/09/11 09:24:01| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:24:01| cbdataFree: 0x11315f0
    2005/09/11 09:24:01| cbdataFree: Freeing 0x11315f0
    2005/09/11 09:24:01| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:24:01| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:24:01| comm_poll: 1+0 FDs ready
    ...

now, switching to the 'better behaved':

    cache_peer 127.0.0.1 parent 8118 7 no-query no-netdb-exchange no-digest
default

top showing:

     1162 squid 0.0% 0:00.32 1 15 34 3.15M 2.66M 4.29M 40.5M
     1160 squid 0.0% 0:00.00 1 10 31 284K 2.66M 240K 37.4M

then '... -k debug' dumps:

    2005/09/11 09:35:25| comm_poll: time out: 1126456525.
    2005/09/11 09:35:25| eventRun: RUN ID 39
    2005/09/11 09:35:25| eventRun: Running 'MaintainSwapSpace', id 38
    2005/09/11 09:35:25| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:35:25| cbdataFree: 0x11314a0
    2005/09/11 09:35:25| cbdataFree: Freeing 0x11314a0
    2005/09/11 09:35:25| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:35:25| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:35:26| comm_poll: 0+0 FDs ready
    2005/09/11 09:35:26| comm_poll: time out: 1126456526.
    2005/09/11 09:35:26| eventRun: RUN ID 40
    2005/09/11 09:35:26| eventRun: Running 'MaintainSwapSpace', id 39
    2005/09/11 09:35:26| storeMaintainSwapSpace: f=0.000000, max_scan=100,
    max_remove=10
    2005/09/11 09:35:26| cbdataFree: 0x11314a0
    2005/09/11 09:35:26| cbdataFree: Freeing 0x11314a0
    2005/09/11 09:35:26| storeUfsDirMaintain: /var/squid/cache removed 0/10
    f=0.000 max_scan=100
    2005/09/11 09:35:26| eventAdd: Adding 'MaintainSwapSpace', in 1.000000
    seconds
    2005/09/11 09:35:27| comm_poll: 0+0 FDs ready
    2005/09/11 09:35:27| comm_poll: time out: 1126456527.

NOTE --

-- *NO* hundreds-of-repetitions of"

    2005/09/11 09:23:57| comm_poll: 1+0 FDs ready

looking at this, i don't thing i've verified your theory, but i'm not at all
sure what *is* happening ...

off to google on com_poll, unless i hear from you first :)

cheers & thx,

richard

Received on Sun Sep 11 2005 - 10:40:35 MDT

This archive was generated by hypermail pre-2.1.9 : Sat Oct 01 2005 - 12:00:03 MDT