xme commented 5 months ago

Prerequisites

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

[x] I am running the latest version
[x] I did read the README!
[x] I checked the documentation and found no answer
[x] I checked to make sure that this issue has not already been filed
[x] I'm reporting the issue to the correct repository (for multi-repository projects)
[x] I have read and checked all configs (with all optional parts)

Expected Behavior

Some modules are enabled but no data is collected at the end of the analysis. the stop() function seems to not be executed.

Current Behavior

This has been seen with the following 3 modules: sysmon, evtx, procmon. They are initialized, I see some debugging info when the analysis is launched but no data is returned at the end of the analysis...

Steps to Reproduce

Analyse a file... Analysis is completed:

2024-05-15 12:48:14,071 [lib.cuckoo.core.guest] INFO: Task #38: End of analysis reached! (id=win10x64, ip=192.168.122.106)
2024-05-15 12:48:55,802 [lib.cuckoo.core.scheduler] INFO: Disabled route 'internet'
2024-05-15 12:48:55,850 [lib.cuckoo.core.scheduler] INFO: Task #38: analysis procedure completed

However data is not collected (directories are empty in the analysis subdir and no logs are generated. For example, for evtx, it should log something like (according to the source code):

log.debug("Adding %s to zip dump", full_path)

doomedraven commented 5 months ago

probably due to subprocess in frond of stop, idk, i dont use those modules so i can't confirm why they doest work

kevoreilly commented 5 months ago

Could it be that debug messages are not showing due to the lack of -d switch for cuckoo.py? If you stop the cape service and run it manually with that switch, you might see more output.

xme commented 5 months ago

@kevoreilly No, because I see the "debug" messages generated by start().

Here is an example: $ grep evtx analysis.log

2024-05-15 12:41:05,674 [root] DEBUG: Importing auxiliary module "modules.auxiliary.evtx"...
2024-05-15 12:41:08,002 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Security State Change" /success:enable /failure:enable
2024-05-15 12:41:09,785 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Security System Extension" /success:enable /failure:enable
2024-05-15 12:41:10,192 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"System Integrity" /success:enable /failure:enable
2024-05-15 12:41:10,856 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"IPsec Driver" /success:disable /failure:disable
2024-05-15 12:41:11,611 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other System Events" /success:disable /failure:enable
2024-05-15 12:41:11,805 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Logon" /success:enable /failure:enable
2024-05-15 12:41:12,168 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Logoff" /success:enable /failure:enable
2024-05-15 12:41:12,584 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Account Lockout" /success:enable /failure:enable
2024-05-15 12:41:12,898 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"IPsec Main Mode" /success:disable /failure:disable
2024-05-15 12:41:13,629 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"IPsec Quick Mode" /success:disable /failure:disable
2024-05-15 12:41:14,049 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"IPsec Extended Mode" /success:disable /failure:disable
2024-05-15 12:41:14,221 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Logon/Logoff Events" /success:enable /failure:enable
2024-05-15 12:41:14,718 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Network Policy Server" /success:enable /failure:enable
2024-05-15 12:41:15,871 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Special Logon" /success:enable /failure:enable
2024-05-15 12:41:16,183 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"File System" /success:enable /failure:enable
2024-05-15 12:41:17,294 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Registry" /success:enable /failure:enable
2024-05-15 12:41:19,725 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Kernel Object" /success:enable /failure:enable
2024-05-15 12:41:21,195 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"SAM" /success:disable /failure:disable
2024-05-15 12:41:21,647 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Certification Services" /success:enable /failure:enable
2024-05-15 12:41:22,210 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Handle Manipulation" /success:disable /failure:disable
2024-05-15 12:41:22,679 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Application Generated" /success:enable /failure:enable
2024-05-15 12:41:24,681 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"File Share" /success:enable /failure:enable
2024-05-15 12:41:26,881 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Filtering Platform Packet Drop" /success:disable /failure:disable
2024-05-15 12:41:29,702 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Filtering Platform Connection" /success:disable /failure:disable
2024-05-15 12:41:32,150 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Object Access Events" /success:disable /failure:disable
2024-05-15 12:41:32,574 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Sensitive Privilege Use" /success:disable /failure:disable
2024-05-15 12:41:33,928 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Non Sensitive Privilege Use" /success:disable /failure:disable
2024-05-15 12:41:35,253 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Privilege Use Events" /success:disable /failure:disable
2024-05-15 12:41:35,997 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"RPC Events" /success:enable /failure:enable
2024-05-15 12:41:37,172 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Audit Policy Change" /success:enable /failure:enable
2024-05-15 12:41:38,196 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Authentication Policy Change" /success:enable /failure:enable
2024-05-15 12:41:38,977 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"MPSSVC Rule-Level Policy Change" /success:disable /failure:disable
2024-05-15 12:41:39,868 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Filtering Platform Policy Change" /success:disable /failure:disable
2024-05-15 12:41:40,259 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Policy Change Events" /success:disable /failure:enable
2024-05-15 12:41:40,603 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"User Account Management" /success:enable /failure:enable
2024-05-15 12:41:41,018 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Computer Account Management" /success:enable /failure:enable
2024-05-15 12:41:41,695 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Security Group Management" /success:enable /failure:enable
2024-05-15 12:41:42,087 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Distribution Group Management" /success:enable /failure:enable
2024-05-15 12:41:42,449 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Application Group Management" /success:enable /failure:enable
2024-05-15 12:41:42,869 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Account Management Events" /success:enable /failure:enable
2024-05-15 12:41:44,212 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Directory Service Access" /success:enable /failure:enable
2024-05-15 12:41:45,328 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Directory Service Changes" /success:enable /failure:enable
2024-05-15 12:41:45,991 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Directory Service Replication" /success:disable /failure:enable
2024-05-15 12:41:46,477 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Detailed Directory Service Replication" /success:disable /failure:disable
2024-05-15 12:41:47,313 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Credential Validation" /success:enable /failure:enable
2024-05-15 12:41:47,626 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Kerberos Service Ticket Operations" /success:enable /failure:enable
2024-05-15 12:41:47,923 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Other Account Logon Events" /success:enable /failure:enable
2024-05-15 12:41:48,313 [modules.auxiliary.evtx] DEBUG: Enabling advanced logging -> auditpol /set /subcategory:"Kerberos Authentication Service" /success:enable /failure:enable
2024-05-15 12:41:49,265 [modules.auxiliary.evtx] DEBUG: Wiping Application
2024-05-15 12:41:50,613 [modules.auxiliary.evtx] DEBUG: Wiping HardwareEvents
2024-05-15 12:41:50,973 [modules.auxiliary.evtx] DEBUG: Wiping Internet Explorer
2024-05-15 12:41:51,207 [modules.auxiliary.evtx] DEBUG: Wiping Key Management Service
2024-05-15 12:41:51,761 [modules.auxiliary.evtx] DEBUG: Wiping OAlerts
2024-05-15 12:41:52,009 [modules.auxiliary.evtx] DEBUG: Wiping Security
2024-05-15 12:41:52,336 [modules.auxiliary.evtx] DEBUG: Wiping Setup
2024-05-15 12:41:52,602 [modules.auxiliary.evtx] DEBUG: Wiping System
2024-05-15 12:41:53,146 [modules.auxiliary.evtx] DEBUG: Wiping Windows PowerShell
2024-05-15 12:41:54,481 [modules.auxiliary.evtx] DEBUG: Wiping Microsoft-Windows-Sysmon/Operational

Could this be the reason?

2024-05-15 12:46:49,822 [root] INFO: Analysis timeout hit, terminating analysis

nbargnesi commented 5 months ago

There's a lot of analyzer changes that just merged yesterday as part of https://github.com/kevoreilly/CAPEv2/pull/2041.

It's worth trying this again as the analyzer has changed quite a bit, in an effort to improve scenarios like these.

kevoreilly / CAPEv2

stop() module functions not executed/reached? #2120

Prerequisites

Expected Behavior

Current Behavior

Steps to Reproduce