Windows 日志高级筛选实践

yoke88 关注 0人评论 3249人阅读 2018-11-22 11:08:06

背景

经常需要查看日志，不仅是用来排错，有些时候我还需要监控系统来抓取特定日志来帮助减少我的工作负担，以及时监控到异常出现，并作出通知及响应，那么从大量日志中快速并精确筛选出想要的日志，并且精确提取信息，是一个必备的技能。我曾经用内置的事件查看器的筛选器进行事件筛选，然后保存视图，或者使用powershell get-winevent 进行筛选，也使用logparser, 或者第三方的日志查看工具比如eventexplorer 进行日志筛选。但是总是遇到几个主要的问题：

从大量日志中过滤出极个别日志，每次执行的事件总是太长。
不能灵活的或者更精确的进行筛选。一般只能大概的匹配，然后再做一步处理。通常又遇到1的问题。

尝试和比较

经过一些尝试和使用，个人觉得powershell 的get-winevent 最方便，因为毕竟是一个脚本语言，可以进一步进行处理，而且可以很灵活的处理。logparser 很快，但是如果精确提取某些日志的字段，就没有那么容易了,windows 日志的EventData中的数据复杂多样，靠几个常规字段是没有办法灵活进行处理的。

论速度的话，除了logparser,使用xml 筛选是最快速的。但是xml 筛选需要使用复杂的、受限的xpath 1.0 (被微软实现后，有更多限制),虽然有点蹩脚又难懂，但是和时间节省算起，还是划的来的，特别是重复任务。

一个比较好的开始是从下面链接开始。

https://blogs.technet.microsoft.com/askds/2011/09/26/advanced-xml-filtering-in-the-windows-event-viewer/

正式实践

一个比较常用场景是，我经常需要精确过滤到哪个账号最近锁定了，哪台计算机锁定的，什么时候。我需要很快速的能查询到锁定日志。过去虽然我用get-winevent –filterhashtable 可以做到这些，但是速度实在太慢了，虽然我的域控只有4台。我经常和用户说，如果你想知道你在哪台计算机上锁定了，请等待一段时间，我会把查询结果用邮件发给你。不过现在使用xpath 过滤时，我基本上可以在用户打电话过来时，告诉他这些信息。

下面XML 过滤AD安全日志中的最近一天的某个用户名的锁定日志

<QueryList>
<Query Id="0" Path="Security">
<Select Path="Security">
*[System[EventID=4740 and TimeCreated[timediff(@SystemTime) &lt;= 86400000] and Provider[@Name='Microsoft-Windows-Security-Auditing']]]
and
*[EventData[Data[@Name='TargetUserName']='somebody']]
</Select>
</Query>
</QueryList>

如果你只想过滤最近一天所有用户的锁定日志，那么这样写

<QueryList>
<Query Id="0" Path="Security">
<Select Path="Security">
*[System[EventID=4740 and TimeCreated[timediff(@SystemTime) &lt;= 86400000] and Provider[@Name='Microsoft-Windows-Security-Auditing']]]
</Select>
</Query>
</QueryList>

上面过滤XML可以在事件查看器的筛选当前日志–》XML—》手动编辑查询中进行测验。

OK ,为了方便使用，我们做成一个powershell function ,方便日常使用，直接上例子。

function get-lockedEvent{     <#     .SYNOPSIS         Function to filter user locked event which id=4740     .DESCRIPTION         This function search user locked events in DC security logs, this function need the domain admin priv.     .EXAMPLE         get-lockedEvent -loginname oaoperator -show     .EXAMPLE         PS C:\> get-lockedEvent -loginname oaoperator -summary         Count Name         ----- ----         457 Oaoperator, OA     .EXAMPLE         PS C:\> get-lockedEvent -loginname oaoperator         Username   LockedPC Datetime           EventLocation         --------   -------- --------           -------------         Oaoperator OA       2018/9/27 10:27:40 dc02         Oaoperator OA       2018/9/27 10:32:40 dc02     #>          [cmdletbinding()]     param(         [parameter(Mandatory=$false)]         [string]         $loginname,         [Parameter(Mandatory=$false)]         [switch]         $summary,         [Parameter(Mandatory=$false)]         [switch]         $show     )
# filter Locked Events generated in 1 day and username eq loginname     $f2=@'     <QueryList>     <Query Id="0" Path="Security">       <Select Path="Security">       *[System[EventID=4740  and TimeCreated[timediff(@SystemTime) &lt;= 86400000] and Provider[@Name='Microsoft-Windows-Security-Auditing']]]        and        *[EventData[Data[@Name='TargetUserName']='{0}']]       </Select>     </Query>     </QueryList>
'@
# filter Locked Events generated in 1 day      $f1=@'     <QueryList>     <Query Id="0" Path="Security">       <Select Path="Security">       *[System[EventID=4740  and TimeCreated[timediff(@SystemTime) &lt;= 86400000] and Provider[@Name='Microsoft-Windows-Security-Auditing']]]       </Select>     </Query>     </QueryList>
'@     if($loginname){         $f=$f2 -f $loginname     }else{         $f=$f1     }     $DCs=Get-ADDomainController -Filter *|%{$_.hostname}     $r=Invoke-Command -ComputerName $DCs -ArgumentList @($f) -Command{         param(             $filter         )         $events=Get-WinEvent -FilterXml  $filter         $events|%{             $e=[xml]$_.toxml()             [PSCustomObject]@{                 'Username'=$e.Event.EventData.Data.where({$_.Name -eq 'TargetUserName'})."#text"                 'LockedPC'=$e.Event.EventData.Data.where({$_.Name -eq 'TargetDomainName'})."#text"                 'Datetime'=[datetime]$e.Event.System.TimeCreated.SystemTime                 'EventLocation'=$e.Event.System.Computer             }         }     }|Sort-Object -Property Datetime |select -Property 'UserName','LockedPC','Datetime','EventLocation'     if($summary){         $r=$r|Group-Object -Property Username,LockedPC -NoElement     }          if($show){         $r|Out-GridView     }else{         $r     }
}

