CERT-Polska / drakvuf-sandbox

DRAKVUF Sandbox - automated hypervisor-level malware analysis system
https://drakvuf-sandbox.readthedocs.io/
Other
1.05k stars 143 forks source link

Error in drak-postprocess #378

Open eddydenantes opened 3 years ago

eddydenantes commented 3 years ago

Hi everyone,

I'm currently facing a bug with drak-postprocess when i want to generate a graph with ProcDOT. I followed the differents steps for the installation process on the documentation but it's still failing (documentation).

I decided to check the log associated to drak-postprocess@1.service and i get this output :

déc. 09 14:14:37 debian drak-postprocess[518]: b'{"Plugin":"filetracer","TimeStamp":"1607519591.439909","PID":768,"PPID":440,"TID":2768,"UserName":"SessionID","UserId":0,"ProcessName":"\\Device\\HarddiskVolume2\\Windows\\System32\\svchost.exe","Method":"NtSetInformationFile","EventUID":"0x2edf98","Operation":"FileBasicInformation","FileHandle":"0x80000874","FileName":"\xe8\xa7\x8d\x01","CreationTime":"0x0","LastAccessTime":"0x0","LastWriteTime":"0xffffffffffffffff","ChangeTime":"0xffffffffffffffff","FileAttributes":"(null)"}\n' déc. 09 14:14:37 debian drak-postprocess[518]: Traceback (most recent call last): déc. 09 14:14:37 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/postprocess/drakparse.py", line 163, in parse_logs déc. 09 14:14:37 debian drak-postprocess[518]: line_obj = json.loads(line) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/init.py", line 348, in loads déc. 09 14:14:37 debian drak-postprocess[518]: return _default_decoder.decode(s) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/decoder.py", line 337, in decode déc. 09 14:14:37 debian drak-postprocess[518]: obj, end = self.raw_decode(s, idx=_w(s, 0).end()) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/decoder.py", line 353, in raw_decode déc. 09 14:14:37 debian drak-postprocess[518]: obj, end = self.scan_once(s, idx) déc. 09 14:14:37 debian drak-postprocess[518]: json.decoder.JSONDecodeError: Invalid control character at: line 1 column 324 (char 323) déc. 09 14:14:37 debian drak-postprocess[518]: ERROR:root:BUG: Unparseable log entry! déc. 09 14:14:37 debian drak-postprocess[518]: b'{"Plugin":"syscall","TimeStamp":"1607519591.439909","PID":768,"PPID":440,"TID":2768,"UserName":"SessionID","UserId":0,"ProcessName":"\\Device\\HarddiskVolume2\\Windows\\System32\\svchost.exe","Method":"NtSetInformationFile","EventUID":"0x2edf98","Module":"nt","vCPU":1,"CR3":"0x5e9f8000","Syscall":36,"NArgs":5,"FileHandle":"\xe8\xa7\x8d\x01","IoStatusBlock":"0xfffff880047628a8","FileInformation":"0xfffff88004762990","Length":"0x28","FileInformationClass":"0x4"}\n' déc. 09 14:14:37 debian drak-postprocess[518]: Traceback (most recent call last): déc. 09 14:14:37 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/postprocess/drakparse.py", line 163, in parse_logs déc. 09 14:14:37 debian drak-postprocess[518]: line_obj = json.loads(line) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/init.py", line 348, in loads déc. 09 14:14:37 debian drak-postprocess[518]: return _default_decoder.decode(s) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/decoder.py", line 337, in decode déc. 09 14:14:37 debian drak-postprocess[518]: obj, end = self.raw_decode(s, idx=_w(s, 0).end()) déc. 09 14:14:37 debian drak-postprocess[518]: File "/usr/lib/python3.7/json/decoder.py", line 353, in raw_decode déc. 09 14:14:37 debian drak-postprocess[518]: obj, end = self.scan_once(s, idx) déc. 09 14:14:37 debian drak-postprocess[518]: json.decoder.JSONDecodeError: Invalid control character at: line 1 column 327 (char 326) déc. 09 14:14:40 debian drak-postprocess[518]: procmon2dot (Build 48u) déc. 09 14:14:40 debian drak-postprocess[518]: Loading ignore-file "procmon2dot_fileignores.dat" ... MD5: déc. 09 14:14:40 debian drak-postprocess[518]: Loading ignore-file "procmon2dot_registrykeyignores.dat" ... MD5: déc. 09 14:14:40 debian drak-postprocess[518]: Loading ignore-file "procmon2dot_serverignores.dat" ... MD5: déc. 09 14:14:40 debian procmon2dot[6705]: Warning: ReadFile(#PB_Any, 'procmon2dot_serverignores.dat') failed! (Callstack: ) déc. 09 14:14:40 debian drak-postprocess[518]: Collecting Procmon data ... déc. 09 14:14:45 debian drak-postprocess[518]: 168723 lines déc. 09 14:14:45 debian drak-postprocess[518]: 70 processes déc. 09 14:14:45 debian drak-postprocess[518]: 1000 threads déc. 09 14:14:45 debian drak-postprocess[518]: 456 files déc. 09 14:14:45 debian drak-postprocess[518]: 539 registry keys déc. 09 14:14:45 debian drak-postprocess[518]: 0 servers déc. 09 14:14:45 debian drak-postprocess[518]: 0 connections déc. 09 14:14:45 debian drak-postprocess[518]: Done. déc. 09 14:14:45 debian drak-postprocess[518]: Managing launcher ... déc. 09 14:14:45 debian drak-postprocess[518]: Launcher found: PID 1264-n2 déc. 09 14:14:45 debian drak-postprocess[518]: Done. déc. 09 14:14:45 debian drak-postprocess[518]: Collecting network data ... déc. 09 14:14:45 debian drak-postprocess[518]: No file provided! déc. 09 14:14:45 debian drak-postprocess[518]: Done. déc. 09 14:14:45 debian drak-postprocess[518]: Analyzing data ... déc. 09 14:14:45 debian drak-postprocess[518]: Done. déc. 09 14:14:45 debian drak-postprocess[518]: Writing files ... déc. 09 14:14:46 debian drak-postprocess[518]: Done. déc. 09 14:14:46 debian drak-postprocess[518]: End. déc. 09 14:14:46 debian drak-postprocess[518]: [2020-12-09 14:14:46,395][ERROR] Postprocess failed déc. 09 14:14:46 debian drak-postprocess[518]: Traceback (most recent call last): déc. 09 14:14:46 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/process.py", line 86, in process déc. 09 14:14:46 debian drak-postprocess[518]: outputs = plugin.handler(self.current_task, task_resources, self.minio) déc. 09 14:14:46 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/postprocess/generate_graphs.py", line 31, in generate_graphs déc. 09 14:14:46 debian drak-postprocess[518]: minio.fput_object("drakrun", f"{analysis_uid}/graph.dot", os.path.join(output_dir, 'graph.dot')) déc. 09 14:14:46 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/minio/api.py", line 628, in fput_object déc. 09 14:14:46 debian drak-postprocess[518]: with open(file_path, 'rb') as file_data: déc. 09 14:14:46 debian drak-postprocess[518]: FileNotFoundError: [Errno 2] No such file or directory: '/tmp/tmpkmrw1s4f/graph.dot' déc. 09 14:15:29 debian drak-postprocess[518]: ERROR:root:Failed to parse 90 lines generated by unknown déc. 09 14:15:38 debian drak-postprocess[518]: [2020-12-09 14:15:38,409][INFO] Skipping generate_ipt_disasm, missing resources déc. 09 14:15:41 debian drak-postprocess[518]: [2020-12-09 14:15:41,694][INFO] Task done - d230b6d2-1ecb-43a1-993c-87bca18c5cc1

