williballenthin / python-evtx

Pure Python parser for Windows Event Log files (.evtx)
Apache License 2.0
719 stars 165 forks source link

parse_filetime error #71

Closed jsaspo closed 3 years ago

jsaspo commented 3 years ago

Using evtx_dump.py to dump several .evtx logs successfully. However, I have one System.evtx that produces the following error mid-dump (the XML at the top is the last successful record "1190" before the dump errors out:

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event"><System><Provider Name="Microsoft-Windows-WLAN-AutoConfig" Guid="{9580d7dd-0379-4658-9870-d5be7d52d6de}"></Provider>
<EventID Qualifiers="">10002</EventID>
<Version>0</Version>
<Level>3</Level>
<Task>0</Task>
<Opcode>0</Opcode>
<Keywords>0x4000000000000000</Keywords>
<TimeCreated SystemTime="2019-07-23 16:07:17.966570"></TimeCreated>
<EventRecordID>1190</EventRecordID>
<Correlation ActivityID="" RelatedActivityID=""></Correlation>
<Execution ProcessID="2012" ThreadID="10056"></Execution>
<Channel>System</Channel>
<Computer>DESKTOP-LOJVG3N</Computer>
<Security UserID="S-1-5-18"></Security>
</System>
<EventData><Data Name="ExtensibleModulePath">C:\WINDOWS\System32\bcmihvsrv64.dll</Data>
</EventData>
</Event>

Traceback (most recent call last):
  File "evtx_dump.py", line 42, in <module>
    main()
  File "evtx_dump.py", line 37, in main
    print(record.xml())
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Evtx.py", line 481, in xml
    return e_views.evtx_record_xml_view(self)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 204, in evtx_record_xml_view
    return render_root_node(record.root())
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 191, in render_root_node
    return render_root_node_with_subs(root_node, subs)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 176, in render_root_node_with_subs
    rec(c, acc)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 126, in rec
    rec(child, acc)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 166, in rec
    sub = render_root_node(sub.root())
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 191, in render_root_node
    return render_root_node_with_subs(root_node, subs)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 176, in render_root_node_with_subs
    rec(c, acc)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 126, in rec
    rec(child, acc)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 126, in rec
    rec(child, acc)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Views.py", line 159, in rec
    sub = escape_value(sub.string())
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Nodes.py", line 1401, in string
    return self.filetime().isoformat(' ')
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 205, in no_length_handler
    return f(offset)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 518, in unpack_filetime
    return parse_filetime(self.unpack_qword(offset))
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 109, in parse_filetime
    return datetime.utcfromtimestamp(float(qword) * 1e-7 - 11644473600)
OSError: [Errno 22] Invalid argument

I'm assuming this is an issue with the following record "1191". Here is the Event Viewer display for that record:

evtx_friendly

Here is the evtx_record_strcture.py dump of that record:

00000000: 2A 2A 00 00 40 03 00 00  A7 04 00 00 00 00 00 00  **..@...........
00000010: 8A B6 09 B4 70 41 D5 01  0F 01 01 00 0C 01 FE 13  ....pA..........
00000020: 19 70 C6 08 00 00 12 00  00 00 01 00 04 00 01 00  .p..............
00000030: 04 00 02 00 06 00 02 00  06 00 02 00 00 00 08 00  ................
00000040: 15 00 08 00 11 00 10 00  00 00 04 00 08 00 04 00  ................
00000050: 08 00 08 00 0A 00 01 00  04 00 00 00 00 00 00 00  ................
00000060: 00 00 3C 00 01 00 10 00  0F 00 0C 00 01 00 33 02  ..<...........3.
00000070: 21 00 04 00 66 00 6B 00  01 00 44 04 00 00 00 00  !...f.k...D.....
00000080: 00 80 8A B6 09 B4 70 41  D5 01 C0 6B FE 0D 7B 02  ......pA...k..{.
00000090: 00 00 00 A7 57 0F 7B 02  00 00 04 00 00 00 B0 1F  ....W.{.........
000000A0: 00 00 A7 04 00 00 00 00  00 00 01 4D 00 69 00 63  ...........M.i.c
000000B0: 00 72 00 6F 00 73 00 6F  00 66 00 74 00 2D 00 57  .r.o.s.o.f.t.-.W
000000C0: 00 69 00 6E 00 64 00 6F  00 77 00 73 00 2D 00 4B  .i.n.d.o.w.s.-.K
000000D0: 00 65 00 72 00 6E 00 65  00 6C 00 2D 00 50 00 6F  .e.r.n.e.l.-.P.o
000000E0: 00 77 00 65 00 72 00 3A  3B 1C 33 05 20 C2 44 AC  .w.e.r.:;.3. .D.
000000F0: 5E 77 22 0C 37 D6 B4 53  00 79 00 73 00 74 00 65  ^w".7..S.y.s.t.e
00000100: 00 6D 00 0C 01 35 30 B6  4B 95 32 00 00 00 00 00  .m...50.K.2.....
00000110: 00 35 30 B6 4B E7 43 00  5C 0B 65 E7 CA 15 48 68  .50.K.C.\.e...Hh
00000120: 71 CC 01 00 00 0F 01 01  00 01 FF FF C0 01 00 00  q...............
00000130: 35 06 00 00 02 41 FF FF  2D 00 00 00 5D 06 00 00  5....A..-...]...
00000140: 1F 00 00 00 06 3D 03 00  00 05 01 0B 00 54 00 61  .....=.......T.a
00000150: 00 72 00 67 00 65 00 74  00 53 00 74 00 61 00 74  .r.g.e.t.S.t.a.t
00000160: 00 65 00 02 0D 00 00 08  04 41 FF FF 33 00 00 00  .e.......A..3...
00000170: 5D 06 00 00 25 00 00 00  06 3D 03 00 00 05 01 0E  ]...%....=......
00000180: 00 45 00 66 00 66 00 65  00 63 00 74 00 69 00 76  .E.f.f.e.c.t.i.v
00000190: 00 65 00 53 00 74 00 61  00 74 00 65 00 02 0D 01  .e.S.t.a.t.e....
000001A0: 00 08 04 41 FF FF 31 00  00 00 5D 06 00 00 23 00  ...A..1...]...#.
000001B0: 00 00 06 3D 03 00 00 05  01 0D 00 57 00 61 00 6B  ...=.......W.a.k
000001C0: 00 65 00 46 00 72 00 6F  00 6D 00 53 00 74 00 61  .e.F.r.o.m.S.t.a
000001D0: 00 74 00 65 00 02 0D 02  00 08 04 41 FF FF 3F 00  .t.e.......A..?.
000001E0: 00 00 5D 06 00 00 31 00  00 00 06 3D 03 00 00 05  ..]...1....=....
000001F0: 01 14 00 50 00 72 00 6F  00 67 00 72 00 61 00 6D  ...P.r.o.g.r.a.m
00000200: 00 6D 00 65 00 64 00 57  00 61 00 6B 00 65 00 54  .m.e.d.W.a.k.e.T
00000210: 00 69 00 6D 00 65 00 41  00 63 00 02 0D 03 00 11  .i.m.e.A.c......
00000220: 04 41 FF FF 3F 00 00 00  5D 06 00 00 31 00 00 00  .A..?...]...1...
00000230: 06 3D 03 00 00 05 01 14  00 50 00 72 00 6F 00 67  .=.......P.r.o.g
00000240: 00 72 00 61 00 6D 00 6D  00 65 00 64 00 57 00 61  .r.a.m.m.e.d.W.a
00000250: 00 6B 00 65 00 54 00 69  00 6D 00 65 00 44 00 63  .k.e.T.i.m.e.D.c
00000260: 00 02 0D 04 00 11 04 41  FF FF 3D 00 00 00 5D 06  .......A..=...].
00000270: 00 00 2F 00 00 00 06 3D  03 00 00 05 01 13 00 57  ../....=.......W
00000280: 00 61 00 6B 00 65 00 52  00 65 00 71 00 75 00 65  .a.k.e.R.e.q.u.e
00000290: 00 73 00 74 00 65 00 72  00 54 00 79 00 70 00 65  .s.t.e.r.T.y.p.e
000002A0: 00 41 00 63 00 02 0D 05  00 08 04 41 FF FF 3D 00  .A.c.......A..=.
000002B0: 00 00 5D 06 00 00 2F 00  00 00 06 3D 03 00 00 05  ..].../....=....
000002C0: 01 13 00 57 00 61 00 6B  00 65 00 52 00 65 00 71  ...W.a.k.e.R.e.q
000002D0: 00 75 00 65 00 73 00 74  00 65 00 72 00 54 00 79  .u.e.s.t.e.r.T.y
000002E0: 00 70 00 65 00 44 00 63  00 02 0D 06 00 08 04 04  .p.e.D.c........
000002F0: 00 07 00 00 00 04 00 08  00 04 00 08 00 04 00 08  ................
00000300: 00 08 00 11 00 08 00 11  00 04 00 08 00 04 00 08  ................
00000310: 00 04 00 00 00 04 00 00  00 04 00 00 00 00 61 C0  ..............a.
00000320: 35 BD 4B D5 01 00 00 00  00 00 00 00 00 02 00 00  5.K.............
00000330: 00 00 00 00 00 00 00 00  2A 2A 00 00 40 03 00 00  ........**..@...
record(absolute_offset=672136)
Traceback (most recent call last):
  File "evtx_record_structure.py", line 106, in <module>
    main()
  File "evtx_record_structure.py", line 101, in main
    print(describe_root(record, record.root(), suppress_values=args.suppress_values))
  File "evtx_record_structure.py", line 79, in describe_root
    ret += rec(root, indent=indent)
  File "evtx_record_structure.py", line 74, in rec
    ret += "%s\n" % (format_node(sub, indent=indent + 2))
  File "evtx_record_structure.py", line 41, in format_node
    ret += describe_root(record, n._root, indent=indent + 1)
  File "evtx_record_structure.py", line 79, in describe_root
    ret += rec(root, indent=indent)
  File "evtx_record_structure.py", line 74, in rec
    ret += "%s\n" % (format_node(sub, indent=indent + 2))
  File "evtx_record_structure.py", line 38, in format_node
    ret += " --> %s" % (n.string())
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\Nodes.py", line 1401, in string
    return self.filetime().isoformat(' ')
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 205, in no_length_handler
    return f(offset)
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 518, in unpack_filetime
    return parse_filetime(self.unpack_qword(offset))
  File "C:\Users\Jay Sasportas\AppData\Roaming\Python\Python38\site-packages\Evtx\BinaryParser.py", line 109, in parse_filetime
    return datetime.utcfromtimestamp(float(qword) * 1e-7 - 11644473600)
