I've made some progress on this, now adding a request identifier and putting that in the context (see updated patch in bug).
I'm willing to see this through, but I'd like a bit of feedback first -- especially around whether this (i.e., sprinkling ctx_* calls throughout the codebase wherever we have a callback) is the right approach, first. Cheers, On 17/12/2009, at 10:24 PM, Mark Nottingham wrote: > I've put a basic proof-of-concept into a bug; see > <http://bugs.squid-cache.org/show_bug.cgi?id=2835>. > > It only logs client FDs, but gives output like this (with debug_options > ALL,2): > > 2009/12/17 22:08:24 client_fd=13 ctx: enter level 0: 'client_fd=13' > 2009/12/17 22:08:24 client_fd=13 Parser: retval 1: from 0->47: method 0->2; > url 4->36; version 38->46 (1/1) > 2009/12/17 22:08:24 client_fd=13 The request GET http://www.mnot.net/test/ is > ALLOWED, because it matched 'localhost' > 2009/12/17 22:08:24 client_fd=13 clientCacheHit: refreshCheckHTTPStale > returned 1 > 2009/12/17 22:08:24 client_fd=13 peerSourceHashSelectParent: Calculating hash > for 127.0.0.1 > 2009/12/17 22:08:28 client_fd=17 ctx: exit level 0 > 2009/12/17 22:08:28 client_fd=17 ctx: enter level 0: 'client_fd=17' > 2009/12/17 22:08:28 client_fd=17 Parser: retval 1: from 0->35: method 0->2; > url 4->24; version 26->34 (1/1) > 2009/12/17 22:08:28 client_fd=17 The request GET http://www.apple.com/ is > ALLOWED, because it matched 'localhost' > 2009/12/17 22:08:28 client_fd=17 clientCacheHit: refreshCheckHTTPStale > returned 0 > 2009/12/17 22:08:28 client_fd=17 clientCacheHit: HIT > 2009/12/17 22:08:28 client_fd=17 The reply for GET http://www.apple.com/ is > ALLOWED, because it matched 'all' > 2009/12/17 22:08:29 ctx: exit level 0 > 2009/12/17 22:08:29 The reply for GET http://www.mnot.net/test/slow.cgi is > ALLOWED, because it matched 'all' > > Feedback / sanity checking appreciated. > > > > On 25/02/2009, at 6:40 PM, Henrik Nordstrom wrote: > >> ons 2009-02-25 klockan 12:10 +1100 skrev Mark Nottingham: >> >>> What am I missing? The most straightforward way that I can see to do >>> this is to add an identifier to clientHttpRequest and pass that to >>> debug where available... >> >> That is what ctx_enter is about... There is not a single location where >> ctx_enter needs to be called, there is many.. >> >> Remember that Squid is a big bunch of event driven state machines, doing >> a little bit of processing at a time interleaved with many other >> unrelated things. ctx_enter indicates which state transition is >> currently being processed, ctx_leave when that state transition has >> completed waiting for next event (even if still at the same state..) >> >> So you need ctx_enter in quite many places, providing a reasonable trace >> of the processing within the state machine so far, based on whatever >> identifier the current small step is about. Each time the processing >> returns to the comm loop you are back at ctx level 0 with no context. >> Sometimes the ctx level may be quite high, having many loosely related >> state transitions in the trace, sometimes even almost completely >> unrelated requests. >> >> Most of the time the state machine starts with something directly >> related to a specific request (read/write on http sockets) however, but >> there is also many other kinds of state transitions like DNS, timers >> etc. >> >> Regards >> Henrik >> > > -- > Mark Nottingham [email protected] > > -- Mark Nottingham [email protected]
