cuckoosandbox / cuckoo

Cuckoo Sandbox is an automated dynamic malware analysis system
http://www.cuckoosandbox.org
Other
5.56k stars 1.7k forks source link

Guest initialization hit the critical timeout #1343

Closed littlejob closed 7 years ago

littlejob commented 7 years ago

Was reading through the open/closed issues. Have had mixed luck with this one:

I submit a file sample for review, VM is loaded, but it appears something is timing out.

2017-03-17 05:00:17,288 [lib.cuckoo.core.resultserver] DEBUG: ResultServer running on 192.168.139.135:2042.
2017-03-17 05:00:17,290 [lib.cuckoo.core.scheduler] INFO: Using "virtualbox" as machine manager
2017-03-17 05:00:17,628 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:00:17,779 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 05:00:17,789 [modules.machinery.virtualbox] DEBUG: Stopping vm Win7
2017-03-17 05:00:17,789 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:00:17,893 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 05:00:18,928 [modules.machinery.virtualbox] DEBUG: VBoxManage exited with error powering off the machine
2017-03-17 05:00:18,931 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:00:19,090 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 05:00:19,113 [lib.cuckoo.core.scheduler] INFO: Loaded 1 machine/s
2017-03-17 05:00:19,132 [lib.cuckoo.core.scheduler] INFO: Waiting for analysis tasks.
2017-03-17 05:01:47,217 [lib.cuckoo.core.scheduler] DEBUG: Processing task #2
2017-03-17 05:01:47,226 [lib.cuckoo.core.scheduler] INFO: Starting analysis of FILE "Invoice_NJINV23946_from_LOOKERS.rtf" (task #2, options "route=none,procmemdump=yes")
2017-03-17 05:01:47,263 [lib.cuckoo.core.scheduler] INFO: Task #2: acquired machine Win7 (label=Win7)
2017-03-17 05:01:47,276 [modules.auxiliary.sniffer] INFO: Started sniffer with PID 2494 (interface=vboxnet0, host=192.168.56.101, pcap=/apps/cuckoo/storage/analyses/2/dump.pcap)
2017-03-17 05:01:47,277 [lib.cuckoo.core.plugins] DEBUG: Started auxiliary module: Sniffer
2017-03-17 05:01:47,322 [modules.machinery.virtualbox] DEBUG: Starting vm Win7
2017-03-17 05:01:47,322 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:01:47,620 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 05:01:47,646 [modules.machinery.virtualbox] DEBUG: Using current snapshot for virtual machine Win7
2017-03-17 05:01:47,794 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:01:47,928 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 05:01:53,341 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:01:53,540 [modules.machinery.virtualbox] DEBUG: Machine Win7 status running
2017-03-17 05:01:53,575 [lib.cuckoo.core.guest] INFO: Starting analysis on guest (id=Win7, ip=192.168.56.101)
2017-03-17 05:01:54,584 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 05:01:55,588 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet

Several VM not ready errors latter... I then get the below:

2017-03-17 05:04:53,023 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 05:04:54,025 [lib.cuckoo.core.scheduler] ERROR: Error from the Cuckoo Guest: Win7: the guest initialization hit the critical timeout, analysis aborted.
2017-03-17 05:04:54,051 [lib.cuckoo.core.plugins] WARNING: Unable to stop auxiliary module: Error running tcpdump to sniff the network traffic during the analysis; stdout = '' and stderr = "tcpdump: vboxnet0: You don't have permission to capture on that device\n(socket: Operation not permitted)\n". Did you enable the extra capabilities to allow running tcpdump as non-root user and disable AppArmor properly (the latter only applies to Ubuntu-based distributions with AppArmor)?
2017-03-17 05:04:54,052 [modules.machinery.virtualbox] DEBUG: Stopping vm Win7
2017-03-17 05:04:54,052 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:04:54,210 [modules.machinery.virtualbox] DEBUG: Machine Win7 status running
2017-03-17 05:04:55,230 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 05:04:55,425 [modules.machinery.virtualbox] DEBUG: Machine Win7 status poweroff
2017-03-17 05:04:55,459 [lib.cuckoo.core.scheduler] DEBUG: Released database task #2
2017-03-17 05:04:55,487 [lib.cuckoo.core.plugins] DEBUG: Executed processing module "AnalysisInfo" on analysis at "/apps/cuckoo/storage/analyses/2"

During these "not ready errors" vboxmanage does report that the VM is running. From the VM i can ping my host. From the host I can ping my VM. Host is Win7, UAC and local firewall is disabled.

doomedraven commented 7 years ago

test this https://cuckoo.sh/docs/faq/index.html#unsupported-method-get with all vms

littlejob commented 7 years ago

So I tried the new REST API agent, I still experience the same issue.

2017-03-17 07:55:38,515 [lib.cuckoo.core.resultserver] DEBUG: ResultServer running on 192.168.139.135:2042.
2017-03-17 07:55:38,517 [lib.cuckoo.core.scheduler] INFO: Using "virtualbox" as machine manager
2017-03-17 07:55:38,648 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:55:38,803 [modules.machinery.virtualbox] DEBUG: Machine Win7 status poweroff
2017-03-17 07:55:38,838 [lib.cuckoo.core.scheduler] INFO: Loaded 1 machine/s
2017-03-17 07:55:38,864 [lib.cuckoo.core.scheduler] INFO: Waiting for analysis tasks.
2017-03-17 07:56:45,844 [lib.cuckoo.core.scheduler] DEBUG: Processing task #3
2017-03-17 07:56:45,860 [lib.cuckoo.core.scheduler] INFO: Starting analysis of FILE "price_list.doc_104700.doc" (task #3, options "route=none,procmemdump=yes")
2017-03-17 07:56:45,907 [lib.cuckoo.core.scheduler] INFO: Task #3: acquired machine Win7 (label=Win7)
2017-03-17 07:56:45,918 [modules.auxiliary.sniffer] INFO: Started sniffer with PID 2596 (interface=vboxnet0, host=192.168.56.101, pcap=/apps/cuckoo/storage/analyses/3/dump.pcap)
2017-03-17 07:56:45,919 [lib.cuckoo.core.plugins] DEBUG: Started auxiliary module: Sniffer
2017-03-17 07:56:45,987 [modules.machinery.virtualbox] DEBUG: Starting vm Win7
2017-03-17 07:56:45,988 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:56:46,171 [modules.machinery.virtualbox] DEBUG: Machine Win7 status poweroff
2017-03-17 07:56:46,204 [modules.machinery.virtualbox] DEBUG: Using current snapshot for virtual machine Win7
2017-03-17 07:56:46,297 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:56:46,458 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 07:56:50,248 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:56:50,442 [modules.machinery.virtualbox] DEBUG: Machine Win7 status running
2017-03-17 07:56:50,483 [lib.cuckoo.core.guest] INFO: Starting analysis on guest (id=Win7, ip=192.168.56.101)
2017-03-17 07:56:51,489 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 07:56:52,493 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 07:56:53,487 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet

Same not ready yet errors

2017-03-17 07:59:50,965 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 07:59:50,969 [lib.cuckoo.core.scheduler] ERROR: Error from the Cuckoo Guest: Win7: the guest initialization hit the critical timeout, analysis aborted.
2017-03-17 07:59:51,025 [lib.cuckoo.core.plugins] WARNING: Unable to stop auxiliary module: Error running tcpdump to sniff the network traffic during the analysis; stdout = '' and stderr = "tcpdump: vboxnet0: You don't have permission to capture on that device\n(socket: Operation not permitted)\n". Did you enable the extra capabilities to allow running tcpdump as non-root user and disable AppArmor properly (the latter only applies to Ubuntu-based distributions with AppArmor)?
2017-03-17 07:59:51,027 [modules.machinery.virtualbox] DEBUG: Stopping vm Win7
2017-03-17 07:59:51,027 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:59:51,218 [modules.machinery.virtualbox] DEBUG: Machine Win7 status running
2017-03-17 07:59:52,238 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 07:59:52,451 [modules.machinery.virtualbox] DEBUG: Machine Win7 status poweroff
doomedraven commented 7 years ago

but no output from that checks...

littlejob commented 7 years ago

I am confused on your statement. If I open the agent on the guest VM, all I see is a black screen no text. With the legacy agent included in the dev release, i get the starting agent on message, but that is all. no confirmation text or what not.

doomedraven commented 7 years ago

you just shoud do curl vm_ip:8000 to each vm and they should responde 501 if there no problem in communication with agent

littlejob commented 7 years ago

My apologies:

With the new REST API, it appears to work.

master@ubuntu:~$ curl 192.168.56.10:8000
{"message": "Cuckoo Agent!", "version": "0.7", "features": ["execpy", "pinning", "logs", "largefile", "unicodepath"]}

The legacy agent included in the release gives me an error.

littlejob commented 7 years ago

I noticed my VM snapshot still had the legacy client running. Switched with the new agent, deleted current snapshot, recaptured saved with the same name to avoid updating the config file, attempted to resubmit an analysis again, same issue persists.

2017-03-17 10:17:57,935 [modules.machinery.virtualbox] DEBUG: Starting vm Win7
2017-03-17 10:17:57,936 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 10:17:58,229 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 10:17:58,247 [modules.machinery.virtualbox] DEBUG: Using current snapshot for virtual machine Win7
2017-03-17 10:17:58,370 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 10:17:58,493 [modules.machinery.virtualbox] DEBUG: Machine Win7 status saved
2017-03-17 10:18:02,157 [modules.machinery.virtualbox] DEBUG: Getting status for Win7
2017-03-17 10:18:02,295 [modules.machinery.virtualbox] DEBUG: Machine Win7 status running
2017-03-17 10:18:02,327 [lib.cuckoo.core.guest] INFO: Starting analysis on guest (id=Win7, ip=192.168.56.101)
2017-03-17 10:18:03,334 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 10:18:04,339 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
2017-03-17 10:18:05,332 [lib.cuckoo.core.guest] DEBUG: Win7: not ready yet
doomedraven commented 7 years ago

That error with legacy agent is ok, mesn it works, no idea what can be wrong

SparkyNZL commented 7 years ago

I've had this same issue, it appears to be virtualbox, I don't know what or where, I cloned the VM deleted the old one and the clone worked, it was most strange as I could ping in both directions and telnet to the agent, but for some reason wouldn't work until I cloned it .

Hope this helps

Sent from my spaceship...

On 18/03/2017 6:27 AM, "doomedraven" notifications@github.com wrote:

That error with legacy agent is ok, mesn it works, no idea what can be wrong

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/cuckoosandbox/cuckoo/issues/1343#issuecomment-287419356, or mute the thread https://github.com/notifications/unsubscribe-auth/AQ_imFUj_n39PRJQyyEYm14_wvidyBiLks5rmsKTgaJpZM4Mgoih .

littlejob commented 7 years ago

Per your suggestion, I have tried the above, still to no prevail That is when I noticed something in my virtualbox config, I was missing an octet for the statically assigned vm......... (frusterating)

After correcting this, and re-submitting a sample, I was able to process the submission, to then continue to get additional errors.

Question, at what point does the processing stop? Is it just a time limit? If so, that explains the below.

2017-03-17 11:36:05,769 [lib.cuckoo.core.guest] DEBUG: Win7Clone: analysis still processing
2017-03-17 11:36:05,832 [lib.cuckoo.core.resultserver] DEBUG: File upload request for shots/0042.jpg
2017-03-17 11:36:05,853 [lib.cuckoo.core.resultserver] DEBUG: Uploaded file length: 58497
2017-03-17 11:36:06,789 [lib.cuckoo.core.guest] DEBUG: Win7Clone: analysis still processing
2017-03-17 11:36:07,790 [lib.cuckoo.core.scheduler] ERROR: Error from the Cuckoo Guest: The analysis hit the critical timeout, terminating.
doomedraven commented 7 years ago

Yes it has timeout of run to kill vm

littlejob commented 7 years ago

Where is this time-out defined? I shall mark this closed after one more test! (I guess i could alter in the advanced settings in the web GUI.. )

Thanks everyone for your help!

SparkyNZL commented 7 years ago

The time out is located in your cuckoo.conf file, I think the timeout is defaulted to 120 seconds

On Sat, Mar 18, 2017 at 8:22 AM, littlejob notifications@github.com wrote:

Where is this time-out defined? I shall mark this closed after one more test!

Thank everyone for their help!

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/cuckoosandbox/cuckoo/issues/1343#issuecomment-287448450, or mute the thread https://github.com/notifications/unsubscribe-auth/AQ_imBIke5MHpgpnTfIZ-xwExHW8AMc_ks5rmt2PgaJpZM4Mgoih .

littlejob commented 7 years ago

awesome, was able to tweak and get working accordingly.

jbremer commented 7 years ago

@littlejob for our information, what did you tweak to get it working?