Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Getting what appears to be a timeout with Cuckoo #56

Open
smclinden opened this issue Oct 16, 2018 · 4 comments
Open

Getting what appears to be a timeout with Cuckoo #56

smclinden opened this issue Oct 16, 2018 · 4 comments

Comments

@smclinden
Copy link

I have verified that Cuckoo was able to download and analyze the file so I'm looking for suggestions as to how to proceed. The parameters for the Cuckoo module are:

WAIT_TIMEOUT 5400
WAIT_STEP 30
ANALYSIS_TIME 300

2018-10-16 08:52: debug: Trying to run cuckoo
2018-10-16 09:05: error: cuckoo: Could not run on http://microsoftupdate.dynamicdns.org.uk/host/290.exe.
Traceback (most recent call last):
File "/home/cirt/fame/fame/core/module.py", line 492, in _try_each
return self.each_with_type(target, file_type)
File "/home/cirt/fame/fame/modules/community/processing/cuckoo/cuckoo.py", line 97, in each_with_type
self.process_report()
File "/home/cirt/fame/fame/modules/community/processing/cuckoo/cuckoo.py", line 159, in process_report
self.extract_info(response)
File "/home/cirt/fame/fame/modules/community/processing/cuckoo/cuckoo.py", line 166, in extract_info
for prefix, event, value in parser:
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/common.py", line 65, in parse
for event, value in basic_events:
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 185, in basic_parse
for value in parse_value(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 119, in parse_value
for event in parse_object(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 163, in parse_object
for event in parse_value(lexer, None, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 119, in parse_value
for event in parse_object(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 163, in parse_object
for event in parse_value(lexer, None, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 116, in parse_value
for event in parse_array(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 138, in parse_array
for event in parse_value(lexer, symbol, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 119, in parse_value
for event in parse_object(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 163, in parse_object
for event in parse_value(lexer, None, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 116, in parse_value
for event in parse_array(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 138, in parse_array
for event in parse_value(lexer, symbol, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 119, in parse_value
for event in parse_object(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 163, in parse_object
for event in parse_value(lexer, None, pos):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 119, in parse_value
for event in parse_object(lexer):
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 170, in parse_object
pos, symbol = next(lexer)
File "/home/cirt/fame/env/local/lib/python2.7/site-packages/ijson/backends/python.py", line 65, in Lexer
data = f.read(buf_size)
File "/home/cirt/fame/env/lib/python2.7/codecs.py", line 488, in read
newdata = self.stream.read(size)
File "/usr/lib/python2.7/socket.py", line 384, in read
data = self._sock.recv(left)
error: [Errno 104] Connection reset by peer

@smclinden
Copy link
Author

Could someone share configuration settings in FAME to work with Cuckoo? I was getting timeout errors and I changed the tcp_keepalive settings which appeared to have helped (no longer getting connection reset problems) but now I get "could not get report before timeout" errors for the Cuckoo process. If I run the same URL analysis on Cuckoo instead of feeding it from FAME, it works just fine!

@gaelmuller
Copy link
Collaborator

The default configuration values work fine for a local instance of cuckoo. Could you provide us with the cuckoo logs related to this analysis ? (is there a cuckoo analysis created ? is it 'reported' before the timeout ?)

@smclinden
Copy link
Author

The Cuckoo analysis completes. I can see it in the Cuckoo dashboard. Here is a copy of the relevent logs. Note that about an hour of processing occurs before the analysis is completed. This is Cuckoo 2.0.6.

2018-11-09 14:54:48,654 [cuckoo.core.scheduler] INFO: Task #1122: acquired machine win1 (label=win1)
2018-11-09 14:54:48,684 [cuckoo.auxiliary.sniffer] INFO: Started sniffer with PID 30631 (interface=vboxnet0, host=192.168.56.101)
2018-11-09 14:54:48,685 [cuckoo.core.plugins] DEBUG: Started auxiliary module: Sniffer
2018-11-09 14:54:48,708 [cuckoo.machinery.virtualbox] DEBUG: Starting vm win1
2018-11-09 14:54:48,921 [cuckoo.machinery.virtualbox] DEBUG: Restoring virtual machine win1 to init
2018-11-09 14:54:49,706 [cuckoo.machinery.virtualbox] INFO: Successfully set remote control ports for virtual machine with label win1: 9000-9100
2018-11-09 14:54:49,858 [cuckoo.machinery.virtualbox] INFO: Successfully enabled remote control for virtual machine with label win1 on port(s): 9000-9100
2018-11-09 14:54:52,423 [cuckoo.core.scheduler] WARNING: Internet network routing has been specified, but not configured, ignoring routing for this analysis
2018-11-09 14:54:52,440 [cuckoo.core.guest] INFO: Starting analysis on guest (id=win1, ip=192.168.56.101)
2018-11-09 14:54:53,444 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:54,451 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:55,458 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:55,502 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:57,510 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:58,517 [cuckoo.core.guest] DEBUG: win1: not ready yet
2018-11-09 14:54:58,683 [cuckoo.core.guest] INFO: Guest is running Cuckoo Agent 0.8 (id=win1, ip=192.168.56.101)
2018-11-09 14:54:58,752 [cuckoo.core.guest] DEBUG: Uploading analyzer to guest (id=win1, ip=192.168.56.101, monitor=latest, size=3834623)
2018-11-09 14:54:59,261 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:00,144 [cuckoo.core.resultserver] DEBUG: LogHandler for live analysis.log initialized.
2018-11-09 14:55:00,274 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:01,281 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:02,295 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:02,329 [cuckoo.core.resultserver] DEBUG: New process (pid=1136, ppid=1592, name=iexplore.exe)
2018-11-09 14:55:03,084 [cuckoo.core.resultserver] DEBUG: File upload request for memory/1672-1.dmp
2018-11-09 14:55:03,194 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 2355680
2018-11-09 14:55:03,290 [cuckoo.core.resultserver] DEBUG: File upload request for shots/0001.jpg
2018-11-09 14:55:03,296 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 46565
2018-11-09 14:55:03,302 [cuckoo.core.resultserver] DEBUG: New process (pid=1672, ppid=1136, name=iexplore.exe)
2018-11-09 14:55:03,314 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:04,326 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:04,373 [cuckoo.core.resultserver] DEBUG: File upload request for shots/0002.jpg
2018-11-09 14:55:04,389 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 40268
2018-11-09 14:55:05,335 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:05,455 [cuckoo.core.resultserver] DEBUG: File upload request for shots/0003.jpg
2018-11-09 14:55:05,481 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 65510
2018-11-09 14:55:06,345 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-09 14:55:06,525 [cuckoo.core.resultserver] DEBUG: File upload request for shots/0004.jpg
2018-11-09 14:55:06,532 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 65907
2018-11-09 14:55:07,357 [cuckoo.core.guest] DEBUG: win1: analysis still processing
...
2018-11-10 15:55:02,640 [cuckoo.core.guest] DEBUG: win1: analysis still processing
2018-11-10 15:55:03,436 [cuckoo.core.resultserver] DEBUG: File upload request for files/1471693be91e53c2_background_gradient[1]
2018-11-10 15:55:03,437 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 453
2018-11-10 15:55:03,450 [cuckoo.core.resultserver] DEBUG: File upload request for files/70f316a5492848bb_down[1]
2018-11-10 15:55:03,451 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 3414
2018-11-10 15:55:03,466 [cuckoo.core.resultserver] DEBUG: File upload request for files/62a7038cc42c1482_tools[1]
2018-11-10 15:55:03,466 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 3560
2018-11-10 15:55:03,482 [cuckoo.core.resultserver] DEBUG: File upload request for files/58268ca71a28973b_httperrorpagesscripts[1]
2018-11-10 15:55:03,483 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 8601
2018-11-10 15:55:03,500 [cuckoo.core.resultserver] DEBUG: File upload request for files/6976c426e3ac66d6_noconnect[1]
2018-11-10 15:55:03,501 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 8230
2018-11-10 15:55:03,540 [cuckoo.core.resultserver] DEBUG: File upload request for files/55fde63881fb0b96_recoverystore.{ee6cffbf-e450-11e8-99e7-080027818d97}.dat
2018-11-10 15:55:03,540 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 3584
2018-11-10 15:55:03,546 [cuckoo.core.resultserver] DEBUG: File upload request for files/1ff3334c3eb27033_dnserror[1]
2018-11-10 15:55:03,547 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 5947
2018-11-10 15:55:03,569 [cuckoo.core.resultserver] DEBUG: File upload request for files/eb5678de9d8f29ca_errorpagestrings[1]
2018-11-10 15:55:03,570 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 1817
2018-11-10 15:55:03,575 [cuckoo.core.resultserver] DEBUG: File upload request for files/07d07a467e4988d3_favcenter[1]
2018-11-10 15:55:03,576 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 3366
2018-11-10 15:55:03,583 [cuckoo.core.resultserver] DEBUG: File upload request for files/ad3753221258d268_{ee6cffc0-e450-11e8-99e7-080027818d97}.dat
2018-11-10 15:55:03,584 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 4608
2018-11-10 15:55:03,589 [cuckoo.core.resultserver] DEBUG: File upload request for files/8d018639281b33da_errorpagetemplate[1]
2018-11-10 15:55:03,590 [cuckoo.core.resultserver] DEBUG: Uploaded file length: 2168
2018-11-10 15:55:03,648 [cuckoo.core.guest] INFO: win1: analysis completed successfully
2018-11-10 15:55:03,695 [cuckoo.core.plugins] DEBUG: Stopped auxiliary module: Sniffer
2018-11-10 15:55:03,696 [cuckoo.machinery.virtualbox] DEBUG: Stopping vm win1
2018-11-10 15:55:07,404 [cuckoo.core.scheduler] DEBUG: Released database task #1122
2018-11-10 15:55:07,467 [cuckoo.core.plugins] DEBUG: Executed processing module "AnalysisInfo" for task #1122
2018-11-10 15:55:07,571 [cuckoo.core.plugins] DEBUG: Executed processing module "BehaviorAnalysis" for task #1122
2018-11-10 15:55:07,610 [cuckoo.core.plugins] DEBUG: Executed processing module "Dropped" for task #1122
2018-11-10 15:55:07,611 [cuckoo.core.plugins] DEBUG: Executed processing module "DroppedBuffer" for task #1122
2018-11-10 15:55:08,440 [cuckoo.core.plugins] DEBUG: Executed processing module "MetaInfo" for task #1122
2018-11-10 15:55:08,499 [cuckoo.core.plugins] DEBUG: Executed processing module "ProcessMemory" for task #1122
2018-11-10 15:55:08,500 [cuckoo.core.plugins] DEBUG: Executed processing module "Procmon" for task #1122
2018-11-10 15:55:08,540 [cuckoo.core.plugins] DEBUG: Executed processing module "Screenshots" for task #1122
2018-11-10 15:55:08,540 [cuckoo.core.plugins] DEBUG: Executed processing module "Static" for task #1122
2018-11-10 15:55:08,541 [cuckoo.core.plugins] DEBUG: Executed processing module "Strings" for task #1122
2018-11-10 15:55:08,541 [cuckoo.core.plugins] DEBUG: Executed processing module "TargetInfo" for task #1122
2018-11-10 15:55:24,809 [cuckoo.core.plugins] DEBUG: Executed processing module "NetworkAnalysis" for task #1122
2018-11-10 15:55:25,217 [cuckoo.core.plugins] DEBUG: Executed processing module "VirusTotal" for task #1122
2018-11-10 15:55:25,218 [cuckoo.core.plugins] DEBUG: Executed processing module "Extracted" for task #1122
2018-11-10 15:55:25,219 [cuckoo.core.plugins] DEBUG: Executed processing module "TLSMasterSecrets" for task #1122
2018-11-10 15:55:25,225 [cuckoo.core.plugins] DEBUG: Executed processing module "Debug" for task #1122
2018-11-10 15:55:25,231 [cuckoo.core.plugins] DEBUG: Running 530 signatures
2018-11-10 15:55:28,267 [cuckoo.core.plugins] DEBUG: Analysis matched signature: network_cnc_http
2018-11-10 15:55:28,268 [cuckoo.core.plugins] DEBUG: Analysis matched signature: network_http
2018-11-10 15:55:28,269 [cuckoo.core.plugins] DEBUG: Analysis matched signature: network_http_post
2018-11-10 15:55:28,273 [cuckoo.core.plugins] DEBUG: Analysis matched signature: network_icmp
2018-11-10 15:55:28,273 [cuckoo.core.plugins] DEBUG: Analysis matched signature: allocates_rwx
2018-11-10 15:55:28,291 [cuckoo.core.plugins] DEBUG: Executed reporting module "ElasticSearch"
2018-11-10 15:55:29,262 [cuckoo.core.plugins] DEBUG: Executed reporting module "JsonDump"

@smclinden
Copy link
Author

I may try forking a change to the module which would download the report and then parse it, locally.

There seem to be two issues. In one case, Cuckoo seems to produce an occasional malformed JSON report for reasons that I am not clear about.

But, in other cases, it appears that a connection is timing out during the processing of the report by extract_info() which causes the ijson parser to fail. If I download the report and then process it with extract_info(), it completes without errors.

Unless someone has a better suggestion, this seems like a decent way to go.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants