kevoreilly / CAPEv2

Malware Configuration And Payload Extraction
https://capesandbox.com/analysis/
Other
1.95k stars 420 forks source link

Analysis Failing After Error Unlocking Physical Machine - session.add(machine) - Can't attach, another instance present in this session. #2353

Open boulwabd opened 5 days ago

boulwabd commented 5 days ago

About accounts on capesandbox.com

This is open source and you are getting free support so be friendly!

Prerequisites

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

Expected Behavior

Submit sample to physical machine, complete analysis, successfully release machine and make analysis available for reporting.

Current Behavior

What is the current behavior? Deployed fresh Cape instance, using a single physical host for analysis (no vms). Submitting sample and analysis is successful but then after the machine is reset to its clean image, Analysis manager fails after trying to release the machine and calling self.session.add(machine) in database.py due to "sqlalchemy.exc.InvalidRequestError: Can't attach instance <Machine at 0x79e514210070>; another instance with key (<class 'lib.cuckoo.core.database.Machine'>, (1,), None) is already present in this session."

Failure Information (for bugs)

2024-10-15 13:24:37,135 [lib.cuckoo.core.analysis_manager] ERROR: Task #1: failure in AnalysisManager.run
Traceback (most recent call last):
  File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 497, in run
    self.launch_analysis()
  File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 459, in launch_analysis
    success = self.perform_analysis()
  File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 443, in perform_analysis
    with self.machine_running(), self.result_server(), self.network_routing(), self.run_auxiliary():
  File "/usr/lib/python3.10/contextlib.py", line 142, in __exit__
    next(self.gen)
  File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 335, in machine_running
    self.machinery_manager.machinery.release(self.machine)
  File "/opt/CAPEv2/lib/cuckoo/common/abstracts.py", line 270, in release
    return self.db.unlock_machine(machine)
  File "/opt/CAPEv2/lib/cuckoo/core/database.py", line 978, in unlock_machine
    self.session.add(machine)
  File "<string>", line 2, in add
  File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2648, in add
    self._save_or_update_state(state)
  File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2672, in _save_or_update_state
    self._save_or_update_impl(state)
  File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3289, in _save_or_update_impl
    self._update_impl(state)
  File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3278, in _update_impl
    self.identity_map.add(state)
  File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/identity.py", line 151, in add
    raise sa_exc.InvalidRequestError(
sqlalchemy.exc.InvalidRequestError: Can't attach instance <Machine at 0x79e514210070>; another instance with key (<class 'lib.cuckoo.core.database.Machine'>, (1,), None) is already present in this session.

Steps to Reproduce

Please provide detailed steps for reproducing the issue.

  1. Running CUCKOO_VERSION = "2.4-CAPE" and SQLAlchemy = "1.4.50" with only one physical machine (no VMs)
  2. Submit file to physical machine for analysis
  3. Once analysis is complete the machine begins to reset to its clean state from Fog
  4. After the machine is reset the analysis fails trying to release the lock on it.
  5. Analysis is stuck in running state on the web app until the services are restarted, then shows analysis failed, although the storage folder seems to have all the analysis content successfully.

Context

CUCKOO_VERSION = "2.4-CAPE" SQLAlchemy = "1.4.50" Ubuntu 22.04.5 Python 3.10.12

Cape is running on a Qemu VM in a bridged virtual network with the physical machine similar to https://mariohenkel.medium.com/using-cape-sandbox-and-fog-to-analyze-malware-on-physical-machines-4dda328d4e2c

I noticed similar issues in https://github.com/kevoreilly/CAPEv2/issues/2225#issue-2407395084 and https://github.com/kevoreilly/CAPEv2/issues/2258#issue-2444522205 but they did not find solutions. I have been trying to debug it myself but have not figured out what the issue is yet. Thank you for any help and let me know if I can provide more info.

Failure Logs

cape.service logs (no sql)

Oct 15 00:32:58 cape sudo[3982]: pam_limits(sudo:session): unknown limit item 'hard'
Oct 15 00:32:58 cape sudo[3982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=997)
Oct 15 00:33:00 cape python3[3704]: 2024-10-15 00:33:00,428 [lib.cuckoo.core.guest] INFO: Task #1: Starting analysis on guest (id=physical01, ip=192.168.200.106)
Oct 15 00:33:00 cape python3[3704]: 2024-10-15 00:33:00,487 [lib.cuckoo.core.guest] INFO: Task #1: Guest is running CAPE Agent 0.12 (id=physical01, ip=192.168.200.106)
Oct 15 00:33:01 cape python3[3704]: 2024-10-15 00:33:01,860 [lib.cuckoo.core.guest] INFO: Task #1: Uploading script files to guest (id=physical01, ip=192.168.200.106)
Oct 15 00:33:14 cape python3[3704]: 2024-10-15 00:33:14,383 [lib.cuckoo.core.resultserver] INFO: Task 1: Process 5172 (parent 7808): 8f236f2d98fe2171ca74.exe, path C:\Users\jerry\AppData\Local\Temp\8f236f2d98fe2171ca74.exe
Oct 15 00:34:13 cape python3[3704]: 2024-10-15 00:34:13,485 [lib.cuckoo.core.resultserver] INFO: Task 1: Process 4324 (parent 5172): cttune.exe, path C:\Windows\SysWOW64\cttune.exe
Oct 15 00:36:42 cape python3[3704]: 2024-10-15 00:36:42,793 [lib.cuckoo.core.guest] INFO: Task #1: Analysis completed successfully (id=physical01, ip=192.168.200.106)
Oct 15 00:36:42 cape sudo[3982]: pam_unix(sudo:session): session closed for user root
Oct 15 00:36:43 cape python3[3704]: 2024-10-15 00:36:43,030 [lib.cuckoo.core.analysis_manager] INFO: Task #1: Disabled route 'internet'
Oct 15 00:41:58 cape python3[3704]: 2024-10-15 00:41:58,110 [lib.cuckoo.core.analysis_manager] ERROR: Task #1: failure in AnalysisManager.run
Oct 15 00:41:58 cape python3[3704]: Traceback (most recent call last):
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 497, in run
Oct 15 00:41:58 cape python3[3704]:     self.launch_analysis()
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 459, in launch_analysis
Oct 15 00:41:58 cape python3[3704]:     success = self.perform_analysis()
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 443, in perform_analysis
Oct 15 00:41:58 cape python3[3704]:     with self.machine_running(), self.result_server(), self.network_routing(), self.run_auxiliary():
Oct 15 00:41:58 cape python3[3704]:   File "/usr/lib/python3.10/contextlib.py", line 142, in __exit__
Oct 15 00:41:58 cape python3[3704]:     next(self.gen)
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/core/analysis_manager.py", line 335, in machine_running
Oct 15 00:41:58 cape python3[3704]:     self.machinery_manager.machinery.release(self.machine)
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/common/abstracts.py", line 270, in release
Oct 15 00:41:58 cape python3[3704]:     return self.db.unlock_machine(machine)
Oct 15 00:41:58 cape python3[3704]:   File "/opt/CAPEv2/lib/cuckoo/core/database.py", line 978, in unlock_machine
Oct 15 00:41:58 cape python3[3704]:     self.session.add(machine)
Oct 15 00:41:58 cape python3[3704]:   File "<string>", line 2, in add
Oct 15 00:41:58 cape python3[3704]:   File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2648, in add
Oct 15 00:41:58 cape python3[3704]:     self._save_or_update_state(state)
Oct 15 00:41:58 cape python3[3704]:   File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2672, in _save_or_update_state
Oct 15 00:41:58 cape python3[3704]:     self._save_or_update_impl(state)
Oct 15 00:41:58 cape python3[3704]:   File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3289, in _save_or_update_impl
Oct 15 00:41:58 cape python3[3704]:     self._update_impl(state)
Oct 15 00:41:58 cape python3[3704]:   File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3278, in _update_impl
Oct 15 00:41:58 cape python3[3704]:     self.identity_map.add(state)
Oct 15 00:41:58 cape python3[3704]:   File "/home/cape/.cache/pypoetry/virtualenvs/capev2-t2x27zRb-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/identity.py", line 151, in add
Oct 15 00:41:58 cape python3[3704]:     raise sa_exc.InvalidRequestError(
Oct 15 00:41:58 cape python3[3704]: sqlalchemy.exc.InvalidRequestError: Can't attach instance <Machine at 0x72786bfcd480>; another instance with key (<class 'lib.cuckoo.core.database.Machine'>, (1,), None) is already present in this session.

cape-processor.service logs (nosql)

Oct 15 00:31:51 cape python3[3394]: WHERE tasks.status = %(status_1)s ORDER BY tasks.completed_on ASC
Oct 15 00:31:51 cape python3[3394]:  LIMIT %(param_1)s) AS anon_1 LEFT OUTER JOIN (tasks_tags AS tasks_tags_1 JOIN tags AS tags_1 ON tags_1.id = tasks_tags_1.tag_id) ON anon_1.tasks_id = tasks_tags_1.task_id LEFT OUTER JOIN guests AS guests_1 ON anon_1.tasks_id = guests_1.task_id LEFT OUTER JOIN errors AS errors_1 ON anon_1.tasks_id = errors_1.task_id ORDER BY anon_1.tasks_completed_on ASC]
Oct 15 00:31:51 cape python3[3394]: [parameters: {'status_1': 'completed', 'param_1': 7}]
Oct 15 00:31:51 cape python3[3394]: (Background on this error at: https://sqlalche.me/e/14/f405)
Oct 15 00:31:51 cape systemd[1]: cape-processor.service: Deactivated successfully.
Oct 15 00:31:51 cape systemd[1]: cape-processor.service: Consumed 1min 36.730s CPU time.
Oct 15 00:32:04 cape systemd[1]: Stopped CAPE report processor.
Oct 15 00:32:04 cape systemd[1]: cape-processor.service: Consumed 1min 36.730s CPU time.
Oct 15 00:32:06 cape systemd[1]: Started CAPE report processor.
Oct 15 00:32:18 cape python3[3721]: 2024-10-15 00:32:18,530 [root] INFO: Processing analysis data

Here are logs with sql debug on. Attaching them separately because of length. Error is at line 5344 in cuckoo.log cuckoo.log process.log

conf files cuckoo.conf.txt physical.conf.txt

doomedraven commented 5 days ago

@tbeadle could you check it plz?