另外一个实践

由于最近有一些计划任务的状态需要监控，而且考虑到这应该是一个非常通用的需求，所以我想过滤计划任务名称匹配\qq_ent 开头的，然后任务执行结果不为0的日志，尽管我参考着下面的一些blog 链接，也让我尝试了好一会，我想应该记录下这些过程。

我们先来看看计划任务日志的xml 内容：

<Event xmlns="https://schemas.microsoft.com/win/2004/08/events/event">
<System>
  <Provider Name="Microsoft-Windows-TaskScheduler" Guid="{DE7B24EA-73C8-4A09-985D-5BDADCFA9017}" /> 
  <EventID>201</EventID> 
  <Version>2</Version> 
  <Level>4</Level> 
  <Task>201</Task> 
  <Opcode>2</Opcode> 
  <Keywords>0x8000000000000000</Keywords> 
  <TimeCreated SystemTime="2018-11-18T05:00:02.058811400Z" /> 
  <EventRecordID>144817</EventRecordID> 
  <Correlation ActivityID="{110529FD-DBFD-4E59-B207-83DF8CC779B8}" /> 
  <Execution ProcessID="1508" ThreadID="24392" /> 
  <Channel>Microsoft-Windows-TaskScheduler/Operational</Channel> 
  <Computer>ComputerName.xxx.com</Computer> 
  <Security UserID="S-1-5-18" /> 
  </System>
<EventData Name="ActionSuccess">
  <Data Name="TaskName">\qq_ent\store_to_db</Data> 
  <Data Name="TaskInstanceId">{110529FD-DBFD-4E59-B207-83DF8CC779B8}</Data> 
  <Data Name="ActionName">C:\Users\UserName\AppData\Local\Programs\Python\Python37\python3.exe</Data> 
  <Data Name="ResultCode">2147942401</Data> 
  <Data Name="EnginePID">22172</Data> 
  </EventData>
  </Event>

说下我们的任务：

匹配 EventData 中Data 名称为TaskName的，它的值应该是\qq_ent\xxxx
匹配 EventData中 Data 名称为ResultCode的，它的值应该是>0 或者不等于0的
EventID=201
Provider Name=Microsoft-Windows-TaskScheduler

最后成型的过滤，和微软的之前的例子不一样。

 <QueryList>
    <Query Id="0" Path="Microsoft-Windows-TaskScheduler/Operational">
      <Select Path="Microsoft-Windows-TaskScheduler/Operational">
      *[System/EventID=201]
       and 
      *[EventData[
                    (
                        Data[@Name='TaskName']='\qq_ent\download_images' 
                    or 
                        Data[@Name='TaskName']='\qq_ent\store_to_db_offline'
                    or 
                        Data[@Name='TaskName']=='\qq_ent\gatherQQmsg' 
                    or 
                        Data[@Name='TaskName']=='\qq_ent\store_to_db'
                    )
                    and
                        Data[@Name='ResultCode'] !=0
        ]]
      </Select>
    </Query>
    </QueryList>

我之前按照微软的例子是这样写的，结果不对的。

    <QueryList>
    <Query Id="0" Path="Microsoft-Windows-TaskScheduler/Operational">
      <Select Path="Microsoft-Windows-TaskScheduler/Operational">
      *[System/EventID=201]
       and 
      *[
            EventData[
                    (
                        Data[@Name='TaskName'] 
                        and 
                        (
                            Data='\qq_ent\download_images' 
                            or 
                            Data='\qq_ent\store_to_db_offline'
                            or 
                            Data='\qq_ent\gatherQQmsg' 
                            or 
                            Data='\qq_ent\store_to_db'
                        )
                    ) 
                    and
                    (
                        Data[@Name='ResultCode'] and Data !='0'
                    )
            ]
        ]
      </Select>
    </Query>
    </QueryList>

注意事项

event log 中的Xpath 受限，能使用的函数有限，因此如果你想筛选字符串，你会发现starts-with contains 这些xpath 函数都不支持。尽量使用其他条件筛选，然后再使用powershell内置过滤功能进行过滤，当然这要牺牲一些处理时间。
Xpath中的一些字符串要进行转义，比如你想比较一个数字，可能写Data>0,那么> 要转义成>