Re: When handlers misfire
On Thursday 21 February 2002 05:21 pm, Rick Myers wrote: On Feb 21, 2002 at 15:23:04 -0800, Milo Hyson wrote: On Wednesday 20 February 2002 07:55 pm, Geoffrey Young wrote: If the redirected request needs that session data, there's a small chance it won't be there yet. have you seen this? I don't recall this ever coming up before (which doesn't mean it can't happen :) Yes, I have seen it happen. Quite frequently in fact. My investigation into the problem is how I discovered the cleanup handler wasn't doing its job in time. Want to see something even more interesting? Let your debugging warnings mention the pid that caused the log entry and let it run a while on a production server. I see stuff like... To add to all of this, since installing the fixup and cleanup/log handlers, I've noticed problems shutting down Apache. When running apachectl stop, I see numerous messages in the logs about the child processes not shutting down and having to be SIGKILLed. Yesterday however, I relocated my session management code into Apache::Registry. This seems to solve all my problems. In fact, it may even open a few additional doors :) -- Milo Hyson CyberLife Labs, LLC
Re: When handlers misfire
On Wednesday 20 February 2002 07:55 pm, Geoffrey Young wrote: If the redirected request needs that session data, there's a small chance it won't be there yet. have you seen this? I don't recall this ever coming up before (which doesn't mean it can't happen :) Yes, I have seen it happen. Quite frequently in fact. My investigation into the problem is how I discovered the cleanup handler wasn't doing its job in time. perhaps your post-content code in a PerlLogHandler instead of a PerlCleanupHandler might help if you are running into problems. the browser isn't released from the current connection until logging is complete, so there wouldn't be the chance that a redirect would be processed before the session is created. I moved the session cleanup phase to a PerlLogHandler and it seems to be working, except for one small issue. Request URIs for directories (i.e. no filename specified) don't seem to trigger the log handler. I put some warnings in the code to trace its execution. The following is a dump of my logs following a test run: [Thu Feb 21 15:02:46 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:02:46 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:03:15 2002] [warn] SessionPrepare called for POST /iddb/target/login.pl [Thu Feb 21 15:03:15 2002] [warn] SessionCleanup called for POST /iddb/target/login.pl [Thu Feb 21 15:03:15 2002] [warn] SessionPrepare called for GET /iddb/target/list-portals.pl [Thu Feb 21 15:03:16 2002] [warn] SessionCleanup called for GET /iddb/target/list-portals.pl [Thu Feb 21 15:03:18 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:03:18 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:03:18 2002] [warn] SessionPrepare called for GET /iddb/target/list-portals.pl [Thu Feb 21 15:03:19 2002] [warn] SessionCleanup called for GET /iddb/target/list-portals.pl [Thu Feb 21 15:04:36 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:04:37 2002] [warn] SessionCleanup called for GET /iddb/target/index.pl [Thu Feb 21 15:04:37 2002] [warn] SessionPrepare called for GET /iddb/target/list-portals.pl [Thu Feb 21 15:04:38 2002] [warn] SessionCleanup called for GET /iddb/target/list-portals.pl The first two lines are the browser's initial request for /iddb/target and the subsequent redirect by Apache to /iddb/target/ and ultimately translated to /iddb/target/index.pl. Notice that the fixup handler fires for both, but the log handler doesn't. In lines seven and eight, I re-issued the initial request and received the same result -- no log handler. However, in lines 11 and 12, I manually entered /iddb/target/index.pl into the browser's address line. This time the log handler was called. Bug or feature? -- Milo Hyson CyberLife Labs, LLC
Re: When handlers misfire
I moved the session cleanup phase to a PerlLogHandler and it seems to be working, except for one small issue. Request URIs for directories (i.e. no filename specified) don't seem to trigger the log handler. I put some warnings in the code to trace its execution. The following is a dump of my logs following a test run: [Thu Feb 21 15:02:46 2002] [warn] SessionPrepare called for GET /iddb/target/index.pl [Thu Feb 21 15:02:46 2002] [warn] SessionPrepare called for GET [snip] The first two lines are the browser's initial request for /iddb/target and the subsequent redirect by Apache to /iddb/target/ and ultimately translated to /iddb/target/index.pl. Notice that the fixup handler fires for both, but the log handler doesn't. In lines seven and eight, I re-issued the initial request and received the same result -- no log handler. However, in lines 11 and 12, I manually entered /iddb/target/index.pl into the browser's address line. This time the log handler was called. Bug or feature? ok, I'd have to analyze this further, but here's what pops in my head... mod_dir is calling ap_internal_redirect for the /iddb/target - /iddb/target/ transition. the way the request cycle seems to work is that the post-read request handler phase through the content-generation phase are handled by ap_process_request_internal (which is called by ap_internal_redirect), while the logging phase is actually handled by ap_process_request, which only happens for client initiated requests... so, my theory is that the bulk of the request will run for requests handled by internal redirects _except_ for the logging phase, which only happens for the main request. this can be easily verified by creating a PerlHandler that only calls $r-internal_redirect and returns OK, and seeing whether the Fixup phase runs twice and the Log phase once. now that I think about it, this _may_ be buried somewhere in some documentation (it sounds vaguely familiar)... or I could be totally off the wall. they are both equal at this point I think. anyway, if my theory is correct, though, you may be able to solve your problem by doing return DECLINED unless $r-is_initial_req; in your fixup handler, which would keep it from running twice. this is only untested theory at this point, and I'm rather tired. I'll investigate more in the morning if things don't work out for you... HTH --Geoff
Re: When handlers misfire
On Feb 21, 2002 at 15:23:04 -0800, Milo Hyson wrote: On Wednesday 20 February 2002 07:55 pm, Geoffrey Young wrote: If the redirected request needs that session data, there's a small chance it won't be there yet. have you seen this? I don't recall this ever coming up before (which doesn't mean it can't happen :) Yes, I have seen it happen. Quite frequently in fact. My investigation into the problem is how I discovered the cleanup handler wasn't doing its job in time. Want to see something even more interesting? Let your debugging warnings mention the pid that caused the log entry and let it run a while on a production server. I see stuff like... (12345) NEW REQUEST (12345) NEW REQUEST (12345) NEW REQUEST (12345) CLEANUP DONE (12345) CLEANUP DONE (12345) CLEANUP DONE ...often enough to have noticed. If I grep around a bit I can find many instances of this sort of thing. In one case I saw page hits that also warned other info with timestamps. The first four requests were timestamped, the fifth wasn't, the sixth was, and the seventh wasn't. At the end of the seventh all seven cleanups fired off. The difference in time between the first and last timestamps was almost four *minutes*. --rick
When handlers misfire
I just ran into a problem with my PerlFixupHandler/PerlCleanupHandler based session manager (discussed earlier). It seems there's no guarantee that the cleanup handler will fire before the browser receives the response from the content handler. There's a niche case where a redirect will get to the browser and back to Apache before the cleanup handler has a chance to write the session to the database. If the redirected request needs that session data, there's a small chance it won't be there yet. Is there any way I can guarantee (short of hacking Apache::Registry) that my post-content code will run before the browser gets a response? From where I sit, the hack job looks like the best option right now. -- Milo Hyson CyberLife Labs, LLC
Re: When handlers misfire
Milo Hyson wrote: I just ran into a problem with my PerlFixupHandler/PerlCleanupHandler based session manager (discussed earlier). It seems there's no guarantee that the cleanup handler will fire before the browser receives the response from the content handler. um, yes there is. the content generation phase is guaranteed to be complete before per-request cleanups run _for a single request_. that's what the request cycle is all about. There's a niche case where a redirect will get to the browser and back to Apache before the cleanup handler has a chance to write the session to the database. that's something different :) due to some long running cleanups, I can see how a redirected response (which is a completely new request) could be initiated before cleanups are complete, since cleanups are run after the browser is released... If the redirected request needs that session data, there's a small chance it won't be there yet. have you seen this? I don't recall this ever coming up before (which doesn't mean it can't happen :) Is there any way I can guarantee (short of hacking Apache::Registry) that my post-content code will run before the browser gets a response? don't confuse the issue - a redirect involves _two_ requests to the browser, not one. From where I sit, the hack job looks like the best option right now. perhaps your post-content code in a PerlLogHandler instead of a PerlCleanupHandler might help if you are running into problems. the browser isn't released from the current connection until logging is complete, so there wouldn't be the chance that a redirect would be processed before the session is created. --Geoff