I'm using :

Have anyone an advice ?

icedevml commented 3 years ago

Hello, thanks for the bug report.

According to @BonusPlay, this is already known to us internally. @BonusPlay Could you describe what is the exact problem here? I will try to fix this with a PR.

eddydenantes commented 3 years ago

Thanks for you answer, I will be waiting for the fix.

I don't know if it's help you but in the same log file i also have those lines :

déc. 09 13:25:40 debian drak-postprocess[518]: b'{"Plugin":"procmon","TimeStamp":"1607516435.094337","PID":4,"PPID":0,"RunningProcess":"System"}\n' déc. 09 13:25:40 debian drak-postprocess[518]: Traceback (most recent call last): déc. 09 13:25:40 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/postprocess/drakparse.py", line 177, in parse_logs déc. 09 13:25:40 debian drak-postprocess[518]: converted = str(plugin_obj(line_obj)) déc. 09 13:25:40 debian drak-postprocess[518]: File "/opt/venvs/drakcore/lib/python3.7/site-packages/drakcore/postprocess/drakparse.py", line 73, in init déc. 09 13:25:40 debian drak-postprocess[518]: if obj["Method"] == "NtCreateUserProcess": déc. 09 13:25:40 debian drak-postprocess[518]: KeyError: 'Method' déc. 09 13:25:40 debian drak-postprocess[518]: ERROR:root:BUG: Failed to parse log entry.