https://issues.apache.org/bugzilla/show_bug.cgi?id=49511
Tim Whittington <t...@apache.org> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |NEEDINFO
--- Comment #2 from Tim Whittington <t...@apache.org> 2010-09-12 19:24:44 EDT
---
What is happening here is:
- pFilterContext is allocated per connection/session
- the uri and query are being correctly set on each request (even if
pFilterContext has been allocated)
- the uri and query are being set correctly in the HTTP_FILTER_LOG structure
- the uri and query are not overwritten until the next request has started
The documentation of HTTP FILTER_LOG
(http://msdn.microsoft.com/en-us/library/ms525464%28v=VS.90%29.aspx) states
that the memory used for the uri and query variables "must remain valid until
the next filter notification", implying that logging occurs before the next
HttpFilterProc notification.
https://forums.iis.net/p/1156804/1900220.aspx and other forum questions with
response from Microsoft reps seems to support this theory.
It's implicit (and occasionally explicit) in all the ISAPI code and advice that
I've seen (even by Microsoft ISAPI reps) that IIS serialises requests through
the ISAPI filter (even for Keep-Alive and pipelined requests).
i.e. you can expect a sequence of ISAPI event notifications through
HttpFilterProc to conclude before a new sequence starts.
I can find no structure, documentation, or advice on how to implement
per-request data structures (aside from implementing something custom under
pFilterContext), which lends weight to this theory.
However if all this were true, then there would be no issue with the logging in
the redirector now - the memory in pFilterContext is allocated once per
connection, and is consistent from the SF_NOTIFY_LOG event until the subsequent
request is started.
The only explanation I can see for this kind of behaviour then is that the
actual log writing is being done outside the ISAPI event sequence and after the
next request has entered HttpFilterProc and changed the uri and query values.
i.e. we get a something like
- SF_NOTIFY_PREPROC_HEADERS request 1
- <normal request processing> request 1
- SF_NOTIFY_LOG request 1
- SF_NOTIFY_PREPROC_HEADERS request 2
- <request 1 logged by IIS>
If this is the case, then setting pfc->pFilterContext to NULL in the
SF_NOTIFY_LOG seems to be the only fix.
This will introduce a per-request memory growth of sizeof(isapi_log_data_t) (~
4k) that will only be freed on termination of the connection though, which may
be unacceptable. (We could implement a freeing of the previous log data in
SF_NOTIFY_LOG, but we're still not sure that the actual logging would take
place before that event. We could also trim the actual memory usage by using
AllocMem individually on the uri and query parts, rather than allocating a
struct with pre-allocated buffers.)
Posts like this one from David Wang (Microsoft) indicate that this is standard
practice however (I've seen numerous examples and mentions of this technique
from MS reps). The code explicitly NULLs pFilterContext on request start,
without checking whether it was allocated previously for that session.
http://groups.google.ie/group/microsoft.public.platformsdk.internet.server.isapi-dev/msg/8d3a72b740735860
What also doesn't make sense is the assertion in the original report that:
"all requests on the same connection (keep-alive enabled) are logged with the
same (probably the first) request uri (and query string)"
What I would expect to see instead is that some (or in the extreme case) all of
the requests on the same connection are logged with the request uri of a
subsequent request (i.e. not the first, but perhaps the last).
--
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
