Analysis hit the critical timeout, terminating

[ctxis]

Analysis hit the critical timeout, terminating

[kevoreilly]

Sorry to hear you are having troubles. The log above tells us that from the server side, the analysis just failed. To know more we need to know what's going on in the Windows host, and for this there is a separate log which is in the analysis page, top right under 'Show Log'. Let me know what that says and hopefully this will shed some light as to what's going on.

The Windows host should be running the agent.py in order to be able to communicate with the server, which will send it analyzer.py to do the analysis - this is what writes in that log and will launch the submitted sample.

[JohnPeng47]

When I clicked show log it, it just showed an empty div:

I also have the Wireshark dump of the exchange which basically shows that the analysis started running (get_status RPC call returns with value of 2). Is there any way I can debug this from the VM side?

[kevoreilly]

Yes for sure - one thing you might try is to run the agent.py in the guest without hiding the window (i.e. keeping .py instead of .pyw) and see how far it gets. A status value of 1 should tell the server the client is ready to receive the analyzer, this is then transferred to the target along with the sample. Let me know how you go.

[doomedraven]

You can see all that in cuckoo.py -d

[doomedraven]

ah i think this is rooter.py race condition i also started observe it, tomorrow will check it

[JohnPeng47]

Ran it with the -d flag and got the following output log. It seems like the analyzer was successfully uploaded to the VM, but just hit a timeout when it tried to run the analysis. I tried increasing the analysis timeout from the default 200 to 1000 but still same timeout error. Gonna try remote debugging the analyzer.py file with Visual Studio Code next

2018-10-11 16:42:22,245 [lib.cuckoo.core.resultserver] DEBUG: ResultServer running on 127.0.0.1:2042.
2018-10-11 16:42:22,248 [lib.cuckoo.core.scheduler] INFO: Using "virtualbox" machine manager with max_analysis_count=0, max_machines_count=2, and max_vmstartup_count=2
2018-10-11 16:42:24,447 [modules.machinery.virtualbox] DEBUG: Getting status for IE11 - Win7
2018-10-11 16:42:24,638 [modules.machinery.virtualbox] DEBUG: Machine IE11 - Win7 status poweroff
2018-10-11 16:42:24,674 [lib.cuckoo.core.scheduler] INFO: Loaded 1 machine/s
2018-10-11 16:42:24,690 [lib.cuckoo.core.scheduler] INFO: Waiting for analysis tasks.
2018-10-11 16:52:09,864 [lib.cuckoo.core.scheduler] DEBUG: Task #10: Processing task
2018-10-11 16:52:09,867 [lib.cuckoo.core.scheduler] INFO: Task #10: Starting analysis of FILE '/tmp/cuckoo-tmp/upload_wzwfZY/binstall.exe'
2018-10-11 16:52:09,883 [lib.cuckoo.core.scheduler] INFO: Task #10: File already exists at '/mnt/c/Users/john/Documents/cape_dev/CAPE/storage/binaries/1284211e57621f84118ce28a4df024163f663c6891c9f154883df804b592ee08'
2018-10-11 16:52:09,945 [lib.cuckoo.core.scheduler] INFO: Task #10: acquired machine cuckoo1 (label=IE11 - Win7)
2018-10-11 16:52:10,018 [modules.machinery.virtualbox] DEBUG: Starting vm IE11 - Win7
2018-10-11 16:52:10,018 [modules.machinery.virtualbox] DEBUG: Getting status for IE11 - Win7
2018-10-11 16:52:10,621 [modules.machinery.virtualbox] DEBUG: Machine IE11 - Win7 status poweroff
2018-10-11 16:52:10,643 [modules.machinery.virtualbox] DEBUG: Using snapshot cape_snap for virtual machine IE11 - Win7
2018-10-11 16:52:11,153 [modules.machinery.virtualbox] DEBUG: Getting status for IE11 - Win7
2018-10-11 16:52:11,224 [modules.machinery.virtualbox] DEBUG: Machine IE11 - Win7 status saved
2018-10-11 16:52:21,310 [modules.machinery.virtualbox] DEBUG: Getting status for IE11 - Win7
2018-10-11 16:52:21,385 [modules.machinery.virtualbox] DEBUG: Machine IE11 - Win7 status running
2018-10-11 16:52:21,435 [lib.cuckoo.core.scheduler] WARNING: Unknown network routing destination specified, ignoring routing for this analysis: None
2018-10-11 16:52:21,446 [lib.cuckoo.core.scheduler] INFO: Enabled route 'None'
2018-10-11 16:52:21,510 [modules.auxiliary.sniffer] ERROR: Tcpdump is not accessible from this user, network capture aborted
2018-10-11 16:52:21,511 [lib.cuckoo.core.plugins] DEBUG: Started auxiliary module: Sniffer
2018-10-11 16:52:21,580 [lib.cuckoo.core.guest] INFO: Starting analysis on guest (id=cuckoo1, ip=192.168.56.102)
2018-10-11 16:52:21,582 [lib.cuckoo.core.guest] DEBUG: cuckoo1: waiting for status 0x0001
2018-10-11 16:52:30,679 [lib.cuckoo.core.guest] DEBUG: cuckoo1: status ready
2018-10-11 16:52:37,255 [lib.cuckoo.core.guest] DEBUG: Uploading analyzer to guest (id=cuckoo1, ip=192.168.56.102)
2018-10-11 16:52:46,004 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analyzer started with PID 2980
2018-10-11 16:52:46,005 [lib.cuckoo.core.guest] DEBUG: cuckoo1: waiting for completion
2018-10-11 16:52:47,010 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:48,014 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:49,018 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:50,021 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:51,027 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:52,030 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:53,033 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:54,037 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:55,041 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:56,046 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:57,050 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:58,054 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:52:59,058 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:00,061 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:01,065 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:02,067 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:03,073 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:04,079 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:05,083 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:06,089 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:07,094 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:08,097 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:09,100 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:10,103 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:11,106 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:12,109 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:13,113 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:14,116 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:15,120 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:16,124 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:17,128 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:18,134 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:19,139 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:20,144 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:21,149 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:22,152 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:23,155 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:24,159 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:25,163 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 16:53:26,279 [lib.cuckoo.core.guest] DEBUG: cuckoo1: analysis not completed yet (status=2)
2018-10-11 17:01:53,850 [lib.cuckoo.core.scheduler] ERROR: The analysis hit the critical timeout, terminating.

[doomedraven]

thats weird it only happens sometime which is fine, is that happens to you for all samples?

[JohnPeng47]

yeah that does seem to be the case for now although i've only tried it with 2 or 3 binaries. Do you know of any that has been run through CAPE before and is 100% working without getting a timeout?

[doomedraven]

im running cape, well timeout sometime popup, but that is something normal, its malware, so if malware not exits, it keeps running so process is alive, so when max time of execution reached, timeout is called, that isn't a error, that is more just information

[JohnPeng47]

Tried on the public CAPE instance and got some results. I even tried switching to windows XP VM still getting the same results. Could this be something to do with the capemon DLL's?

[kevoreilly]

Can you share a job number on the public instance so I can see what you mean?

[JohnPeng47]

19917 working_sample

[JohnPeng47]

uh just ran a git pull and the timeout went away

[JohnPeng47]

Sorry I probably should have done that a long time ago

[doomedraven]

Cool so solved?

[JohnPeng47]

Yep

[doomedraven]

then press close ;)

[JohnPeng47]

oops