williballenthin / EVTXtract

EVTXtract recovers and reconstructs fragments of EVTX log files from raw binary data, including unallocated space and memory images.
Apache License 2.0
189 stars 22 forks source link

Parsing error #15

Open nwf9 opened 7 years ago

nwf9 commented 7 years ago

Hi Willi,

You will find below the traceback i met with the last release.

Scenario : Windows 2008

traceback evtxtract :

evtxtract raw_image.001 > evtxcarving.xml
INFO:evtxtract.carvers:Unknown exception processing record at 0xC74052200
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/evtxtract/carvers.py", line 174, in extract_chunk_records
    record_xml = Evtx.Views.evtx_record_xml_view(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 186, in evtx_record_xml_view
    return _build_record_xml(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 169, in _build_record_xml
    xml = rec(record.root())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 160, in rec
    subs_strs.append(rec(sub))
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 156, in rec
    for sub in root_node.fast_substitutions():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 925, in fast_substitutions
    ofs = self.tag_and_children_length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 900, in tag_and_children_length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 890, in children
    return self._children(end_tokens=[SYSTEM_TOKENS.EndOfStreamToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 124, in _children
    self._chunk, self)
TypeError: 'NoneType' object is not callable
INFO:evtxtract.carvers:Unicode decoding issue processing record at 0xC740533E0
INFO:evtxtract.carvers:Unicode decoding issue processing record at 0xC74053808
INFO:evtxtract.carvers:Unknown exception processing record at 0xC74053C80
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/evtxtract/carvers.py", line 174, in extract_chunk_records
    record_xml = Evtx.Views.evtx_record_xml_view(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 186, in evtx_record_xml_view
    return _build_record_xml(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 169, in _build_record_xml
    xml = rec(record.root())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 160, in rec
    subs_strs.append(rec(sub))
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 154, in rec
    f = _make_template_xml_view(root_node, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 129, in _make_template_xml_view
    for c in node.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 139, in children
    return self._children()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 477, in children
    self._chunk, self, self.type())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 439, in get_variant_value
    TypeClass = types[type_]
KeyError: 194

Thanks

williballenthin commented 7 years ago

hi @nwf9

thanks for reporting these tracebacks. would you confirm that these were not fatal errors that killed the carver? i think these are dangerous-looking messages, yet are simply there to let you know some records were unrecoverable (corrupt, etc). i should probably make this more clear.

nwf9 commented 7 years ago

Hi willi,

Unfortunately it would not crash the process until i stop them by a kill signal because i see a lot of activity with iotop but no more results...

williballenthin commented 7 years ago

@nwf9

thanks for the quick reply.

evtxtract does at least two passes of the entire image while carving event log entries. you can probably expect to see a bunch of complete entries extracted during the first run, and a slower rate of incomplete entries during the second run. it often takes quite a while to scan a large image (imagine the time it takes to copy 500GB, twice!).

nwf9 commented 7 years ago

Thanks to you for all your discovery. In my case i test only in 60GB. It's currently underway.

nwf9 commented 7 years ago

Unfortunately the process kill itself

evtxtract raw_disk.001 > evtxcarve.xml
INFO:evtxtract.carvers:Unknown exception processing record at 0xC74052200
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/evtxtract/carvers.py", line 174, in extract_chunk_records
    record_xml = Evtx.Views.evtx_record_xml_view(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 186, in evtx_record_xml_view
    return _build_record_xml(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 169, in _build_record_xml
    xml = rec(record.root())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 160, in rec
    subs_strs.append(rec(sub))
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 156, in rec
    for sub in root_node.fast_substitutions():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 925, in fast_substitutions
    ofs = self.tag_and_children_length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 900, in tag_and_children_length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 890, in children
    return self._children(end_tokens=[SYSTEM_TOKENS.EndOfStreamToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 124, in _children
    self._chunk, self)
TypeError: 'NoneType' object is not callable
INFO:evtxtract.carvers:Unicode decoding issue processing record at 0xC740533E0
INFO:evtxtract.carvers:Unicode decoding issue processing record at 0xC74053808
INFO:evtxtract.carvers:Unknown exception processing record at 0xC74053C80
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/evtxtract/carvers.py", line 174, in extract_chunk_records
    record_xml = Evtx.Views.evtx_record_xml_view(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 186, in evtx_record_xml_view
    return _build_record_xml(record, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 169, in _build_record_xml
    xml = rec(record.root())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 160, in rec
    subs_strs.append(rec(sub))
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 154, in rec
    f = _make_template_xml_view(root_node, cache=cache)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Views.py", line 129, in _make_template_xml_view
    for c in node.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 139, in children
    return self._children()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 305, in children
    SYSTEM_TOKENS.CloseEmptyElementToken])
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 130, in _children
    ofs += child.length()
  File "/usr/local/lib/python2.7/dist-packages/Evtx/BinaryParser.py", line 64, in __call__
    cache[key] = self.func(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 148, in length
    for child in self.children():
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 477, in children
    self._chunk, self, self.type())
  File "/usr/local/lib/python2.7/dist-packages/Evtx/Nodes.py", line 439, in get_variant_value
    TypeClass = types[type_]
KeyError: 194
Killed
williballenthin commented 7 years ago

@nwf9

when you see killed, this typically means that the operating system has killed the process, often because it is using too many resources. this stackoverflow post is related: http://stackoverflow.com/questions/19189522/what-does-killed-mean

do you have a limited amount of memory available on your analysis system?

nwf9 commented 7 years ago

I have 32 Gigagbytes and more than 24 CPU core

williballenthin commented 7 years ago

ok, thats probably not the issue :-)

this is going to be a little tricky to debug without lots of roundtrips. i will brainstorm on that front, and also go through the code with this issue in mind.

in the meantime, a solution that may work for you is to split the image into smaller fragments, and run evtxtract against each fragment. since evtxtract is a carver, the results should be similar as running a single time against the entire image.

thanks for you patience with this issue, and for responding quickly to my questions!

williballenthin commented 7 years ago

you can emulate the fragmentation technique without copying the data by using losetup. the flags --offset and --sizelimit can be used to expose a device that points to a sub-section of an existing file.

something like:

losetup --offset=$((0 * 1024 * 1024 * 1024 )) --sizelimit=$((1024 * 1024 * 1024 )) /dev/loop0 raw_disk.001
losetup --offset=$((1 * 1024 * 1024 * 1024 )) --sizelimit=$((1024 * 1024 * 1024 )) /dev/loop1 raw_disk.001
...
nwf9 commented 7 years ago

I will test only the evtx into the unallocated cluster

nwf9 commented 7 years ago

I can confirm that it works better on the unallocated cluster image because i was recover more than 110MB of event while i recover only 510K with a disk image.

nwf9 commented 7 years ago

Willi do you need some other log to debug ?