yampelo / beagle

Beagle is an incident response and digital forensics tool which transforms security logs and data into graphs.
MIT License
1.27k stars 145 forks source link

HX Triage parsing timeout in Beagle web gui #12

Closed hnsrck closed 5 years ago

hnsrck commented 5 years ago

Hello,

when uploading HX triage files over the web gui, apparently there is some initial parsing being done (see "MATCHED UP" log entries below). However, the worker times out after a couple of minutes, and no results are found under beagle:8000/fireeye_hx ("No Entries!").

2019-04-02T08:10:33 | beagle.web.api.views.new:208 | INFO | Recieved upload request for datasource=<HXTriage>, transformer=<FireEyeHXTransformer>
2019-04-02T08:10:33 | beagle.web.api.views.new:245 | INFO | Transforming data to a graph.
2019-04-02T08:10:33 | beagle.web.api.views.new:274 | INFO | Saved uploaded files {'triage': <tempfile._TemporaryFileWrapper object at 0x7f003153a240>}
2019-04-02T08:10:33 | beagle.datasources.hx_triage.__init__:53 | INFO | Setting up HXTriage for /tmp/tmpljshp3um
2019-04-02T08:10:33 | beagle.transformers.fireeye_hx_transformer.__init__:17 | INFO | Created FireEyeHX Transformer.
2019-04-02T08:10:38 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up 8f9a35e04670 to powershell from office programs
2019-04-02T08:10:38 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up b405089e5bfb to POWERSHELL DOWNLOADER C (METHODOLOGY)
2019-04-02T08:10:38 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up 5f795540aa46 to POWERSHELL DOWNLOADER (METHODOLOGY)
2019-04-02T08:10:38 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up af94a0db70fd to POWERSHELL DOWNLOADER D (METHODOLOGY)
2019-04-02T08:10:38 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up 8f9a35e04670 to powershell from office programs
[2019-04-02 08:18:54 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:13)
[2019-04-02 08:18:54 +0000] [13] [INFO] Worker exiting (pid: 13)
[2019-04-02 08:18:54 +0000] [42] [INFO] Booting worker with pid: 42
yampelo commented 5 years ago

Hmm, sounds like for some reason the node generation is hanging and not finishing.

Can you please run the docker container with the following env variable, upload again, and share the output?

BEAGLE__GENERAL__LOG_LEVEL=DEBUG

And make sure you are using the latest image:

docker pull yampelo/beagle
docker run ..... yampelo/beagle:latest
hnsrck commented 5 years ago

Should be latest version:

Using default tag: latest
latest: Pulling from yampelo/beagle
Digest: sha256:0a2b89ea00ef73ae5b0a593fcf42068291f9d79deeb5d85fa937910da1bcef72
Status: Image is up to date for yampelo/beagle:latest

Log after enabling DEBUG log level:

