Skip to content

All analyses stuck in "pending" and never run #268

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

Closed
4 tasks done
pieterbork opened this issue Sep 11, 2020 · 11 comments
Closed
4 tasks done

All analyses stuck in "pending" and never run #268

pieterbork opened this issue Sep 11, 2020 · 11 comments

Comments

@pieterbork
Copy link

This is opensource and you getting free support so be friendly!

Prerequisites

Please answer the following questions for yourself before submitting an issue.

  • I am running the latest version
  • I checked the documentation and found no answer
  • I checked to make sure that this issue has not already been filed
  • I'm reporting the issue to the correct repository (for multi-repository projects)

Expected Behavior

Files are submitted to VMs and results are processed

Current Behavior

All files submitted create tasks that are "pending" forever

Failure Information (for bugs)

I've recently upgraded from CapeV1 to CapeV2 and haven't been able to get analyses to process properly. All files I submit end up in "pending" status forever. I am able to manually query select * from tasks; in postgresql and see the tasks are present, but they never move into "running" status.

All services: cape-rooter, cape-processor, cape, cape-web, postgresql, mongod are running and produce no errors. I'm currently running cape + cape-processor with the --debug flags, but see no processing happening in logs when I submit a file other than the web API "POST /submit/ HTTP/1.1" 200 3309

Some results from the API:

/api/machines/list

{
    "data": [
        {
            "id": 7,
            "name": "cape001",
            "label": "cape001",
            "ip": "192.168.123.10",
            "platform": "windows",
            "interface": "virbr123",
            "snapshot": "cape001-snap01",
            "locked": false,
            "locked_changed_on": null,
            "status": "poweroff",
            "status_changed_on": "2020-09-11 17:57:09",
            "resultserver_ip": "192.168.123.1",
            "resultserver_port": "2042",
            "tags": []
        }
    ],
    "error": false
}

/api/cuckoo/status

{
    "error": false,
    "data": {
        "version": "2.1-CAPE",
        "hostname": "capev2",
        "machines": {
            "total": 1,
            "available": 1
        },
        "tasks": {
            "total": 4,
            "pending": 4,
            "running": 0,
            "completed": 0,
            "reported": 0
        }
    }
}

I'm starting to go through some code, but if you have any ideas for how I can troubleshoot this I would be very appreciative.

Cheers,
Pieter

@doomedraven
Copy link
Collaborator

doomedraven commented Sep 11, 2020 via email

@pieterbork
Copy link
Author

Here is the output from python3 cuckoo.py -d. Nothing else gets logged even after submitting new files.