OSError: [Errno 22] Invalid argument
jsaspo commented 3 years ago

I now see that Issue #69 was recently closed with this same log, event ID, and error. Was there a fix?

williballenthin commented 3 years ago

the reporter closed the issue without any further information. im not aware of any fix.

interesting that its the same log/id/error. i'm not able to provide too much support for this parser these days, but perhaps i can take a peek and attempt a fix if its obvious.

williballenthin commented 3 years ago

taking a hint from this post, i've found that Python on Windows handles dates differently than on Linux (i guess thats probably not a surprise to anyone). specifically, a "zero date" (like the 1601-01... one you show above) cannot be represented correctly:

image

I'll update the date parsing code to better handle this case on Windows

williballenthin commented 3 years ago

although... i think this should be fixed in master thanks to 28095cc24fdd972531b67edc8aa80bdf83c403ef and a5eac06a44c232cca509d8a5308e61c3989faf99

do you have a moment to try out the code in master? if it works for you, i'll cut a new release and upload to pypi

jsaspo commented 3 years ago

Thank you for the quick response. The code in master worked great! No issue, buzzed through the entire System.evtx.

I should have looked into this further. I used pip install initially and didn't realize the versions are different. I'm a little green on Git/PyPi.

Awesome, thanks again.

jsaspo commented 3 years ago

@williballenthin

Closing as it appears this is resolved in master.