[2019-04-02 10:21:53 +0000] [1] [INFO] Starting gunicorn 19.9.0
[2019-04-02 10:21:53 +0000] [1] [INFO] Listening at: http://0.0.0.0:8000 (1)
[2019-04-02 10:21:53 +0000] [1] [INFO] Using worker: sync
[2019-04-02 10:21:53 +0000] [8] [INFO] Booting worker with pid: 8
[2019-04-02 10:21:53 +0000] [9] [INFO] Booting worker with pid: 9
[2019-04-02 10:21:53 +0000] [10] [INFO] Booting worker with pid: 10
[2019-04-02 10:21:53 +0000] [11] [INFO] Booting worker with pid: 11
[2019-04-02 10:21:53 +0000] [12] [INFO] Booting worker with pid: 12
[2019-04-02 10:21:53 +0000] [14] [INFO] Booting worker with pid: 14
[2019-04-02 10:21:53 +0000] [13] [INFO] Booting worker with pid: 13
[2019-04-02 10:21:53 +0000] [15] [INFO] Booting worker with pid: 15
[2019-04-02 10:21:53 +0000] [16] [INFO] Booting worker with pid: 16
[2019-04-02 10:21:53 +0000] [17] [INFO] Booting worker with pid: 17
[2019-04-02 10:21:53 +0000] [18] [INFO] Booting worker with pid: 18
[2019-04-02 10:21:54 +0000] [20] [INFO] Booting worker with pid: 20
2019-04-02T10:22:22 | beagle.web.api.views.new:208 | INFO | Recieved upload request for datasource=<HXTriage>, transformer=<FireEyeHXTransformer>
2019-04-02T10:22:22 | beagle.web.api.views.new:245 | INFO | Transforming data to a graph.
2019-04-02T10:22:22 | beagle.web.api.views.new:274 | INFO | Saved uploaded files {'triage': <tempfile._TemporaryFileWrapper object at 0x7fc21b9584e0>}
2019-04-02T10:22:22 | beagle.datasources.hx_triage.__init__:53 | INFO | Setting up HXTriage for /tmp/tmp2ihl2rzf
2019-04-02T10:22:23 | beagle.datasources.hx_triage.__init__:57 | DEBUG | Generated temporary directory /tmp/tmp8_oef_6j_beagle
2019-04-02T10:22:23 | beagle.datasources.hx_triage.__init__:93 | DEBUG | Mapped uHhXLpAJFw59wCydqwTvh2 to stateagentinspector
2019-04-02T10:22:23 | beagle.datasources.hx_triage.__init__:68 | DEBUG | Found alert file hits.json
2019-04-02T10:22:23 | beagle.datasources.hx_triage.__init__:68 | DEBUG | Found alert file threats.json
2019-04-02T10:22:23 | beagle.transformers.fireeye_hx_transformer.__init__:17 | INFO | Created FireEyeHX Transformer.
2019-04-02T10:22:23 | beagle.transformers.base_transformer.run:77 | DEBUG | Launching transformer
2019-04-02T10:22:23 | beagle.transformers.base_transformer.run:86 | DEBUG | Started producer thread
2019-04-02T10:22:23 | beagle.transformers.base_transformer.run:94 | DEBUG | Started 0 consumer threads
2019-04-02T10:22:26 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a4b642d2-9d06-4437-8128-8f9a35e04670 to powershell from office programs
2019-04-02T10:22:26 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a73f410b-ac29-4108-8cdd-b405089e5bfb to POWERSHELL DOWNLOADER C (METHODOLOGY)
2019-04-02T10:22:26 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up 47811c94-d301-4008-b3cf-5f795540aa46 to POWERSHELL DOWNLOADER (METHODOLOGY)
2019-04-02T10:22:26 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up f642355c-a6dd-43af-bc9b-af94a0db70fd to POWERSHELL DOWNLOADER D (METHODOLOGY)
2019-04-02T10:22:26 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a4b642d2-9d06-4437-8128-8f9a35e04670 to powershell from office programs
2019-04-02T10:22:26 | beagle.transformers.base_transformer._producer_thread:121 | DEBUG | Producer Thread Thread-1 finished after 18569 events
[2019-04-02 10:30:42 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:13)
[2019-04-02 10:30:43 +0000] [13] [INFO] Worker exiting (pid: 13)
[2019-04-02 10:30:43 +0000] [33] [INFO] Booting worker with pid: 33
yampelo commented 5 years ago

Thats interesting, it looks like your docker container is return 1 from mp.cpu_count():

2019-04-02T10:22:23 | beagle.transformers.base_transformer.run:86 | DEBUG | Started producer thread
2019-04-02T10:22:23 | beagle.transformers.base_transformer.run:94 | DEBUG | Started 0 consumer threads

Since the transformers use a producer/consumer queue, there's a thread giving out events, but nothing is spawned to consume them. Can you explicitly giving more CPUs through docker? I'm going to add a fix meanwhile that guarantees that at least one consumer and producer thread are spawned.

--cpus="4"
hnsrck commented 5 years ago

After adding another CPU to the VM I was running the docker image in, the graph was created successfully, even without applying the most recent commit, see below.

Great tool, I'll do some more testing in the upcoming days/weeks.