�[31m
  .-----------------.
  | Cuckoo Sandbox? |
  |     OH NOES!    |\  '-.__.-'
  '-----------------' \  /oo |--.--,--,--.
                         \_.-'._i__i__i_.'
                               """""""""�[0m

 Cuckoo Sandbox �[33m2.1-CAPE�[0m
 www.cuckoosandbox.org
 Copyright (c) 2010-2015

 CAPE: Config and Payload Extraction
 github.com/kevoreilly/CAPEv2

2020-09-11 19:03:11,254 [root] DEBUG: Importing modules...
2020-09-11 19:03:11,277 [volatility.framework.interfaces.layers] DEBUG: Imported python-magic, autodetecting compressed files based on content
2020-09-11 19:03:11,824 [root] DEBUG: Imported "auxiliary" modules:
2020-09-11 19:03:11,824 [root] DEBUG: 	 `-- Sniffer
2020-09-11 19:03:11,825 [root] DEBUG: Imported "processing" modules:
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- CAPE
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- AnalysisInfo
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- BehaviorAnalysis
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Curtain
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Debug
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Decompression
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Deduplicate
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Dropped
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- MMBot
2020-09-11 19:03:11,825 [root] DEBUG: 	 |-- Memory
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- NetworkAnalysis
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- ProcDump
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- ProcessMemory
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Procmon
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Static
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Strings
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Suricata
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Sysmon
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- TargetInfo
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- TrID
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- Usage
2020-09-11 19:03:11,826 [root] DEBUG: 	 `-- VirusTotal
2020-09-11 19:03:11,826 [root] DEBUG: Imported "signatures" modules:
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPEDetectedThreat
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_Compression
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_Decryption
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_Doppelganging
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_EvilGrab
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_Injection
2020-09-11 19:03:11,826 [root] DEBUG: 	 |-- CAPE_InjectionCreateRemoteThread
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_InjectionProcessHollowing
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_InjectionSetWindowLong
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_PlugX
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_RegBinary
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_TransactedHollowing
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPE_Unpacker
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CAPEExtractedContent
2020-09-11 19:03:11,827 [root] DEBUG: 	 `-- NetworkHTTPS
2020-09-11 19:03:11,827 [root] DEBUG: Imported "reporting" modules:
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- BinGraph
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CALLBACKHOME
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- Compression
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- CompressResults
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- JsonDump
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- MAEC41Report
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- MaecReport
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- MISP
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- MITRE_TTPS
2020-09-11 19:03:11,827 [root] DEBUG: 	 |-- MongoDB
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- RAMFSCLEAN
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- ReportHTML
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- ReportHTMLSummary
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- ReportPDF
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- ReSubmitExtractedEXE
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- Retention
2020-09-11 19:03:11,828 [root] DEBUG: 	 |-- SubmitCAPE
2020-09-11 19:03:11,828 [root] DEBUG: 	 `-- Syslog
2020-09-11 19:03:11,828 [root] DEBUG: Imported "machinery" modules:
2020-09-11 19:03:11,828 [root] DEBUG: 	 `-- KVM
2020-09-11 19:03:11,828 [root] DEBUG: Checking for locked tasks...
2020-09-11 19:03:11,937 [root] DEBUG: Initializing Yara...
2020-09-11 19:03:11,941 [root] DEBUG: 	 |-- binaries HeavensGate.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE AgentTesla.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Arkei.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE AsyncRat.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Atlas.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Azer.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Azorult.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE BadRabbit.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE BitPaymer.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Cerber.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Clop.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE CobaltStrikeBeacon.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Codoso.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE Cryptoshield.yar
2020-09-11 19:03:11,949 [root] DEBUG: 	 |-- CAPE DoppelPaymer.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Dreambot.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE DridexLoader.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE DridexV4.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Emotet.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Emotet_Loader.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE EternalRomance.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Fareit.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Gandcrab.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Gootkit.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Hancitor.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Hermes.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE IcedID.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Imminent.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Jaff.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Kovter.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Kronos.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Lockbit.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Locky.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Loki.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Magniber.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE MegaCortex.yar
2020-09-11 19:03:11,950 [root] DEBUG: 	 |-- CAPE Mole.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE NanoLocker.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Nemty.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE NetTraveler.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE OlympicDestroyer.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE PetrWrap.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Petya.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Phorpiex.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE QakBot.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE RCSession.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Ramnit.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Remcos.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE RokRat.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Ryuk.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Scarab.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Sedreco.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Seduploader.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE TClient.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE TSCookie.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE TrickBot.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Ursnif.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Ursnif3.yar
2020-09-11 19:03:11,951 [root] DEBUG: 	 |-- CAPE Varenyky.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE Vidar.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE WanaCry.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE ZeroT.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE ZeusPanda.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE Zloader.yar
2020-09-11 19:03:11,952 [root] DEBUG: 	 |-- CAPE tRat.yar
2020-09-11 19:03:11,952 [root] WARNING: �[33mMissing Yara directory: /opt/CAPEv2/data/yara/macro?�[0m
2020-09-11 19:03:11,954 [lib.cuckoo.core.scheduler] INFO: Using "kvm" machine manager with max_analysis_count=0, max_machines_count=10, and max_vmstartup_count=5
2020-09-11 19:03:11,966 [lib.cuckoo.common.abstracts] DEBUG: Getting status for cape001
2020-09-11 19:03:11,975 [lib.cuckoo.core.scheduler] INFO: Loaded 1 machine/s
2020-09-11 19:03:11,980 [lib.cuckoo.core.scheduler] INFO: Waiting for analysis tasks.
pywin32 is not installed (only is required if you want to use MS Excel)

@doomedraven
Copy link
Collaborator

how do you adding tasks? i suppouse you run something as root and something as another user, that is most common issue for pending tasks

@pieterbork
Copy link
Author

pieterbork commented Sep 14, 2020

I'm submitting using the web UI, only the rooter is running as root. All submissions with the Web UI are stuck "pending".

root       64778       1  0 21:42 ?        00:00:00 /usr/bin/python3 rooter.py -g cuckoo
cuckoo     69483       1  0 21:45 ?        00:00:05 /usr/bin/python3 process.py -p7 auto -pt 900 --debug
cuckoo     69510       1  1 21:45 ?        00:00:29 /usr/bin/python3 cuckoo.py --debug
cuckoo     69511       1  0 21:45 ?        00:00:02 /usr/bin/python3 manage.py runserver 0.0.0.0:8000
postgres   69534   63011  0 21:45 ?        00:00:00 postgres: cuckoo analysis 127.0.0.1(47548) idle
postgres   69573   63011  0 21:45 ?        00:00:04 postgres: cuckoo analysis 127.0.0.1(47558) idle
postgres   69574   63011  0 21:45 ?        00:00:00 postgres: cuckoo analysis 127.0.0.1(47560) idle
cuckoo     69581   69511  1 21:45 ?        00:00:42 /usr/bin/python3 manage.py runserver 0.0.0.0:8000
postgres   69627   63011  0 21:45 ?        00:00:00 postgres: cuckoo analysis 127.0.0.1(47580) idle

Trying to submit with submit.py seems to actually work to submit the analysis

[root@cape01 opt]# sudo -u cuckoo python3 CAPEv2/utils/submit.py 46224284f2cc1537456bc385e85b1a0ef9a93b49
Success: File "/opt/46224284f2cc1537456bc385e85b1a0ef9a93b49" added as task with ID 2

2020-09-14 22:33:38,705 [lib.cuckoo.core.scheduler] DEBUG: Task #2: Processing task
2020-09-14 22:33:38,707 [lib.cuckoo.core.scheduler] INFO: Task #2: Starting analysis of FILE '/opt/46224284f2cc1537456bc385e85b1a0ef9a93b49'
2020-09-14 22:33:38,720 [lib.cuckoo.core.scheduler] INFO: Task #2: acquired machine cape001 (label=cape001, platform=windows)
2020-09-14 22:33:38,746 [root] DEBUG: Now tracking machine 192.168.123.10 for task #2
2020-09-14 22:33:38,756 [lib.cuckoo.common.abstracts] DEBUG: Starting machine cape001
2020-09-14 22:33:38,756 [lib.cuckoo.common.abstracts] DEBUG: Getting status for cape001
2020-09-14 22:33:38,789 [lib.cuckoo.common.abstracts] DEBUG: Using snapshot cape001-snap01 for virtual machine cape001
2020-09-14 22:33:40,519 [lib.cuckoo.common.abstracts] DEBUG: Getting status for cape001
2020-09-14 22:33:40,553 [lib.cuckoo.core.scheduler] INFO: Enabled route 'none'
2020-09-14 22:33:40,561 [modules.auxiliary.sniffer] INFO: Started sniffer with PID 71495 (interface=virbr123, host=192.168.123.10, dump path=/opt/CAPEv2/storage/analyses/2/dump.pcap)
2020-09-14 22:33:40,562 [lib.cuckoo.core.plugins] DEBUG: Started auxiliary module: Sniffer
2020-09-14 22:33:40,576 [lib.cuckoo.core.guest] INFO: Starting analysis #2 on guest (id=cape001, ip=192.168.123.10)
2020-09-14 22:33:41,579 [lib.cuckoo.core.guest] DEBUG: cape001: not ready yet
2020-09-14 22:33:42,582 [lib.cuckoo.core.guest] DEBUG: cape001: not ready yet
2020-09-14 22:33:43,585 [lib.cuckoo.core.guest] DEBUG: cape001: not ready yet
2020-09-14 22:33:43,594 [lib.cuckoo.core.guest] INFO: Guest is running CAPE Agent 0.11 (id=cape001, ip=192.168.123.10)
2020-09-14 22:33:43,629 [lib.cuckoo.core.guest] DEBUG: Uploading analyzer to guest (id=cape001, ip=192.168.123.10, size=17059709)
2020-09-14 22:33:43,988 [lib.cuckoo.core.guest] INFO: Uploading support files to guest (id=cape001, ip=192.168.123.10)
2020-09-14 22:33:54,933 [lib.cuckoo.core.guest] DEBUG: cape001: analysis #2 is still running
2020-09-14 22:33:59,957 [lib.cuckoo.core.guest] DEBUG: cape001: analysis #2 is still running
...
2020-09-14 22:38:10,458 [lib.cuckoo.core.guest] INFO: cape001: end of analysis reached!
2020-09-14 22:38:10,466 [lib.cuckoo.core.plugins] DEBUG: Stopped auxiliary module: Sniffer
2020-09-14 22:38:10,466 [lib.cuckoo.common.abstracts] DEBUG: Stopping machine cape001
2020-09-14 22:38:10,466 [lib.cuckoo.common.abstracts] DEBUG: Getting status for cape001
2020-09-14 22:38:10,701 [lib.cuckoo.common.abstracts] DEBUG: Getting status for cape001
2020-09-14 22:38:10,722 [root] DEBUG: Stopped tracking machine 192.168.123.10 for task #2
2020-09-14 22:38:10,792 [lib.cuckoo.core.scheduler] DEBUG: Task #2: Released database task with status True
2020-09-14 22:38:10,792 [lib.cuckoo.core.scheduler] INFO: Task #2: analysis procedure completed

But then the web UI is broken trying to go to the "Recent" tab, throwing this error:

OperationFailure at /analysis/

Path collision at info.custom remaining portion custom, full error: {'ok': 0.0, 'errmsg': 'Path collision at info.custom remaining portion custom', 'code': 31249, 'codeName': 'Location31249'}

Thanks for all your help and hard work on this project!

@doomedraven
Copy link
Collaborator

doomedraven commented Sep 15, 2020 via email

@pieterbork
Copy link
Author

pieterbork commented Sep 16, 2020

I've updated my installation to use the cape user instead of the cuckoo user and reviewed your install scripts to try to find anything else I may be missing, but still having the same issues.

Here are the groups/process/files that are cape-related:

[root@cape01 ~]# cat /etc/group | grep cape
libvirt:x:980:cape
virusgroup:x:977:clamupdate,clamscan,cape
cape:x:2000:
pcap:x:2001:cape

[root@cape01 ~]# ps -ef | grep cape
cape        8339       1  1 21:02 ?        00:00:07 /usr/bin/python3 cuckoo.py
root        8362       1  0 21:02 ?        00:00:00 /usr/bin/python3 rooter.py -g cape
cape        8402       1  0 21:02 ?        00:00:02 /usr/bin/python3 manage.py runserver 0.0.0.0:8000
postgres    8436    8207  0 21:02 ?        00:00:00 postgres: cape cape 127.0.0.1(50286) idle
postgres    8471    8207  0 21:02 ?        00:00:00 postgres: cape cape 127.0.0.1(50304) idle
cape        8472       1  0 21:02 ?        00:00:03 /usr/bin/python3 process.py -p7 auto -pt 900
cape        8475    8402  2 21:02 ?        00:00:10 /usr/bin/python3 manage.py runserver 0.0.0.0:8000
postgres    8547    8207  0 21:02 ?        00:00:00 postgres: cape cape 127.0.0.1(50316) idle
postgres    8553    8207  0 21:02 ?        00:00:00 postgres: cape cape 127.0.0.1(50322) idle
postgres    8734    8207  0 21:05 ?        00:00:00 postgres: cape cape 127.0.0.1(50354) idle
root        9043    2116  0 21:09 pts/0    00:00:00 grep --color=auto cape

[root@cape01 ~]# ls -al /tmp | grep cape
srw--w----   1 root     cape           0 Sep 15 21:02 cuckoo-rooter
drwxr-xr-x. 16 cape     cape        4096 Sep 15 21:03 cuckoo-tmp
srwxr-xr-x   1 cape     cape           0 Sep 15 18:11 tmpdmlaixxv
srwxr-xr-x   1 cape     cape           0 Sep 15 21:08 tmpei73i44r
srwxr-xr-x   1 cape     cape           0 Sep 15 17:34 tmpwekayfoj
srwxr-xr-x   1 cape     cape           0 Sep 14 22:38 tmpwpq60bmd

(I've run a chown -R cape:cape /opt/CAPEv2)
[root@cape01 ~]# ls -al /opt/
drwxr-xr-x  18 cape cape   4096 Sep 15 18:30 CAPEv2

Submissions with Web UI are still stuck in pending. If I submit with sudo -u cape utils/submit.py <binary OR url> it will be processed, but this traceback is then being thrown trying to visit /analysis on the Web UI:

Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/django/core/handlers/exception.py", line 47, in inner
Sep 15 21:05:25 cape01 python3[8402]:    response = get_response(request)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/django/core/handlers/base.py", line 179, in _get_response
Sep 15 21:05:25 cape01 python3[8402]:    response = wrapped_callback(request, *callback_args, **callback_kwargs)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/django/views/decorators/http.py", line 40, in inner
Sep 15 21:05:25 cape01 python3[8402]:    return func(request, *args, **kwargs)
Sep 15 21:05:25 cape01 python3[8402]:  File "/opt/CAPEv2/web/analysis/views.py", line 289, in index
Sep 15 21:05:25 cape01 python3[8402]:    new = get_analysis_info(db, task=task)
Sep 15 21:05:25 cape01 python3[8402]:  File "/opt/CAPEv2/web/analysis/views.py", line 139, in get_analysis_info
Sep 15 21:05:25 cape01 python3[8402]:    sort=[("_id", pymongo.DESCENDING)],
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/collection.py", line 1319, in find_one
Sep 15 21:05:25 cape01 python3[8402]:    for result in cursor.limit(-1):
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/cursor.py", line 1207, in next
Sep 15 21:05:25 cape01 python3[8402]:    if len(self.__data) or self._refresh():
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/cursor.py", line 1124, in _refresh
Sep 15 21:05:25 cape01 python3[8402]:    self.__send_message(q)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/cursor.py", line 1001, in __send_message
Sep 15 21:05:25 cape01 python3[8402]:    address=self.__address)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/mongo_client.py", line 1372, in _run_operation_with_response
Sep 15 21:05:25 cape01 python3[8402]:    exhaust=exhaust)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/mongo_client.py", line 1471, in _retryable_read
Sep 15 21:05:25 cape01 python3[8402]:    return func(session, server, sock_info, slave_ok)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/mongo_client.py", line 1366, in _cmd
Sep 15 21:05:25 cape01 python3[8402]:    unpack_res)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/server.py", line 137, in run_operation_with_response
Sep 15 21:05:25 cape01 python3[8402]:    first, sock_info.max_wire_version)
Sep 15 21:05:25 cape01 python3[8402]:  File "/usr/local/lib64/python3.6/site-packages/pymongo/helpers.py", line 168, in_check_command_response
Sep 15 21:05:25 cape01 python3[8402]:    max_wire_version)
Sep 15 21:05:25 cape01 python3[8402]: pymongo.errors.OperationFailure: Path collision at info.custom remaining portion custom, full error: {'ok': 0.0, 'errmsg': 'Path collision at info.custom remaining portion custom', 'code': 31249, 'codeName': 'Location31249'}

Here are the tasks from the mongo/postgres:

mongodump [<Task('2','http://www.example.com')>, <Task('1','/tmp/cuckoo-tmp/upload__4ot448z/946f2c19bdf5edd48bedf507d44466da')>]
postgresdump [<Task('1','/tmp/cuckoo-tmp/upload__4ot448z/946f2c19bdf5edd48bedf507d44466da')>, <Task('2','http://www.example.com')>]

I agree that this seems like a permissions issue, but I'm having issues figuring it out. Any suggestions of other things I can check?

@doomedraven
Copy link
Collaborator

is first time that i see that mongo error, but that is probably part of your problem, ensure that mongo works correctly, for othe rest everything looks correct

@pieterbork
Copy link
Author

I commented out Lines 118-138 in web/analysis/view.py which fixed the pymongo error being thrown.

I've found that if I use "Detect Automatically" selected in the web UI, my tasks will be "pending" forever. However, selecting my VM from the dropdown seems to work and my sample processes successfully.

I'm going to do some more testing with tags and different VM names and will report back any additional findings.

@doomedraven
Copy link
Collaborator

doomedraven commented Sep 17, 2020 via email

@pieterbork
Copy link
Author

pieterbork commented Sep 17, 2020

Yep, that was why Detect Automatically was not working. Last issue I'm having is that Cape doesn't seem to be able to start virtual machines by itself when tasks are acquired - I have to start the machine manually for processing to continue.

2020-09-17 17:54:19,272 [lib.cuckoo.core.scheduler] INFO: Task #13: Starting analysis of FILE '/tmp/cuckoo-tmp/upload_c4q_byi5/c9dcf107a584e3fbeadfe1486bf5fd1c'
2020-09-17 17:54:19,284 [lib.cuckoo.core.scheduler] INFO: Task #13: acquired machine win7_x64_1 (label=win7_x64_1, platform=windows)

If I do nothing:

2020-09-17 16:55:04,321 [lib.cuckoo.core.scheduler] ERROR: Timeout hit while for machine win7_x64_1 to change status
Traceback (most recent call last):
  File "/opt/CAPEv2/lib/cuckoo/core/scheduler.py", line 308, in launch_analysis
    machinery.start(self.machine.label)
  File "/opt/CAPEv2/modules/machinery/kvm.py", line 29, in start
    super(KVM, self).start(label)
  File "/opt/CAPEv2/lib/cuckoo/common/abstracts.py", line 445, in start
    self._wait_status(label, self.RUNNING)
  File "/opt/CAPEv2/lib/cuckoo/common/abstracts.py", line 352, in _wait_status
    raise CuckooMachineError("Timeout hit while for machine {0} " "to change status".format(label))

After running virsh start win7_x64_1

2020-09-17 17:55:36,013 [lib.cuckoo.core.scheduler] INFO: Enabled route 'none'
2020-09-17 17:55:36,024 [modules.auxiliary.sniffer] INFO: Started sniffer with PID 83733 (interface=virbr123, host=192.168.123.11, dump path=/opt/CAPEv2/storage/analyses/13/dump.pcap)
2020-09-17 17:55:36,033 [lib.cuckoo.core.guest] INFO: Starting analysis #13 on guest (id=win7_x64_1, ip=192.168.123.11)
2020-09-17 17:55:43,057 [lib.cuckoo.core.guest] INFO: Guest is running CAPE Agent 0.11 (id=win7_x64_1, ip=192.168.123.11)
2020-09-17 17:55:43,566 [lib.cuckoo.core.guest] INFO: Uploading support files to guest (id=win7_x64_1, ip=192.168.123.11)

Seems like cape is missing permissions to start VMs, but this seems to work fine:

[cape@cape01 CAPEv2]$ python3
>>> import libvirt
>>> conn = libvirt.open('qemu:///system')
>>> machine = conn.lookupByName('win7_x64_1')
>>> machine.create()
0
>>> quit()
[cape@cape01 CAPEv2]$ virsh list
 Id    Name                           State
----------------------------------------------------
 8     win7_x64_1                     running

If I add self.vms[label].create() on this line then everything is working as expected. I'm not sure how machines are supposed to be getting created automatically when I don't see .create() being called anywhere in this start function or this start function?

@doomedraven
Copy link
Collaborator

doomedraven commented Sep 17, 2020

go to the old cape repo and search in issues, or maybe it was cuckoo-modified, i don't remember already, and you will see that create is required when you incorrectly created vm

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