RE: [logs] Windows Event Log Analysis

From: Eric Fitzgerald (ericfat_private)
Date: Tue Jan 07 2003 - 16:46:29 PST

  • Next message: swatch swatch: "Re: [logs] swatchrc emailing works!!!!"

    Are you using event viewer or your central syslog collection tool to
    determine whether the process tracking events are being generated?  I
    would hesitate before throwing around statements like "Windows event
    logging is not reliable" while you're using a UDP-based unacknowledged
    unauthenticated unencrypted network transport. ;-)
    I'm not claiming that a bug does not exist, but I have never seen it.
    1) Windows event logging is "reliable"- the RPC call to the eventlog
    service doesn't return until the data is committed to disk.  However,
    disk  write caches could affect this.
    2) Windows auditing- that is, security event logging- does have internal
    queues.  It is possible to lose events during a power down (even a
    graceful one) if the event log service stops before LSASS finishes
    flushing these queues.  We are working on a design that can be
    configured not to lose data under any circumstances, even a sudden
    shutdown such as a power loss.  Note that this issue will not cause
    intermittent loss of events; it will only cause loss during a shutdown.
    3) Due to queuing there might be a time lag between audit generation and
    audit appearing in the log.
    4) Event Viewer does not auto-refresh- press F5.
    5) An "everything on" audit policy is not unreasonable, but will affect
    performance.  I personally recommend turning off "privilege use" do to a
    low signal/noise ratio, but it's up to you.  Do NOT turn on the options
    in security policy "audit base system objects" and "crashonauditfail".
    Please verify for me the configured maximum size of your security log.
    If it is above 128MB then please reduce it until we determine the source
    of your problem.
    How are you determining whether or not the process termination audit is
    missing?  In other words, what method are you using to correlate the
    events?  I would suggest, on Windows 2000, you use the DUMPEL utility
    from the Windows 2000 Resource Kit to dump all event 592 and 593 to a
    CSV text file, and then use findstr or grep to find the events of
    dumpel -l security -m security -e 592 593 -c > process.csv
    findstr "myprocess.exe" process.csv > event592.txt
    Then to find the process termination events, match the Process ID field
    between the 592 event and the 593 event that occurs next in the log
    chronologically (the PID can be re-used after a process is terminated).
    Eric Fitzgerald
    Program Manager, Windows Auditing and Intrusion Detection
    Microsoft Corporation
    -----Original Message-----
    From: Buck Buchanan [mailto:lbuchanaat_private] 
    Sent: Tuesday, January 07, 2003 12:31 PM
    To: loganalysisat_private
    Subject: RE: [logs] Windows Event Log Analysis
    This is a response to postings by H C and Frank Heyne.
    FH> > I have both systems configured so that the event logger logs
    FH> > that is sent to it.  Both systems have the logs set to overwrite.
    FH> IMHO, this is not a good idea.
    FH> You should be aware what the system has to do in overwrite mode *for
    FH> every single event* when the log is full:
    FH> - search the oldest event
    FH> - check whether the new event is larger than the oldest event
    FH> - if yes, search the second oldest event
    FH> - check again, until enough space for the new event is found
    FH> - write the new event
    FH> - write eventlog footer after new event
    FH> - write updated information into eventlog header
    Agreed.  However, on an idle system that should not be an issue.  Frank
    Heyne's FAQ and the
    documentation for his r592.exe both point out that Windows event logging
    is not reliable.
    For my NT I don't think that "No Overwrite" or "Overwrite after x days"
    is a good idea. I have NT Syslog forwarding all events to a central
    syslog host.  If I need to see overwritten events, I put in a request
    for my log entries.  I really need to get my 2K system forwarding its
    event logs.
    With the exception of shutting the machine down when the event log fills
    up (which is a denial of service attack waiting to happen) log entries
    are going to get lost.
    HC> Could you dump the audit config w/
    HC> auditpol.exe, and post that?  It would certainly be
    HC> more helpful and instructive.
    C:\>auditpol \\c111753
    Running ...
    (X) Audit Enabled
    System                    = Success and Failure
    Logon                     = Success and Failure
    Object Access             = Success and Failure
    Privilege Use             = Success and Failure
    Process Tracking          = Success and Failure
    Policy Change             = Success and Failure
    Account Management        = Success and Failure
    Directory Service Access  = Success and Failure
    Account Logon             = Success and Failure
    HC> Unfortunately, whatever identifier the EventLog
    HC> assigns to a process creation, it does NOT use the
    HC> same identifier when the process terminates.  Do you
    HC> get ANY process termination log entries at all?
    I have no termination events.  Before the reboot I ran arp four times in
    a row and had four process creation events and no termination events.
    HC> When looking for corresponding termination events,
    HC> what exactly are you looking for?  Are you just
    HC> looking for any number of creation events to match the
    HC> same number of termination events, or are you looking
    HC> at particular fields in the EventLog entry?
    I am looking at particular fields.  For example here is a process
    A new process has been created:
          New Process ID:   1204
          Image File Name:  \cygwin\bin\ls.exe
          Creator Process ID:     960
          User Name:  lbuchana
          Domain:           C111753
          Logon ID:         (0x0,0x7D68)
    and here is the corresponding process termination description:
    A process has exited:
          Process ID: 1204
          User Name:  lbuchana
          Domain:           C111753
          Logon ID:         (0x0,0x7D68)
    The key fields are the New Process ID, Image File Name, and Process ID
    along with the Date and Time fields.  What I was looking for originally
    was TDImon was reporting that a process that had supposedly terminated
    was continuing to communicate with remote systems.  The bash shell the
    program had been run from, Task Manger, pslist and fport all agreed that
    the process had terminated, yet TDImon was still reporting the process
    sending and receiving packets.  I would consider this to be a quirk.
    This lead me to looking at the event log and not finding the process
    termination message and the "whole new education".  It turns out that
    the system process also had the port open and it was handling the
    HC> Sometimes when I review the lists, the "quirks" that
    HC> are identified aren't really "quirks" at all, just
    HC> normal operations for the operating system
    HC> environment, and most usually something that the
    HC> poster thinks 'should' happen, rather than what really does.
    Good point.  My perspective is primarily from a UNIX view point and I
    find Windows to be a large collection of quirks ;-).
    FH> This seems to be "normal behaviour",...
    OK, so this is not a quirk but normal Microsoft behavior.  My point in
    starting this thread was simply to raise peoples awareness that logging
    on Microsoft Windows is not reliable.  Frank Heyne's FAQ points out that
    Arne Vidstrom's WinZapper allows for selective deletions from the event
    log. For more information see
    B Cing U
    LogAnalysis mailing list
    LogAnalysis mailing list

    This archive was generated by hypermail 2b30 : Wed Jan 08 2003 - 08:49:33 PST