2019-04-02T11:04:18 | beagle.web.api.views.new:208 | INFO | Recieved upload request for datasource=<HXTriage>, transformer=<FireEyeHXTransformer>
2019-04-02T11:04:18 | beagle.web.api.views.new:245 | INFO | Transforming data to a graph.
2019-04-02T11:04:18 | beagle.web.api.views.new:274 | INFO | Saved uploaded files {'triage': <tempfile._TemporaryFileWrapper object at 0x7f9c5b7aa828>}
2019-04-02T11:04:18 | beagle.datasources.hx_triage.__init__:53 | INFO | Setting up HXTriage for /tmp/tmpmsd9m39h
2019-04-02T11:04:18 | beagle.datasources.hx_triage.__init__:57 | DEBUG | Generated temporary directory /tmp/tmp2pczqkkg_beagle
2019-04-02T11:04:18 | beagle.datasources.hx_triage.__init__:93 | DEBUG | Mapped uHhXLpAJFw59wCydqwTvh2 to stateagentinspector
2019-04-02T11:04:18 | beagle.datasources.hx_triage.__init__:68 | DEBUG | Found alert file hits.json
2019-04-02T11:04:18 | beagle.datasources.hx_triage.__init__:68 | DEBUG | Found alert file threats.json
2019-04-02T11:04:18 | beagle.transformers.fireeye_hx_transformer.__init__:17 | INFO | Created FireEyeHX Transformer.
2019-04-02T11:04:18 | beagle.transformers.base_transformer.run:77 | DEBUG | Launching transformer
2019-04-02T11:04:18 | beagle.transformers.base_transformer.run:86 | DEBUG | Started producer thread
2019-04-02T11:04:18 | beagle.transformers.base_transformer.run:94 | DEBUG | Started 1 consumer threads
2019-04-02T11:04:23 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a4b642d2-9d06-4437-8128-8f9a35e04670 to powershell from office programs
2019-04-02T11:04:23 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a73f410b-ac29-4108-8cdd-b405089e5bfb to POWERSHELL DOWNLOADER C (METHODOLOGY)
2019-04-02T11:04:23 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up 47811c94-d301-4008-b3cf-5f795540aa46 to POWERSHELL DOWNLOADER (METHODOLOGY)
2019-04-02T11:04:23 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up f642355c-a6dd-43af-bc9b-af94a0db70fd to POWERSHELL DOWNLOADER D (METHODOLOGY)
2019-04-02T11:04:23 | beagle.datasources.hx_triage.parse_alert_files:293 | INFO | Matched up a4b642d2-9d06-4437-8128-8f9a35e04670 to powershell from office programs
2019-04-02T11:04:24 | beagle.transformers.base_transformer._producer_thread:121 | DEBUG | Producer Thread Thread-1 finished after 18569 events
2019-04-02T11:04:24 | beagle.transformers.base_transformer._consumer_thread:132 | DEBUG | Consumer Thread Thread-2 finished after processing 18570 events
2019-04-02T11:04:24 | beagle.transformers.base_transformer.run:107 | INFO | Finished processing of events, created 55715 nodes.
2019-04-02T11:04:24 | beagle.backends.networkx.__init__:51 | INFO | Initialized NetworkX Backend
2019-04-02T11:04:24 | beagle.backends.networkx.graph:65 | INFO | Beginning graph generation.
2019-04-02T11:04:25 | beagle.backends.networkx.graph:71 | INFO | Completed graph generation.
2019-04-02T11:04:25 | beagle.backends.networkx.graph:72 | INFO | Graph contains 1404 nodes and 3374 edges.
2019-04-02T11:04:25 | beagle.web.api.views.new:305 | INFO | Finished generating graph
2019-04-02T11:04:26 | beagle.web.api.views.new:340 | INFO | Added graph to database with id=1
2019-04-02T11:04:26 | beagle.web.api.views.new:344 | INFO | Saved graph to /data/beagle/fireeye_hx/891a86ea93c67f8163f1775c10e44b7622539454ba6b83862aa8c4735710bb9c.json
yampelo commented 5 years ago

Perfect! You should be able to just pull the latest image (once it finishes building) and you won't need to explicitly set the cpu count anymore.