A little problem: IIS 6.0 custom logging + HTTP pipelining [Answered]RSS

3 replies

Last post Apr 14, 2009 02:20 PM by _OK

  • A little problem: IIS 6.0 custom logging + HTTP pipelining

    Apr 11, 2009 03:38 PM|_OK|LINK

    Task:

    ISAPI filter performs URL rewrite.

    Requested and rewritten URLs have to be written to IIS log:

    “rewritten URL” goes to “cs-uri-stem”, “requested URL” to “cs-username” fields respectively.

     

    How it’s done:

    On SF_NOTIFY_PREPROC_HEADERS event:

    “requested URL” is saved to a memory allocated by PHTTP_FILTER_CONTEXT->AllocMem()

    Pointer is saved to PHTTP_FILTER_CONTEXT ->pFilterContext

     

    On SF_NOTIFY_LOG event:

    pLog->pszClientUserName = (char *) pFC->pFilterContext;

     

    Memory is freed by IIS in SF_NOTIFY_END_OF_NET_SESSION as described in:

    http://msdn.microsoft.com/en-us/library/ms525115.aspx

     

    Everything works fine, until we got clients using HTTP pipelining…

     

    They make numerous requests and NEVER disconnect.

    And SF_NOTIFY_END_OF_NET_SESSION is fired only on client disconnect.

    I.e. memory is never been freed for them…

     

    I have decided to switch custom memory allocation mechanist on "per request" basis:

    Memory is allocated in SF_NOTIFY_PREPROC_HEADERS event handler.

    Pointer is used in SF_NOTIFY_LOG event handler – it cannot be freed there as log is not written yet.

     

    Memory has to be freed some kind of SF_NOTIFY_LOG_IS_WRITTEN event – but it doesn’t exists…

     

    But there is no any event after SF_NOTIFY_LOG except SF_NOTIFY_END_OF_NET_SESSION, which is never called for clients using HTTP pipelining…

     

    What is the solution there?

      

    And very related question:

    http://msdn.microsoft.com/en-us/library/ms525115.aspx

     

    It recommends “whatever memory allocation function that you like and clean up” based on “Event Notification Order”

    http://msdn.microsoft.com/en-us/library/ms524855.aspx

     

    But “Event Notification Order” there is:

    Important Note:

    Due to the complex and dynamic event model IIS uses, it is important that developers not rely on the exact sequence described above. An ISAPI filter must handle the occurrence of events in nonstandard order without failing and, more importantly, without causing IIS to fail.

     

    How do I suppose to write my memory allocation and clean up mechanism then?

    I do know – Microsoft has it all thought over – I’m not bright enough to the solution… ;-(

     

     

    ISAPI Filters Custom Logging HTTP pipelining

  • Re: A little problem: IIS 6.0 custom logging + HTTP pipelining

    Apr 14, 2009 07:57 AM|_OK|LINK

    Guys,

    I was wondering – was the question too difficult or it’s not clear what is it about? ;-/

  • Re: A little problem: IIS 6.0 custom logging + HTTP pipelining

    Apr 14, 2009 12:44 PM|anilr|LINK

    The solution would be to free the memory in the SF_NOTIFY_PREPROC_HEADER for the next request or SF_NOTIFY_END_OF_NET_SESSION when the client disconnects - whichever happens first.

    Anil Ruia
    Software Design Engineer
    IIS Core Server
  • Re: A little problem: IIS 6.0 custom logging + HTTP pipelining

    Apr 14, 2009 02:20 PM|_OK|LINK

    Anil,

    The solution would be to free the memory in the SF_NOTIFY_PREPROC_HEADER for the next request or SF_NOTIFY_END_OF_NET_SESSION when the client disconnects - whichever happens first. 

    Right…

    ---------------------------------------------------------------------------------------

    ISAPI Filter Event Notifications

    http://msdn.microsoft.com/en-us/library/ms524855.aspx

     

    Important Note:

    Due to the complex and dynamic event model IIS uses, it is important that developers not rely on the exact sequence described above. An ISAPI filter must handle the occurrence of events in nonstandard order without failing and, more importantly, without causing IIS to fail.

    ---------------------------------------------------------------------------------------

     

    1-st SF_NOTIFY_PREPROC_HEADERS – get memory.

    Subsequent SF_NOTIFY_LOG – set pointer to the memory for log operation.

    N-th SF_NOTIFY_PREPROC_HEADERS – free memory.

     

    The only problem here – how do I know that Log was actually written before I free memory?

    Technically, either SF_NOTIFY_END_OF_REQUEST should be called after SF_NOTIFY_LOG _AND_ Log was actually record written (because, IMO, log writing is part or request)

    Or better – it should be SF_NOTIFY_END_OF_LOG event. AKA undocumented function. (C) MS

     

    I guess, I can still make it work with current schema by implementing:

    1. “remember” time (A) of 1st SF_NOTIFY_PREPROC_HEADERS

    2. Check somehow what is the current record time in IIS log (B).

    3. If B > A – my log record has to be written already so it’s safe to free memory

     

    Is there any better approach or am I missing something?

      

    And one more question:

    Does anybody when above “Important Note” come into play?