Re: a tricky problem with using events

> I traced down the problem by measuring time consumed by each stage from
> the beginning of the event till httpReadReply() gets called. I found that
> there're two cases for these extremely slow events:
> case 1 (total time is 400+ms) :
> 2003/06/09 01:33:42| peoridcalFire: 0x8457ea8 at 1055136822.107.
> 2003/06/09 01:33:42| periodicalConnectDone: entry 0x8457ea8 at 1055136822.107
> 2003/06/09 01:33:42| httpSendRequest: 0x8457ea8 at 1055136822.107.
> 2003/06/09 01:33:42| eventRun: MaintainSwapSpace at 1055136822.107.
> 2003/06/09 01:33:42| httpSendComplete: 0x8457ea8 at 1055136822.555.
> 2003/06/09 01:33:42| eventRun: MaintainSwapSpace at 1055136822.555.
> 2003/06/09 01:33:42| eventRun: MaintainSwapSpace at 1055136822.555.
> 2003/06/09 01:33:42| httpReadReply: entry 0x8457ea8 at 1055136822.555
> From the trace, we can see a MaintainSwapSpace happened *between
> httpSendRequest and httpSendComplete* and this took most of the time.

Just because the time between MaintainSwapSpace and httpSendComplete
is 400msec, it doesn't mean that MaintainSwapSpace actually took
that long to execute. It would be helpful to see more debugging
from the routines in comm_select.c.

> case 2 (total time is 3000+ms) :
> 2003/06/09 01:33:26| periodicalConnectDone: entry 0x8464a70 at 1055136806.549
> 2003/06/09 01:33:26| httpSendRequest: 0x8464a70 at 1055136806.549.
> 2003/06/09 01:33:26| httpSendComplete: 0x8464a70 at 1055136806.549.
> 2003/06/09 01:33:26| eventRun: MaintainSwapSpace at 1055136806.552.
> 2003/06/09 01:33:27| eventRun: MaintainSwapSpace at 1055136807.778.
> 2003/06/09 01:33:27| eventRun: MaintainSwapSpace at 1055136807.778.
> 2003/06/09 01:33:28| eventRun: MaintainSwapSpace at 1055136808.779.
> 2003/06/09 01:33:28| eventRun: MaintainSwapSpace at 1055136808.779.
> 2003/06/09 01:33:29| eventRun: MaintainSwapSpace at 1055136809.779.
> 2003/06/09 01:33:29| eventRun: fqdncache_purgelru at 1055136809.779.
> 2003/06/09 01:33:29| httpReadReply: entry 0x8464a70 at 1055136809.779
> From the trace we can see that man MaintainSwapSpace happened *between
> httpSendComplete and httpReadReply* and these took most of the time.

Also it looks like you have two MaintainSwapSpace events executing each
second. Seems like maybe two events got added somehow and they keep
on that way. If you look at the event list with the cache manager,
you should see only one MaintainSwapSpace event listed.

>
> But for normal client-squid-httpd model, I never see any eventRun happened
> between httpSendRequest-httpSendComplete-httpReadReply in my experiments.
> This is very weird because from httpSendRequest on my periodical
> contacting http server requests are no different from oridnary http
> requests initiated by a client except that the requests in my code have no
> client associated. But is that the reason? I can't tell why that could
> cause this much delay.

Perhaps you should run tcpdump at the same time and double check that
the packets are not arriving later than you actually think.

> I've been spent a lot of time on this but couldn't find where the problem
> is. Hope you gurus can give me some idea. Is eventAdd() is the right way
> at all to do this thing I want? Thanks a lot.

eventAdd() is the right way. You might find that the netdbExchangeStart()
function is similar to what you are doing, except that it uses
fwdStart().

Duane W.
Received on Mon Jun 09 2003 - 18:23:54 MDT