search

blacklanternsecurity / bbot

A recursive internet scanner for hackers.
https://www.blacklanternsecurity.com/bbot/
GNU General Public License v3.0
4.43k stars 396 forks source link

Tests Hang Arbitrarily #1571

Closed TheTechromancer closed 1 month ago

TheTechromancer commented 1 month ago

Pytest sometimes hangs arbitrarily:

2024-07-21T10:08:37.7202349Z PASSED                                                                   [ 27%]
2024-07-21T10:08:37.7260128Z bbot/test/test_step_2/module_tests/test_module_ajaxpro.py::TestAjaxpro::test_module_run 
2024-07-21T10:08:37.7261148Z -------------------------------- live log setup --------------------------------
2024-07-21T10:08:37.7261713Z INFO     bbot:base.py:103 Starting ajaxpro module test
2024-07-21T12:00:07.0968512Z ##[error]The operation was canceled.
2024-07-21T10:09:00.7963794Z PASSED                                                                   [ 30%]
2024-07-21T10:09:00.8019729Z bbot/test/test_step_2/module_tests/test_module_azure_tenant.py::TestAzure_Tenant::test_module_run 
2024-07-21T10:09:00.8021193Z -------------------------------- live log setup --------------------------------
2024-07-21T10:09:00.8022495Z INFO     bbot:base.py:103 Starting azure_tenant module test
2024-07-21T10:09:01.7808582Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-21T10:09:01.7851698Z WARNING  bbot.scanner:scanner.py:1053 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-21T10:09:01.9254036Z [WARN] Executing <Task pending name='Task-7350' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.123 seconds
2024-07-21T10:09:01.9259879Z WARNING  asyncio:base_events.py:1904 Executing <Task pending name='Task-7350' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.123 seconds
2024-07-21T10:09:01.9919984Z HUGEINFO bbot.scanner:scanner.py:1038 Scan with 1 modules seeded with 1 targets (1 in whitelist)
2024-07-21T10:09:01.9941437Z VERBOSE  bbot.scanner:scanner.py:1023 Loading 1 scan modules: azure_tenant
2024-07-21T10:09:01.9946697Z VERBOSE  bbot.scanner:scanner.py:1023 Loaded module "azure_tenant"
2024-07-21T10:09:01.9950123Z INFO     bbot.scanner:scanner.py:1033 Loaded 1/1 scan modules (azure_tenant)
2024-07-21T10:09:01.9952582Z VERBOSE  bbot.scanner:scanner.py:1023 Loading 1 internal modules: dnsresolve
2024-07-21T10:09:01.9956568Z VERBOSE  bbot.scanner:scanner.py:1023 Loaded module "dnsresolve"
2024-07-21T10:09:01.9959561Z INFO     bbot.scanner:scanner.py:1033 Loaded 1/1 internal modules (dnsresolve)
2024-07-21T10:09:01.9961731Z VERBOSE  bbot.scanner:scanner.py:1023 Loading 1 output modules: python
2024-07-21T10:09:01.9966087Z VERBOSE  bbot.scanner:scanner.py:1023 Loaded module "python"
2024-07-21T10:09:01.9968891Z INFO     bbot.scanner:scanner.py:1033 Loaded 1/1 output modules, (python)
2024-07-21T10:09:01.9972014Z VERBOSE  bbot.scanner:scanner.py:1023 Setting up modules
2024-07-21T10:09:02.1827800Z WARNING  asyncio:base_events.py:1904 Executing <Task finished name='Task-7354' coro=<BaseModule._setup() done, defined at /home/runner/work/bbot/bbot/bbot/modules/base.py:536> result=(<bbot.modules...x7f94018d71c0>, True, 'success') created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:337> took 0.181 seconds
2024-07-21T10:09:02.1845198Z SUCCESS  bbot.scanner:scanner.py:1043 Setup succeeded for 5/5 modules.
2024-07-21T10:09:02.1866242Z TRACE    bbot.scanner:scanner.py:1073 Ran BBOT v0.0.0 at 2024-07-21 10:09:02.184919, command: /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/bin/pytest --exitfirst --reruns 2 -o timeout_func_only=true --timeout 1200 --disable-warnings --log-cli-level=DEBUG --cov-config=bbot/test/coverage.cfg --cov-report xml:cov.xml --cov=bbot .
2024-07-21T10:09:02.1872512Z TRACE    bbot.scanner:scanner.py:1073 Target: {'seeds': ['blacklanternsecurity.com'], 'whitelist': ['blacklanternsecurity.com'], 'blacklist': [], 'strict_scope': False, 'hash': 'cffefd70a4eac5b8389a3c16987fb2ae91328c4c', 'seed_hash': '29b7be19a3f7633571a48c40f320d465c918c26b', 'whitelist_hash': '29b7be19a3f7633571a48c40f320d465c918c26b', 'blacklist_hash': 'da39a3ee5e6b4b0d3255bfef95601890afd80709', 'scope_hash': 'ef4a64d445f60a4ae47d81411d8994e40c3382d1'}
2024-07-21T10:09:02.2157278Z TRACE    bbot.scanner:scanner.py:1073 Preset: {'config': {'home': '/tmp/.bbot_test', 'keep_scans': 20, 'status_frequency': 15, 'file_blobs': False, 'folder_blobs': False, 'scope': {'report_distance': 0, 'search_distance': 0}, 'dns': {'disable': False, 'minimal': True, 'threads': 20, 'brute_threads': 1000, 'search_distance': 1, 'runaway_limit': 5, 'timeout': 1, 'retries': 1, 'wildcard_disable': False, 'wildcard_ignore': ['blacklanternsecurity.com', 'fakedomain', 'notreal', 'google', 'google.com', 'example.com', 'evilcorp.com', 'one'], 'wildcard_tests': 10, 'abort_threshold': 50, 'filter_ptrs': True, 'debug': False, 'omit_queries': ['SRV:mail.protection.outlook.com', 'CNAME:mail.protection.outlook.com', 'TXT:mail.protection.outlook.com']}, 'web': {'http_proxy': None, 'user_agent': 'BBOT Test User-Agent', 'spider_distance': 0, 'spider_depth': 1, 'spider_links_per_page': 25, 'http_timeout': 10, 'httpx_timeout': 5, 'http_headers': {'test': 'header'}, 'http_retries': 1, 'httpx_retries': 1, 'debug': False, 'http_max_redirects': 5, 'ssl_verify': False}, 'deps': {'ffuf': {'version': '2.1.0'}}, 'module_paths': [], 'speculate': False, 'excavate': False, 'aggregate': False, 'dnsresolve': True, 'cloudcheck': False, 'deps_behavior': 'abort_on_failure', 'url_querystring_remove': True, 'url_querystring_collapse': True, 'url_extension_blacklist': ['png', 'jpg', 'bmp', 'ico', 'jpeg', 'gif', 'svg', 'webp', 'css', 'woff', 'woff2', 'ttf', 'eot', 'sass', 'scss', 'mp3', 'm4a', 'wav', 'flac', 'mp4', 'mkv', 'avi', 'wmv', 'mov', 'flv', 'webm'], 'url_extension_httpx_only': ['js'], 'omit_event_types': [], 'interactsh_server': None, 'interactsh_disable': False, 'modules': {'massdns': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/deepmagic.com-prefixes-top500.txt'}, 'ffuf': {'prefix_busting': True, 'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/Web-Content/raft-small-directories.txt', 'lines': 5000, 'max_depth': 0, 'extensions': ''}, 'http': {'url': '', 'bearer': '', 'method': 'POST', 'timeout': 10, 'siem_friendly': False}, 'websocket': {'url': '', 'preserve_graph': True}, 'neo4j': {'uri': 'bolt://localhost:7687'}, 'asn': {}, 'affiliates': {}, 'discord': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'slack': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'splunk': {'url': '', 'index': '', 'source': '', 'timeout': 10}, 'teams': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'subdomains': {'output_file': '', 'include_unresolved': False}, 'emails': {'output_file': ''}, 'txt': {'output_file': ''}, 'web_report': {'output_file': '', 'css_theme_file': 'https://cdnjs.cloudflare.com/ajax/libs/github-markdown-css/5.1.0/github-markdown.min.css'}, 'python': {}, 'csv': {'output_file': ''}, 'stdout': {'format': 'text', 'event_types': [], 'event_fields': [], 'in_scope_only': False, 'accept_dupes': True}, 'json': {'output_file': '', 'siem_friendly': False}, 'asset_inventory': {'output_file': '', 'use_previous': False, 'recheck': False, 'summary_netmask': 16}, 'speculate': {'max_hosts': 65536, 'ports': '80,443'}, 'excavate': {'retain_querystring': False, 'yara_max_match_data': 2000, 'custom_yara_rules': ''}, 'cloudcheck': {}, 'dnsresolve': {}, 'aggregate': {}, 'anubisdb': {'limit': 1000}, 'gitlab': {}, 'trufflehog': {'version': '3.75.1', 'only_verified': True, 'concurrency': 8}, 'httpx': {'threads': 50, 'in_scope_only': True, 'version': '1.2.5', 'max_response_size': 5242880, 'store_responses': False, 'probe_all_ips': False}, 'chaos': {}, 'threatminer': {}, 'shodan_dns': {}, 'bucket_google': {'permutations': False}, 'crt': {}, 'git': {}, 'bucket_azure': {'permutations': False}, 'docker_pull': {'all_tags': False, 'output_folder': ''}, 'sitedossier': {}, 'portscan': {'top_ports': 100, 'ports': '', 'rate': 300, 'wait': 5, 'ping_first': False, 'ping_only': False, 'adapter': '', 'adapter_ip': '', 'adapter_mac': '', 'router_mac': ''}, 'ntlm': {'try_all': False}, 'smuggler': {}, 'dehashed': {}, 'newsletters': {}, 'hackertarget': {}, 'bucket_digitalocean': {'permutations': False}, 'hunt': {}, 'git_clone': {'output_folder': ''}, 'wayback': {'urls': False, 'garbage_threshold': 10}, 'wappalyzer': {}, 'url_manipulation': {'allow_redirects': True}, 'rapiddns': {}, 'ipstack': {}, 'c99': {}, 'censys': {'max_pages': 5}, 'leakix': {}, 'emailformat': {}, 'paramminer_getparams': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'badsecrets': {}, 'bucket_amazon': {'permutations': False}, 'ffuf_shortnames': {'wordlist': '', 'wordlist_extensions': '', 'lines': 1000000, 'max_depth': 1, 'version': '2.0.0', 'extensions': '', 'ignore_redirects': True, 'find_common_prefixes': False, 'find_delimiters': True}, 'hunterio': {}, 'dockerhub': {}, 'binaryedge': {'max_records': 1000}, 'subdomaincenter': {}, 'wafw00f': {'generic_detect': True}, 'github_org': {'include_members': True, 'include_member_repos': False}, 'riddler': {}, 'crobat': {}, 'otx': {}, 'telerik': {'exploit_RAU_crypto': False}, 'credshed': {'credshed_url': ''}, 'iis_shortnames': {'detect_only': True, 'max_node_count': 50}, 'baddns': {'custom_nameservers': [], 'only_high_confidence': False, 'enable_references': False}, 'sublist3r': {}, 'virustotal': {}, 'columbus': {}, 'dnscaa': {'in_scope_only': True, 'dns_names': True, 'emails': True, 'urls': True}, 'generic_ssrf': {}, 'certspotter': {}, 'github_codesearch': {'limit': 100}, 'azure_realm': {}, 'dnscommonsrv': {'max_depth': 2}, 'myssl': {}, 'pgp': {'search_urls': ['https://keyserver.ubuntu.com/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'http://the.earth.li:11371/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'https://pgpkeys.eu/pks/lookup?search=<query>&op=index', 'https://pgp.mit.edu/pks/lookup?search=<query>&op=index']}, 'wpscan': {'enumerate': 'vp,vt,tt,cb,dbe,u,m', 'threads': 5, 'request_timeout': 60, 'connection_timeout': 30, 'disable_tls_checks': True, 'force': False}, 'gowitness': {'version': '2.4.2', 'threads': 0, 'timeout': 10, 'resolution_x': 1440, 'resolution_y': 900, 'output_path': '', 'social': False, 'idle_timeout': 1800}, 'social': {}, 'dnsdumpster': {}, 'viewdns': {}, 'bucket_file_enum': {'file_limit': 50}, 'github_workflows': {'num_logs': 1}, 'securitytrails': {}, 'oauth': {'try_all': False}, 'internetdb': {'show_open_ports': False}, 'bucket_firebase': {'permutations': False}, 'host_header': {}, 'baddns_zone': {'custom_nameservers': [], 'only_high_confidence': False}, 'code_repository': {}, 'azure_tenant': {}, 'ip2location': {'lang': ''}, 'bypass403': {}, 'fullhunt': {}, 'dnsbrute': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'max_depth': 5}, 'secretsdb': {'min_confidence': 99, 'signatures': 'https://raw.githubusercontent.com/blacklanternsecurity/secrets-patterns-db/master/db/rules-stable.yml'}, 'zoomeye': {'max_pages': 20, 'include_related': False}, 'robots': {'include_sitemap': False, 'include_allow': True, 'include_disallow': True}, 'paramminer_headers': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'ipneighbor': {'num_bits': 4}, 'unstructured': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'ica', 'indd', 'ini', 'key', 'pub', 'log', 'markdown', 'md', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'ignore_folders': ['.git']}, 'postman': {}, 'sslcert': {'timeout': 5.0, 'skip_non_ssl': True}, 'filedownload': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'exe', 'ica', 'indd', 'ini', 'jar', 'key', 'pub', 'log', 'markdown', 'md', 'msi', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'raw', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'tar', 'tar.gz', 'zip', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'max_filesize': '10MB', 'base_64_encoded_file': 'false'}, 'ajaxpro': {}, 'dnsbrute_mutations': {'max_mutations': 100}, 'dotnetnuke': {}, 'digitorus': {}, 'skymem': {}, 'passivetotal': {}, 'builtwith': {'redirects': True}, 'urlscan': {'urls': False}, 'bevigil': {'urls': False}, 'paramminer_cookies': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'fingerprintx': {'version': '1.1.4', 'skip_common_web': True}, 'dastardly': {}, 'vhost': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'force_basehost': '', 'lines': 5000}, 'nuclei': {'version': '3.2.0', 'tags': '', 'templates': '', 'severity': '', 'ratelimit': 150, 'concurrency': 25, 'mode': 'manual', 'etags': '', 'budget': 1, 'silent': False, 'directory_only': True, 'retries': 0, 'batch_size': 200}, 'testmodule4': {}, 'testmodule1': {}, 'testmodule2': {}, 'testmodule3': {}}, 'agent_url': 'ws://127.0.0.1:8765', 'debug': True}, 'modules': ['azure_tenant'], 'output_modules': ['python'], 'scan_name': 'testazure_tenant_test_drov8jjaus', 'output_dir': None}
2024-07-21T10:09:02.2187809Z HUGESUCCESS bbot.scanner:scanner.py:1048 Starting scan testazure_tenant_test_drov8jjaus
2024-07-21T10:09:02.2188493Z VERBOSE  bbot.scanner:scanner.py:1023 Starting module worker loops
2024-07-21T10:09:02.4088430Z VERBOSE  bbot.scanner:scanner.py:1023 5 modules started
2024-07-21T10:09:02.4104725Z WARNING  asyncio:base_events.py:1904 Executing <Task pending name='Task-7350' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 0.226 seconds
2024-07-21T10:09:02.4672301Z VERBOSE  bbot.modules._scan_ingress:base.py:1250 Target: SCAN("{'id': 'SCAN:557f325dd4c965f7c1de66b48a7dd07c76df62e3', 'name': 'testazure_tenan...", module=TARGET, tags={'in-scope', 'target'})
2024-07-21T10:09:02.5160595Z [VERB] _scan_ingress: Target: DNS_NAME("blacklanternsecurity.com", module=TARGET, tags={'distance-1', 'domain', 'target'})
2024-07-21T10:09:02.5162431Z VERBOSE  bbot.modules._scan_ingress:base.py:1250 Target: DNS_NAME("blacklanternsecurity.com", module=TARGET, tags={'distance-1', 'domain', 'target'})
2024-07-21T10:09:02.7063039Z WARNING  asyncio:base_events.py:1904 Executing <Task pending name='_scan_ingress._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1447> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:337> took 0.188 seconds
2024-07-21T10:09:02.7235180Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-21T10:09:02.7252102Z VERBOSE  bbot.core.target:target.py:34 Creating events from 1 whitelist entries
2024-07-21T10:09:02.7293898Z DEBUG    httpx:_config.py:80 load_ssl_context verify=<ssl.SSLContext object at 0x7f945cdba640> cert=None trust_env=True http2=False
2024-07-21T12:00:07.7030619Z ##[error]The operation was canceled.

It's not clear why this is happening, but I did notice this new warning:

  /usr/lib/python3.12/pty.py:95: DeprecationWarning: This process (pid=994509) is multi-threaded, use of forkpty() may lead to deadlocks in the child.
    pid, fd = os.forkpty()

The culprit is ansible:

bbot/core/helpers/depsinstaller/installer.py:277: in ansible_run
    res = run(
/usr/lib/python3.12/site-packages/ansible_runner/interface.py:213: in run
    r.run()
/usr/lib/python3.12/site-packages/ansible_runner/runner.py:286: in run
    child = pexpect.spawn(
/usr/lib/python3.12/site-packages/pexpect/pty_spawn.py:205: in __init__
    self._spawn(command, args, preexec_fn, dimensions)
/usr/lib/python3.12/site-packages/pexpect/pty_spawn.py:303: in _spawn
    self.ptyproc = self._spawnpty(self.args, env=self.env,
/usr/lib/python3.12/site-packages/pexpect/pty_spawn.py:315: in _spawnpty
    return ptyprocess.PtyProcess.spawn(args, **kwargs)
/usr/lib/python3.12/site-packages/ptyprocess/ptyprocess.py:230: in spawn
    pid, fd = pty.fork()

There's a cpython issue that talks about these deadlocks:

https://github.com/python/cpython/issues/84559

TheTechromancer commented 1 month ago

Upstream ansible runner issue: https://github.com/ansible/ansible-runner/issues/1380

TheTechromancer commented 1 month ago

Even after the httpserver workaround, pytest still sometimes refuses to exit:

2024-07-21T13:27:33.0248085Z -------------------------------- live log call ---------------------------------
2024-07-21T13:27:33.0249300Z INFO     bbot.test.subdomainenumlowestparent:base.py:123 Finished subdomainenumlowestparent module test
2024-07-21T13:27:33.0257585Z INFO     bbot.test.subdomainenumlowestparent:base.py:129 No unfinished tasks detected
2024-07-21T13:27:38.6291887Z PASSED                                                                   [100%]
2024-07-21T13:27:38.6292280Z 
2024-07-21T13:27:38.6292389Z Test Session Summary:
2024-07-21T13:27:38.6292664Z Total tests run: 290
2024-07-21T13:27:38.6293424Z Passed: 289, Failed: 0, Skipped: 1, Errors: 0
2024-07-21T13:27:38.6293813Z 
2024-07-21T13:27:38.6294272Z ---------- coverage: platform linux, python 3.10.14-final-0 ----------
2024-07-21T13:27:38.6294754Z Coverage XML written to file cov.xml
2024-07-21T13:27:38.6294999Z 
2024-07-21T13:27:38.6295004Z 
2024-07-21T13:27:38.6295249Z =========== 289 passed, 1 skipped, 81 warnings in 1969.48s (0:32:49) ===========
2024-07-21T13:24:10.5505002Z -------------------------------- live log call ---------------------------------
2024-07-21T13:24:10.5506010Z INFO     bbot.test.secretsdb:base.py:123 Finished secretsdb module test
2024-07-21T13:24:10.5520069Z INFO     bbot.test.secretsdb:base.py:129 No unfinished tasks detected
2024-07-21T13:24:10.5528478Z [INFO] No unfinished tasks detected
2024-07-21T13:24:11.1650658Z PASSED                                                                   [ 83%]
2024-07-21T13:24:11.1714043Z bbot/test/test_step_2/module_tests/test_module_securitytrails.py::TestSecurityTrails::test_module_run 
2024-07-21T13:24:11.1715540Z -------------------------------- live log setup --------------------------------
2024-07-21T13:24:11.1716407Z INFO     bbot:base.py:103 Starting securitytrails module test
2024-07-21T13:24:12.1582653Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-21T13:24:12.1640893Z WARNING  bbot.scanner:scanner.py:1055 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-21T13:24:12.2938712Z [WARN] Executing <Task pending name='Task-18567' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f45fc1059d0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:626> took 1.122 seconds
2024-07-21T13:24:12.2945278Z WARNING  asyncio:base_events.py:1900 Executing <Task pending name='Task-18567' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f45fc1059d0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:626> took 1.122 seconds

https://github.com/blacklanternsecurity/bbot/issues/1563

TheTechromancer commented 1 month ago 
2024-07-21T14:34:57.6826678Z INFO     bbot.scanner:scanner.py:715 Finishing scan
2024-07-21T14:34:57.6853890Z VERBOSE  bbot.scanner:scanner.py:1025 Completed finish()
2024-07-21T14:34:57.7876284Z VERBOSE  bbot.scanner:scanner.py:1025 Completed final finish()
2024-07-21T14:34:57.7970392Z DEBUG    httpx:_config.py:80 load_ssl_context verify=<ssl.SSLContext object at 0x7f67e3980c40> cert=None trust_env=True http2=False
2024-07-21T14:34:57.8072027Z HUGESUCCESS bbot.scanner:scanner.py:1050 Scan testexcavate_retain_querystring_not_test_0k4cjpb2uc completed in 1 second with status FINISHED
2024-07-21T14:34:57.8082893Z [SUCC] Scan testexcavate_retain_querystring_not_test_0k4cjpb2uc completed in 1 second with status FINISHED
2024-07-21T14:34:57.8099827Z -------------------------------- live log call ---------------------------------
2024-07-21T14:34:57.8101294Z INFO     bbot.test.excavate_retain_querystring_not:base.py:123 Finished excavate_retain_querystring_not module test
2024-07-21T14:34:57.8103011Z [INFO] Finished excavate_retain_querystring_not module test
2024-07-21T14:34:57.8113811Z INFO     bbot.test.excavate_retain_querystring_not:base.py:129 No unfinished tasks detected
2024-07-21T14:34:58.3948399Z ##[error]The operation was canceled.
2024-07-21T14:08:04.4251258Z PASSED                                                                   [ 31%]
2024-07-21T14:08:04.4307092Z bbot/test/test_step_2/module_tests/test_module_baddns.py::TestBaddns_cname_nxdomain::test_module_run 
2024-07-21T14:08:04.4308634Z -------------------------------- live log setup --------------------------------
2024-07-21T14:08:04.4309605Z INFO     bbot:base.py:103 Starting baddns_cname_nxdomain module test
2024-07-21T14:08:05.3939284Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-21T14:08:05.3978018Z WARNING  bbot.scanner:scanner.py:1055 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-21T14:08:05.5365177Z WARNING  asyncio:base_events.py:1904 Executing <Task pending name='Task-7336' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.105 seconds
2024-07-21T14:34:59.0283880Z ##[error]The operation was canceled.
TheTechromancer commented 1 month ago

I'm seeing a lot of these warnings right before the freeze:

WARNING  asyncio:base_events.py:1904 Executing <Task pending name='Task-7336' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.105 seconds

WARNING  asyncio:base_events.py:1900 Executing <Task pending name='Task-18567' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py:326> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f45fc1059d0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:626> took 1.122 seconds

So I'm suspicious that this might be due to a bug in pytest-asyncio. There have been similar bugs in the past: https://github.com/pytest-dev/pytest-asyncio/issues/91.

TheTechromancer commented 1 month ago

Tried downgrading pytest-asyncio, no dice.

3.9

2024-07-21T15:42:45.4543666Z -------------------------------- live log call ---------------------------------
2024-07-21T15:42:45.4544813Z INFO     bbot.test.asset_inventoryrecheck:base.py:123 Finished asset_inventoryrecheck module test
2024-07-21T15:42:45.4549625Z INFO     bbot.test.asset_inventoryrecheck:base.py:129 No unfinished tasks detected
2024-07-21T15:42:46.4286676Z PASSED                                                                   [ 30%]
2024-07-21T15:42:46.4340263Z bbot/test/test_step_2/module_tests/test_module_azure_realm.py::TestAzure_Realm::test_module_run 
2024-07-21T15:42:46.4341745Z -------------------------------- live log setup --------------------------------
2024-07-21T15:42:46.4342671Z INFO     bbot:base.py:103 Starting azure_realm module test
2024-07-21T15:42:47.4121380Z [VERB] Creating events from 1 targets
2024-07-21T15:42:47.4122325Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-21T15:42:47.4158653Z WARNING  bbot.scanner:scanner.py:1055 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-21T15:42:47.4160799Z [WARN] You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-21T15:42:47.5409976Z WARNING  asyncio:base_events.py:1900 Executing <Task pending name='Task-7228' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe03b1a3a30>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:626> took 1.106 seconds
2024-07-21T16:14:41.6714575Z ##[error]The operation was canceled.

3.10

2024-07-21T16:02:00.4509636Z Test Session Summary:
2024-07-21T16:02:00.4509971Z Total tests run: 290
2024-07-21T16:02:00.4510792Z Passed: 289, Failed: 0, Skipped: 1, Errors: 0
2024-07-21T16:02:00.4511267Z 
2024-07-21T16:02:00.4511604Z ---------- coverage: platform linux, python 3.10.14-final-0 ----------
2024-07-21T16:02:00.4512181Z Coverage XML written to file cov.xml
2024-07-21T16:02:00.4512468Z 
2024-07-21T16:02:00.4512474Z 
2024-07-21T16:02:00.4512759Z =========== 289 passed, 1 skipped, 79 warnings in 1987.61s (0:33:07) ===========
2024-07-21T16:02:00.4513375Z === Detailed Thread and Process Information ===
2024-07-21T16:02:00.4513676Z 
2024-07-21T16:02:00.4513763Z === Threads ===
2024-07-21T16:02:00.4514010Z Thread Name: MainThread
2024-07-21T16:02:00.4514278Z Thread ID: 140643496418176
2024-07-21T16:02:00.4514540Z Is Alive: True
2024-07-21T16:02:00.4514761Z Daemon: False
2024-07-21T16:02:00.4514993Z Target Function: None
2024-07-21T16:02:00.4515160Z 
2024-07-21T16:02:00.4515310Z Thread Name: Thread-1 (_monitor)
2024-07-21T16:02:00.4515610Z Thread ID: 140643444368960
2024-07-21T16:02:00.4515868Z Is Alive: True
2024-07-21T16:02:00.4516088Z Daemon: True
2024-07-21T16:02:00.4516402Z Target Function: logging.handlers.QueueListener._monitor
2024-07-21T16:02:00.4516806Z Arguments:
2024-07-21T16:02:00.4517126Z 
2024-07-21T16:02:00.4517290Z Thread Name: Thread-10 (server_process)
2024-07-21T16:02:00.4517619Z Thread ID: 140642513180224
2024-07-21T16:02:00.4517873Z Is Alive: True
2024-07-21T16:02:00.4518092Z Daemon: True
2024-07-21T16:02:00.4518440Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4518865Z Arguments:
2024-07-21T16:02:00.4519256Z   server_class: <class 'bbot.core.helpers.dns.engine.DNSEngine'>
2024-07-21T16:02:00.4519725Z   socket_path: /tmp/zmq_xa0eipy3.sock
2024-07-21T16:02:00.4519963Z 
2024-07-21T16:02:00.4520440Z Thread Name: Thread-11 (server_process)
2024-07-21T16:02:00.4521088Z Thread ID: 140642613184064
2024-07-21T16:02:00.4521359Z Is Alive: True
2024-07-21T16:02:00.4521581Z Daemon: True
2024-07-21T16:02:00.4521937Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4522358Z Arguments:
2024-07-21T16:02:00.4522768Z   server_class: <class 'bbot.core.helpers.dns.engine.DNSEngine'>
2024-07-21T16:02:00.4523230Z   socket_path: /tmp/zmq_8ustrlh9.sock
2024-07-21T16:02:00.4523462Z 
2024-07-21T16:02:00.4523617Z Thread Name: Thread-14 (server_process)
2024-07-21T16:02:00.4523939Z Thread ID: 140642479617600
2024-07-21T16:02:00.4524197Z Is Alive: True
2024-07-21T16:02:00.4524415Z Daemon: True
2024-07-21T16:02:00.4524757Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4525175Z Arguments:
2024-07-21T16:02:00.4525575Z   server_class: <class 'bbot.core.helpers.dns.engine.DNSEngine'>
2024-07-21T16:02:00.4526046Z   socket_path: /tmp/zmq_rffi2jqg.sock
2024-07-21T16:02:00.4526275Z 
2024-07-21T16:02:00.4526436Z Thread Name: Thread-25 (server_process)
2024-07-21T16:02:00.4526760Z Thread ID: 140642227312192
2024-07-21T16:02:00.4527018Z Is Alive: True
2024-07-21T16:02:00.4527238Z Daemon: True
2024-07-21T16:02:00.4527699Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4528126Z Arguments:
2024-07-21T16:02:00.4528671Z   server_class: <class 'bbot.test.test_step_1.test_engine.test_engine.<locals>.TestEngineServer'>
2024-07-21T16:02:00.4529276Z   socket_path: /tmp/zmq_oxcjzd60.sock
2024-07-21T16:02:00.4529501Z 
2024-07-21T16:02:00.4529664Z Thread Name: Thread-108 (server_process)
2024-07-21T16:02:00.4529990Z Thread ID: 140641891767872
2024-07-21T16:02:00.4530247Z Is Alive: True
2024-07-21T16:02:00.4530464Z Daemon: True
2024-07-21T16:02:00.4530892Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4531307Z Arguments:
2024-07-21T16:02:00.4531705Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4532166Z   socket_path: /tmp/zmq_dwjw957z.sock
2024-07-21T16:02:00.4532384Z 
2024-07-21T16:02:00.4532539Z Thread Name: Thread-145 (server_process)
2024-07-21T16:02:00.4532862Z Thread ID: 140640784479808
2024-07-21T16:02:00.4533116Z Is Alive: True
2024-07-21T16:02:00.4533329Z Daemon: True
2024-07-21T16:02:00.4533660Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4534081Z Arguments:
2024-07-21T16:02:00.4534477Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4534937Z   socket_path: /tmp/zmq_9zmgzye6.sock
2024-07-21T16:02:00.4535158Z 
2024-07-21T16:02:00.4535313Z Thread Name: Thread-448 (server_process)
2024-07-21T16:02:00.4535642Z Thread ID: 140640566322752
2024-07-21T16:02:00.4535895Z Is Alive: True
2024-07-21T16:02:00.4536116Z Daemon: True
2024-07-21T16:02:00.4536445Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4536859Z Arguments:
2024-07-21T16:02:00.4537252Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4537706Z   socket_path: /tmp/zmq_3djygvsq.sock
2024-07-21T16:02:00.4537926Z 
2024-07-21T16:02:00.4538115Z Thread Name: Thread-546 (process_request_thread)
2024-07-21T16:02:00.4538481Z Thread ID: 140640616666688
2024-07-21T16:02:00.4538738Z Is Alive: True
2024-07-21T16:02:00.4538953Z Daemon: True
2024-07-21T16:02:00.4539326Z Target Function: socketserver.ThreadingMixIn.process_request_thread
2024-07-21T16:02:00.4539871Z Arguments:
2024-07-21T16:02:00.4540675Z   request: <socket.socket fd=111, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 8888), raddr=('127.0.0.1', 56478)>
2024-07-21T16:02:00.4541500Z   client_address: ('127.0.0.1', 56478)
2024-07-21T16:02:00.4541725Z 
2024-07-21T16:02:00.4541884Z Thread Name: Thread-550 (server_process)
2024-07-21T16:02:00.4542216Z Thread ID: 140640633448000
2024-07-21T16:02:00.4542473Z Is Alive: True
2024-07-21T16:02:00.4542685Z Daemon: True
2024-07-21T16:02:00.4543111Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4543539Z Arguments:
2024-07-21T16:02:00.4543935Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4544392Z   socket_path: /tmp/zmq_c9np74z6.sock
2024-07-21T16:02:00.4544616Z 
2024-07-21T16:02:00.4544767Z Thread Name: Thread-551 (server_process)
2024-07-21T16:02:00.4545089Z Thread ID: 140640448935488
2024-07-21T16:02:00.4545345Z Is Alive: True
2024-07-21T16:02:00.4545562Z Daemon: True
2024-07-21T16:02:00.4545899Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4546311Z Arguments:
2024-07-21T16:02:00.4546695Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4547141Z   socket_path: /tmp/zmq_i0zzriib.sock
2024-07-21T16:02:00.4547367Z 
2024-07-21T16:02:00.4547516Z Thread Name: Thread-553 (server_process)
2024-07-21T16:02:00.4547834Z Thread ID: 140640180500032
2024-07-21T16:02:00.4548089Z Is Alive: True
2024-07-21T16:02:00.4548296Z Daemon: True
2024-07-21T16:02:00.4548634Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4549041Z Arguments:
2024-07-21T16:02:00.4549420Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4549939Z   socket_path: /tmp/zmq_fks88qxz.sock
2024-07-21T16:02:00.4550161Z 
2024-07-21T16:02:00.4550315Z Thread Name: Thread-567 (server_process)
2024-07-21T16:02:00.4550634Z Thread ID: 140639945610816
2024-07-21T16:02:00.4550883Z Is Alive: True
2024-07-21T16:02:00.4551099Z Daemon: True
2024-07-21T16:02:00.4551434Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4551845Z Arguments:
2024-07-21T16:02:00.4552218Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4552676Z   socket_path: /tmp/zmq_xwxvbtcx.sock
2024-07-21T16:02:00.4552971Z 
2024-07-21T16:02:00.4553124Z Thread Name: Thread-575 (server_process)
2024-07-21T16:02:00.4553441Z Thread ID: 140640750917184
2024-07-21T16:02:00.4553688Z Is Alive: True
2024-07-21T16:02:00.4553908Z Daemon: True
2024-07-21T16:02:00.4554249Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4554667Z Arguments:
2024-07-21T16:02:00.4555055Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4555510Z   socket_path: /tmp/zmq_axgmhgwq.sock
2024-07-21T16:02:00.4555739Z 
2024-07-21T16:02:00.4555900Z Thread Name: Thread-578 (server_process)
2024-07-21T16:02:00.4556231Z Thread ID: 140639761016384
2024-07-21T16:02:00.4556485Z Is Alive: True
2024-07-21T16:02:00.4556708Z Daemon: True
2024-07-21T16:02:00.4557051Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4567669Z Arguments:
2024-07-21T16:02:00.4568409Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4568921Z   socket_path: /tmp/zmq_6j06ibs8.sock
2024-07-21T16:02:00.4569167Z 
2024-07-21T16:02:00.4569341Z Thread Name: Thread-582 (server_process)
2024-07-21T16:02:00.4569683Z Thread ID: 140639777797696
2024-07-21T16:02:00.4569962Z Is Alive: True
2024-07-21T16:02:00.4570187Z Daemon: True
2024-07-21T16:02:00.4570545Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4570980Z Arguments:
2024-07-21T16:02:00.4571388Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4571850Z   socket_path: /tmp/zmq_uey31zwj.sock
2024-07-21T16:02:00.4572081Z 
2024-07-21T16:02:00.4572390Z Thread Name: Thread-583 (server_process)
2024-07-21T16:02:00.4573030Z Thread ID: 140639609984576
2024-07-21T16:02:00.4573367Z Is Alive: True
2024-07-21T16:02:00.4573587Z Daemon: True
2024-07-21T16:02:00.4573953Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4574375Z Arguments:
2024-07-21T16:02:00.4574789Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4575253Z   socket_path: /tmp/zmq_ektxu1x8.sock
2024-07-21T16:02:00.4575479Z 
2024-07-21T16:02:00.4575641Z Thread Name: Thread-585 (server_process)
2024-07-21T16:02:00.4576086Z Thread ID: 140639794579008
2024-07-21T16:02:00.4576351Z Is Alive: True
2024-07-21T16:02:00.4576576Z Daemon: True
2024-07-21T16:02:00.4576926Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4577355Z Arguments:
2024-07-21T16:02:00.4577752Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4578212Z   socket_path: /tmp/zmq_p87of0qk.sock
2024-07-21T16:02:00.4578444Z 
2024-07-21T16:02:00.4578600Z Thread Name: Thread-740 (server_process)
2024-07-21T16:02:00.4578933Z Thread ID: 140640281155136
2024-07-21T16:02:00.4579189Z Is Alive: True
2024-07-21T16:02:00.4579411Z Daemon: True
2024-07-21T16:02:00.4579759Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4580178Z Arguments:
2024-07-21T16:02:00.4580561Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4581015Z   socket_path: /tmp/zmq_i3h0jsok.sock
2024-07-21T16:02:00.4581235Z 
2024-07-21T16:02:00.4581398Z Thread Name: Thread-749 (server_process)
2024-07-21T16:02:00.4581732Z Thread ID: 140639895266880
2024-07-21T16:02:00.4581985Z Is Alive: True
2024-07-21T16:02:00.4582206Z Daemon: True
2024-07-21T16:02:00.4582631Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4583049Z Arguments:
2024-07-21T16:02:00.4583445Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4583901Z   socket_path: /tmp/zmq_lwrstcdz.sock
2024-07-21T16:02:00.4584118Z 
2024-07-21T16:02:00.4584279Z Thread Name: Thread-758 (server_process)
2024-07-21T16:02:00.4584594Z Thread ID: 140639811360320
2024-07-21T16:02:00.4584853Z Is Alive: True
2024-07-21T16:02:00.4585073Z Daemon: True
2024-07-21T16:02:00.4585411Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4585904Z Arguments:
2024-07-21T16:02:00.4586297Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4586744Z   socket_path: /tmp/zmq_vf4nzm7f.sock
2024-07-21T16:02:00.4586963Z 
2024-07-21T16:02:00.4587122Z Thread Name: Thread-776 (server_process)
2024-07-21T16:02:00.4587437Z Thread ID: 140639643547200
2024-07-21T16:02:00.4587698Z Is Alive: True
2024-07-21T16:02:00.4587917Z Daemon: True
2024-07-21T16:02:00.4588255Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4588658Z Arguments:
2024-07-21T16:02:00.4589043Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4589485Z   socket_path: /tmp/zmq_2njhuc50.sock
2024-07-21T16:02:00.4589699Z 
2024-07-21T16:02:00.4589861Z Thread Name: Thread-785 (server_process)
2024-07-21T16:02:00.4590171Z Thread ID: 140639542859328
2024-07-21T16:02:00.4590429Z Is Alive: True
2024-07-21T16:02:00.4590652Z Daemon: True
2024-07-21T16:02:00.4590986Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4591397Z Arguments:
2024-07-21T16:02:00.4591786Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4592233Z   socket_path: /tmp/zmq_dfagyai1.sock
2024-07-21T16:02:00.4592450Z 
2024-07-21T16:02:00.4592609Z Thread Name: Thread-2103 (server_process)
2024-07-21T16:02:00.4592940Z Thread ID: 140640583104064
2024-07-21T16:02:00.4593203Z Is Alive: True
2024-07-21T16:02:00.4593430Z Daemon: True
2024-07-21T16:02:00.4593770Z Target Function: bbot.core.engine.EngineClient.server_process
2024-07-21T16:02:00.4594193Z Arguments:
2024-07-21T16:02:00.4594667Z   server_class: <class 'bbot.core.helpers.web.engine.HTTPEngine'>
2024-07-21T16:02:00.4595124Z   socket_path: /tmp/zmq_q1lsgys3.sock
2024-07-21T16:02:00.4595348Z 
2024-07-21T16:02:00.4595490Z Thread Name: Thread-6697 (_serve)
2024-07-21T16:02:00.4595796Z Thread ID: 140640734135872
2024-07-21T16:02:00.4596058Z Is Alive: True
2024-07-21T16:02:00.4596284Z Daemon: True
2024-07-21T16:02:00.4596707Z Target Function: multiprocessing.resource_sharer._ResourceSharer._serve
2024-07-21T16:02:00.4597171Z Arguments:
2024-07-21T16:02:00.4597299Z 
2024-07-21T16:02:00.4597397Z === Processes ===
2024-07-21T16:02:00.4597715Z Process ID: 1854
2024-07-21T16:02:00.4597948Z Name: python
2024-07-21T16:02:00.4598173Z Status: sleeping
2024-07-21T16:02:00.4598654Z CPU Times: pcputimes(user=0.14, system=0.04, children_user=0.0, children_system=0.0, iowait=0.0)
2024-07-21T16:02:00.4599455Z Memory Info: pmem(rss=22511616, vms=30318592, shared=10616832, text=4096, lib=0, data=12742656, dirty=0)
2024-07-21T16:02:00.4599933Z 
2024-07-21T16:02:00.4600034Z === Current Process ===
2024-07-21T16:02:00.4600296Z Process ID: 1847
2024-07-21T16:02:00.4600656Z Name: pytest
2024-07-21T16:02:00.4600972Z Status: running
2024-07-21T16:02:00.4601498Z CPU Times: pcputimes(user=785.36, system=19.4, children_user=528.34, children_system=103.29, iowait=0.0)
2024-07-21T16:02:00.4602336Z Memory Info: pmem(rss=727482368, vms=4084363264, shared=52166656, text=4096, lib=0, data=2204229632, dirty=0)
2024-07-21T16:02:00.4602822Z 
2024-07-21T16:14:41.6547813Z ##[error]The operation was canceled.
TheTechromancer commented 1 month ago

3.11

2024-07-21T16:36:04.1278956Z -------------------------------- live log call ---------------------------------
2024-07-21T16:36:04.1280093Z INFO     bbot.test.aggregate:base.py:123 Finished aggregate module test
2024-07-21T16:36:04.1283845Z INFO     bbot.test.aggregate:base.py:129 No unfinished tasks detected
2024-07-21T16:36:04.9827325Z PASSED                                                                   [ 27%]
2024-07-21T16:36:04.9883349Z bbot/test/test_step_2/module_tests/test_module_ajaxpro.py::TestAjaxpro::test_module_run 
2024-07-21T16:36:04.9884772Z -------------------------------- live log setup --------------------------------
2024-07-21T16:36:04.9885658Z INFO     bbot:base.py:103 Starting ajaxpro module test
2024-07-21T22:22:27.7103228Z ##[error]The operation was canceled.
TheTechromancer commented 1 month ago

3.10

2024-07-22T04:23:42.3935985Z -------------------------------- live log call ---------------------------------
2024-07-22T04:23:42.3937006Z INFO     bbot.test.github_org:base.py:123 Finished github_org module test
2024-07-22T04:23:42.3943012Z INFO     bbot.test.github_org:base.py:129 No unfinished tasks detected
2024-07-22T04:23:42.3949357Z [INFO] Finished github_org module test
2024-07-22T04:23:42.3950360Z [INFO] No unfinished tasks detected
2024-07-22T04:23:42.3961243Z 
2024-07-22T04:23:42.3961600Z ------------------------------ live log teardown -------------------------------
2024-07-22T04:23:42.3962813Z DEBUG    asyncio:base_events.py:672 Close <_UnixSelectorEventLoop running=False closed=False debug=True>
2024-07-22T04:23:42.3968173Z DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
2024-07-22T04:23:43.2099372Z PASSED                                                                   [ 60%]
2024-07-22T04:23:43.2143886Z bbot/test/test_step_2/module_tests/test_module_github_org.py::TestGithub_Org_No_Members::test_module_run 
2024-07-22T04:23:43.2145826Z -------------------------------- live log setup --------------------------------
2024-07-22T04:23:43.2146792Z DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
2024-07-22T04:23:43.2152996Z DEBUG    asyncio:base_events.py:672 Close <_UnixSelectorEventLoop running=False closed=False debug=True>
2024-07-22T04:23:43.2164040Z INFO     bbot:base.py:103 Starting github_org_no_members module test
2024-07-22T04:23:43.2165950Z [INFO] Starting github_org_no_members module test
2024-07-22T04:23:43.4195366Z DEBUG    bbot.presets:preset.py:963 Preset : Getting baked
2024-07-22T04:23:44.2406398Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "github_org" of type "scan"
2024-07-22T04:23:44.2409517Z VERBOSE  bbot.presets:preset.py:959 Preset : Adding module "social" because github_org depends on it
2024-07-22T04:23:44.2411616Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "social" of type "scan"
2024-07-22T04:23:44.2414664Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "python" of type "output"
2024-07-22T04:23:44.2424384Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "speculate" of type "internal"
2024-07-22T04:23:44.2429371Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "dnsresolve" of type "internal"
2024-07-22T04:23:44.2433936Z VERBOSE  bbot.core.target:target.py:29 Creating events from 1 targets
2024-07-22T04:23:44.2491462Z WARNING  bbot.scanner:scanner.py:1055 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-22T04:23:44.2501811Z DEBUG    bbot:base.py:107 Mocking DNS
2024-07-22T04:23:44.3963278Z [WARN] Executing <Task pending name='Task-13407' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.179 seconds
2024-07-22T04:23:44.3974272Z WARNING  asyncio:base_events.py:1904 Executing <Task pending name='Task-13407' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.10/lib/python3.10/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:429> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/base_events.py:184] created at /opt/hostedtoolcache/Python/3.10.14/x64/lib/python3.10/asyncio/tasks.py:636> took 1.179 seconds
2024-07-22T04:23:44.3978825Z [DBUG] EngineServer DNSEngine got message: {'c': 99, 'k': {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}}}
2024-07-22T04:23:44.3980124Z DEBUG    bbot.core.dnsengine:engine.py:440 EngineServer DNSEngine got message: {'c': 99, 'k': {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}}}
2024-07-22T05:02:44.0209323Z ##[error]The operation was canceled.
TheTechromancer commented 1 month ago

3.12

2024-07-23T02:43:52.6520813Z -------------------------------- live log call ---------------------------------
2024-07-23T02:43:52.6522062Z DEBUG    bbot.core.httpengine:engine.py:446 EngineServer HTTPEngine got message: {'c': -99}
2024-07-23T02:43:52.6523639Z DEBUG    bbot.core.httpengine:engine.py:497 EngineServer HTTPEngine: shutting down...
2024-07-23T02:43:52.6529990Z DEBUG    bbot.core.httpengine:engine.py:507 EngineServer HTTPEngine: finished shutting down
2024-07-23T02:43:52.6532738Z [DBUG] EngineServer HTTPEngine: shutting down...
2024-07-23T02:43:52.6534598Z [DBUG] EngineServer HTTPEngine: finished shutting down
2024-07-23T02:43:52.6538077Z DEBUG    bbot.core.httpengine:engine.py:494 EngineServer HTTPEngine: finished worker()
2024-07-23T02:43:52.6544496Z DEBUG    bbot.core.dnsengine:engine.py:446 EngineServer DNSEngine got message: {'c': -99}
2024-07-23T02:43:52.6547296Z DEBUG    bbot.core.dnsengine:engine.py:497 EngineServer DNSEngine: shutting down...
2024-07-23T02:43:52.6554526Z DEBUG    bbot.core.dnsengine:engine.py:507 EngineServer DNSEngine: finished shutting down
2024-07-23T02:43:52.6557615Z DEBUG    bbot.core.dnsengine:engine.py:494 EngineServer DNSEngine: finished worker()
2024-07-23T02:43:52.6572879Z INFO     bbot.test.nucleiretries:base.py:123 Finished nucleiretries module test
2024-07-23T02:43:52.6580322Z INFO     bbot.test.nucleiretries:base.py:129 No unfinished tasks detected
2024-07-23T02:43:52.6606568Z 
2024-07-23T02:43:52.6607169Z ------------------------------ live log teardown -------------------------------
2024-07-23T02:43:52.6608420Z DEBUG    asyncio:base_events.py:710 Close <_UnixSelectorEventLoop running=False closed=False debug=True>
2024-07-23T02:43:52.6611576Z DEBUG    asyncio:selector_events.py:64 Using selector: EpollSelector
2024-07-23T02:43:53.0778274Z PASSED                                                                   [ 74%]
2024-07-23T02:43:53.0834983Z bbot/test/test_step_2/module_tests/test_module_nuclei.py::TestNucleiRetriesCustom::test_module_run 
2024-07-23T02:43:53.0836281Z -------------------------------- live log setup --------------------------------
2024-07-23T02:43:53.0837286Z DEBUG    asyncio:selector_events.py:64 Using selector: EpollSelector
2024-07-23T02:43:53.0846199Z DEBUG    asyncio:base_events.py:710 Close <_UnixSelectorEventLoop running=False closed=False debug=True>
2024-07-23T02:43:53.0859806Z INFO     bbot:base.py:103 Starting nucleiretriescustom module test
2024-07-23T02:43:53.3448164Z DEBUG    bbot.presets:preset.py:963 Preset : Getting baked
2024-07-23T02:43:54.3557899Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "nuclei" of type "scan"
2024-07-23T02:43:54.3563299Z VERBOSE  bbot.presets:logger.py:132 Preset : Adding module "httpx" because nuclei depends on it
2024-07-23T02:43:54.3566699Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "httpx" of type "scan"
2024-07-23T02:43:54.3571590Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "httpx" of type "scan"
2024-07-23T02:43:54.3579152Z [VERB] Preset : Adding module "httpx" because nuclei depends on it
2024-07-23T02:43:54.3580929Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "python" of type "output"
2024-07-23T02:43:54.3589111Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "excavate" of type "internal"
2024-07-23T02:43:54.3593667Z DEBUG    bbot.presets:preset.py:963 Preset : Adding module "dnsresolve" of type "internal"
2024-07-23T02:43:54.3600316Z VERBOSE  bbot.core.target:logger.py:132 Creating events from 1 targets
2024-07-23T02:43:54.5235157Z WARNING  bbot.scanner:scanner.py:1055 You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-23T02:43:54.5237155Z [WARN] You have enabled custom HTTP headers. These will be attached to all in-scope requests and all requests made by httpx.
2024-07-23T02:43:54.5251227Z DEBUG    bbot:base.py:107 Mocking DNS
2024-07-23T02:43:54.5275802Z DEBUG    bbot.core.dnshelper:engine.py:136 EngineClient DNSHelper: executing run-and-return _mock_dns((), {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}})
2024-07-23T02:43:54.5332557Z WARNING  asyncio:base_events.py:1982 Executing <Task pending name='Task-15955' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/lib/python3.12/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[_AsyncSocket._remove_finished_future(event_list=deque([_FutureEvent(...re._NoTimer'>)]), event=_FutureEvent(...re._NoTimer'>))() at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/lib/python3.12/site-packages/zmq/_future.py:475, Task.task_wakeup()] created at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/lib/python3.12/site-packages/zmq/_future.py:495> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:182] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/tasks.py:695> took 1.446 seconds
2024-07-23T02:43:54.5349049Z DEBUG    bbot.core.dnsengine:engine.py:446 EngineServer DNSEngine got message: {'c': 99, 'k': {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}}}
2024-07-23T02:43:54.5368583Z DEBUG    bbot.core.dnsengine:engine.py:380 EngineServer DNSEngine run-and-return _mock_dns((), {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}})
2024-07-23T02:43:54.5373124Z DEBUG    bbot.core.dnsengine:engine.py:391 EngineServer DNSEngine: Sending response to _mock_dns((), {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}}): None
2024-07-23T02:43:54.5391391Z DEBUG    bbot.core.dnsengine:engine.py:399 EngineServer DNSEngine finished run-and-return _mock_dns((), {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}})
2024-07-23T02:43:54.5403156Z DEBUG    bbot.core.dnshelper:engine.py:156 EngineClient DNSHelper: _mock_dns((), {'mock_data': {'blacklanternsecurity.com': {'A': ['127.0.0.88']}}}) got return value: None
2024-07-23T02:43:54.5404705Z DEBUG    bbot:base.py:109 Executing setup_before_prep()
2024-07-23T02:43:54.5408501Z DEBUG    bbot:base.py:111 Executing scan._prep()
2024-07-23T02:43:54.6294137Z HUGEINFO bbot.scanner:logger.py:132 Scan with 2 modules seeded with 1 targets (1 in whitelist)
2024-07-23T02:43:54.6311242Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:72 Installing excavate - Preloaded Deps {'modules': [], 'pip': [], 'pip_constraints': [], 'shell': [], 'apt': [], 'ansible': [], 'common': []}
2024-07-23T02:43:54.6314077Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:84 No dependency work to do for module "excavate"
2024-07-23T02:43:54.6318204Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:72 Installing python - Preloaded Deps {'modules': [], 'pip': [], 'pip_constraints': [], 'shell': [], 'apt': [], 'ansible': [], 'common': []}
2024-07-23T02:43:54.6321460Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:84 No dependency work to do for module "python"
2024-07-23T02:43:54.6328061Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:72 Installing nuclei - Preloaded Deps {'modules': ['httpx'], 'pip': ['pyyaml~=6.0'], 'pip_constraints': [], 'shell': [], 'apt': [], 'ansible': [{'name': 'Download nuclei', 'unarchive': {'src': 'https://github.com/projectdiscovery/nuclei/releases/download/v3.2.0/nuclei_3.2.0_linux_amd64.zip', 'include': 'nuclei', 'dest': '/tmp/.bbot_test/tools', 'remote_src': True}, 'become': False}], 'common': []}
2024-07-23T02:43:54.6332325Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:110 Skipping dependency install for module "nuclei" because it's already done (--force-deps to re-run)
2024-07-23T02:43:54.6338815Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:72 Installing httpx - Preloaded Deps {'modules': ['httpx'], 'pip': [], 'pip_constraints': [], 'shell': [], 'apt': [], 'ansible': [{'name': 'Download httpx', 'unarchive': {'src': 'https://github.com/projectdiscovery/httpx/releases/download/v1.2.5/httpx_1.2.5_linux_amd64.zip', 'include': 'httpx', 'dest': '/tmp/.bbot_test/tools', 'remote_src': True}, 'become': False}], 'common': []}
2024-07-23T02:43:54.6343594Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:110 Skipping dependency install for module "httpx" because it's already done (--force-deps to re-run)
2024-07-23T02:43:54.6346550Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:72 Installing dnsresolve - Preloaded Deps {'modules': [], 'pip': [], 'pip_constraints': [], 'shell': [], 'apt': [], 'ansible': [], 'common': []}
2024-07-23T02:43:54.6348647Z DEBUG    bbot.core.helpers.depsinstaller:installer.py:84 No dependency work to do for module "dnsresolve"
2024-07-23T02:43:54.6358751Z VERBOSE  bbot.scanner:logger.py:132 Loading 2 scan modules: httpx,nuclei
2024-07-23T02:43:54.6364737Z VERBOSE  bbot.scanner:logger.py:132 Loaded module "httpx"
2024-07-23T02:43:54.6368393Z VERBOSE  bbot.scanner:logger.py:132 Loaded module "nuclei"
2024-07-23T02:43:54.6373675Z INFO     bbot.scanner:scanner.py:1035 Loaded 2/2 scan modules (httpx,nuclei)
2024-07-23T02:43:54.6376267Z VERBOSE  bbot.scanner:logger.py:132 Loading 2 internal modules: dnsresolve,excavate
2024-07-23T02:43:54.6382983Z VERBOSE  bbot.scanner:logger.py:132 Loaded module "dnsresolve"
2024-07-23T02:43:54.6387978Z VERBOSE  bbot.scanner:logger.py:132 Loaded module "excavate"
2024-07-23T02:43:54.6391569Z INFO     bbot.scanner:scanner.py:1035 Loaded 2/2 internal modules (dnsresolve,excavate)
2024-07-23T02:43:54.6395057Z VERBOSE  bbot.scanner:logger.py:132 Loading 1 output modules: python
2024-07-23T02:43:54.6398680Z VERBOSE  bbot.scanner:logger.py:132 Loaded module "python"
2024-07-23T02:43:54.6402864Z INFO     bbot.scanner:scanner.py:1035 Loaded 1/1 output modules, (python)
2024-07-23T02:43:54.6408738Z VERBOSE  bbot.scanner:logger.py:132 Setting up modules
2024-07-23T02:43:54.6492703Z WARNING  asyncio:base_events.py:1982 Executing <Task pending name='Task-15955' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/lib/python3.12/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:449> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:182] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/tasks.py:695> took 0.109 seconds
2024-07-23T02:43:54.6498503Z DEBUG    bbot.modules._scan_ingress:base.py:1234 Setting up module _scan_ingress
2024-07-23T02:43:54.6499819Z DEBUG    bbot.modules._scan_ingress:base.py:1234 Finished setting up module _scan_ingress
2024-07-23T02:43:54.6501070Z DEBUG    bbot.modules.dnsresolve:base.py:1234 Setting up module dnsresolve
2024-07-23T02:43:54.8939786Z DEBUG    bbot.modules.dnsresolve:base.py:1234 Finished setting up module dnsresolve
2024-07-23T02:43:54.8950346Z WARNING  asyncio:base_events.py:1982 Executing <Task finished name='Task-15959' coro=<BaseModule._setup() done, defined at /home/runner/work/bbot/bbot/bbot/modules/base.py:536> result=(<bbot.modules...x7fbeb7e04d10>, True, 'success') created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/tasks.py:420> took 0.245 seconds
2024-07-23T02:43:54.8953582Z DEBUG    bbot.modules.httpx:base.py:1234 Setting up module httpx
2024-07-23T02:43:54.8963569Z DEBUG    bbot.modules.httpx:base.py:1234 Finished setting up module httpx
2024-07-23T02:43:54.8972365Z DEBUG    bbot.modules.nuclei:base.py:1234 Setting up module nuclei
2024-07-23T02:43:54.8976249Z INFO     bbot.modules.nuclei:base.py:1282 Updating Nuclei templates
2024-07-23T02:43:54.8981319Z HUGEVERBOSE bbot.core.helpers.command:logger.py:132 run: nuclei -update-template-dir /tmp/.bbot_test/tools/nuclei-templates -update-templates
2024-07-23T02:43:54.9003000Z DEBUG    asyncio:base_events.py:1679 execute program 'nuclei' stdout=<pipe> stderr=<pipe>
2024-07-23T02:43:54.9021675Z DEBUG    asyncio:base_subprocess.py:50 process 'nuclei' created: pid 20559
2024-07-23T02:43:54.9037546Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Setting up module excavate
2024-07-23T02:43:54.9039661Z [DBUG] internal.excavate: Setting up module excavate
2024-07-23T02:43:54.9263144Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule CSPExtractor
2024-07-23T02:43:54.9265563Z [DBUG] internal.excavate: Including Submodule CSPExtractor
2024-07-23T02:43:54.9269889Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule EmailExtractor
2024-07-23T02:43:54.9275368Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule ErrorExtractor
2024-07-23T02:43:54.9279696Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule FunctionalityExtractor
2024-07-23T02:43:54.9284387Z [DBUG] internal.excavate: Including Submodule EmailExtractor
2024-07-23T02:43:54.9288621Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule HostnameExtractor
2024-07-23T02:43:54.9296801Z [DBUG] internal.excavate: Including Submodule ErrorExtractor
2024-07-23T02:43:54.9298126Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule JWTExtractor
2024-07-23T02:43:54.9300640Z [DBUG] internal.excavate: Including Submodule FunctionalityExtractor
2024-07-23T02:43:54.9305196Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule NonHttpSchemeExtractor
2024-07-23T02:43:54.9318758Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule ParameterExtractor
2024-07-23T02:43:54.9325143Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Parameter Extraction disabled because no modules consume WEB_PARAMETER events
2024-07-23T02:43:54.9328204Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule SerializationExtractor
2024-07-23T02:43:54.9333319Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Including Submodule URLExtractor
2024-07-23T02:43:54.9426441Z DEBUG    bbot.modules.internal.excavate:base.py:1234 Finished setting up module excavate
2024-07-23T02:43:54.9433998Z DEBUG    bbot.modules.output.python:base.py:1234 Setting up module python
2024-07-23T02:43:54.9435940Z DEBUG    bbot.modules.output.python:base.py:1234 Finished setting up module python
2024-07-23T02:43:54.9447717Z DEBUG    bbot.modules._scan_egress:base.py:1234 Setting up module _scan_egress
2024-07-23T02:43:54.9451407Z DEBUG    bbot.modules._scan_egress:base.py:1234 Finished setting up module _scan_egress
2024-07-23T02:43:54.9488128Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for dnsresolve (success)
2024-07-23T02:43:54.9489478Z [DBUG] Setup succeeded for dnsresolve (success)
2024-07-23T02:43:54.9494951Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for httpx (success)
2024-07-23T02:43:54.9501495Z [DBUG] Setup succeeded for httpx (success)
2024-07-23T02:43:54.9502485Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for python (success)
2024-07-23T02:43:54.9507154Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for _scan_ingress (success)
2024-07-23T02:43:54.9510787Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for excavate (success)
2024-07-23T02:43:54.9516069Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for _scan_egress (success)
2024-07-23T02:43:54.9539766Z DEBUG    asyncio:base_events.py:1648 Read pipe 196 connected: (<_UnixReadPipeTransport fd=196 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=196 polling>>)
2024-07-23T02:43:54.9558422Z DEBUG    asyncio:base_events.py:1648 Read pipe 211 connected: (<_UnixReadPipeTransport fd=211 polling>, <ReadSubprocessPipeProto fd=2 pipe=<_UnixReadPipeTransport fd=211 polling>>)
2024-07-23T02:43:54.9570592Z INFO     asyncio:base_events.py:1748 execute program 'nuclei': <_UnixSubprocessTransport pid=20559 running stdout=<_UnixReadPipeTransport fd=196 polling> stderr=<_UnixReadPipeTransport fd=211 polling>>
2024-07-23T02:43:54.9623205Z DEBUG    asyncio:subprocess.py:180 <Process 20559> communicate: read stdout
2024-07-23T02:43:54.9633899Z DEBUG    asyncio:subprocess.py:180 <Process 20559> communicate: read stderr
2024-07-23T02:43:55.7227043Z INFO     asyncio:unix_events.py:535 <_UnixReadPipeTransport fd=211 polling> was closed by peer
2024-07-23T02:43:55.7238515Z INFO     asyncio:unix_events.py:535 <_UnixReadPipeTransport fd=196 polling> was closed by peer
2024-07-23T02:43:55.7255484Z INFO     asyncio:base_subprocess.py:211 <_UnixSubprocessTransport pid=20559 running stdout=<_UnixReadPipeTransport closed fd=196 closed> stderr=<_UnixReadPipeTransport closed fd=211 closed>> exited with return code 0
2024-07-23T02:43:55.7267243Z DEBUG    asyncio:subprocess.py:184 <Process 20559> communicate: close stderr
2024-07-23T02:43:55.7274863Z DEBUG    asyncio:subprocess.py:184 <Process 20559> communicate: close stdout
2024-07-23T02:43:55.7284469Z INFO     bbot.modules.nuclei:base.py:1282 Nuclei templates already up-to-date
2024-07-23T02:43:55.7300900Z INFO     bbot.modules.nuclei:base.py:1282 Setting the following nuclei tags: [musictraveler]
2024-07-23T02:43:55.7310355Z INFO     bbot.modules.nuclei:base.py:1282 Running nuclei in MANUAL mode. Settings will be passed directly into nuclei with no modification
2024-07-23T02:43:55.7312502Z DEBUG    bbot.modules.nuclei:base.py:1234 Finished setting up module nuclei
2024-07-23T02:43:55.7322284Z DEBUG    bbot.scanner:scanner.py:1020 Setup succeeded for nuclei (success)
2024-07-23T02:43:55.7329034Z DEBUG    bbot.scanner:scanner.py:1020 Setting intercept module dnsresolve._incoming_event_queue to previous intercept module _scan_ingress.outgoing_event_queue
2024-07-23T02:43:55.7332228Z DEBUG    bbot.scanner:scanner.py:1020 Setting intercept module _scan_egress._incoming_event_queue to previous intercept module dnsresolve.outgoing_event_queue
2024-07-23T02:43:55.7334952Z SUCCESS  bbot.scanner:logger.py:132 Setup succeeded for 7/7 modules.
2024-07-23T02:43:55.7337840Z DEBUG    bbot:base.py:113 Executing setup_after_prep()
2024-07-23T02:43:55.7342083Z DEBUG    bbot:base.py:115 Starting scan
2024-07-23T02:43:55.7372303Z TRACE    bbot.scanner:logger.py:132 Ran BBOT v0.0.0 at 2024-07-23 02:43:55.734301, command: /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/bin/pytest --exitfirst --reruns 2 -o timeout_func_only=true --timeout 1200 --disable-warnings --log-cli-level=DEBUG --cov-config=bbot/test/coverage.cfg --cov-report xml:cov.xml --cov=bbot .
2024-07-23T02:43:55.7376471Z TRACE    bbot.scanner:logger.py:132 Target: {'seeds': ['http://127.0.0.1:8888/'], 'whitelist': ['127.0.0.1'], 'blacklist': [], 'strict_scope': False, 'hash': '3edaf4e35c65ed04d8af23d2e696081c46698362', 'seed_hash': '739b2352ef4230bd474bb11e9e23b5235f36c193', 'whitelist_hash': '306f9dee732268504604f53a55c1fdbf7949b3f7', 'blacklist_hash': 'da39a3ee5e6b4b0d3255bfef95601890afd80709', 'scope_hash': '82d01722ef215f063844f17caf5012b49db106e9'}
2024-07-23T02:43:55.7768680Z TRACE    bbot.scanner:logger.py:132 Preset: {'config': {'home': '/tmp/.bbot_test', 'keep_scans': 20, 'status_frequency': 15, 'file_blobs': False, 'folder_blobs': False, 'scope': {'report_distance': 0, 'search_distance': 0}, 'dns': {'disable': False, 'minimal': True, 'threads': 20, 'brute_threads': 1000, 'search_distance': 1, 'runaway_limit': 5, 'timeout': 1, 'retries': 1, 'wildcard_disable': False, 'wildcard_ignore': ['blacklanternsecurity.com', 'fakedomain', 'notreal', 'google', 'google.com', 'example.com', 'evilcorp.com', 'one'], 'wildcard_tests': 10, 'abort_threshold': 50, 'filter_ptrs': True, 'debug': False, 'omit_queries': ['SRV:mail.protection.outlook.com', 'CNAME:mail.protection.outlook.com', 'TXT:mail.protection.outlook.com']}, 'web': {'http_proxy': None, 'user_agent': 'BBOT Test User-Agent', 'spider_distance': 0, 'spider_depth': 1, 'spider_links_per_page': 25, 'http_timeout': 10, 'httpx_timeout': 5, 'http_headers': {'test': 'header'}, 'http_retries': 1, 'httpx_retries': 1, 'debug': False, 'http_max_redirects': 5, 'ssl_verify': False}, 'deps': {'ffuf': {'version': '2.1.0'}}, 'module_paths': [], 'speculate': False, 'excavate': True, 'aggregate': False, 'dnsresolve': True, 'cloudcheck': False, 'deps_behavior': 'abort_on_failure', 'url_querystring_remove': True, 'url_querystring_collapse': True, 'url_extension_blacklist': ['png', 'jpg', 'bmp', 'ico', 'jpeg', 'gif', 'svg', 'webp', 'css', 'woff', 'woff2', 'ttf', 'eot', 'sass', 'scss', 'mp3', 'm4a', 'wav', 'flac', 'mp4', 'mkv', 'avi', 'wmv', 'mov', 'flv', 'webm'], 'url_extension_httpx_only': ['js'], 'omit_event_types': [], 'interactsh_server': None, 'interactsh_disable': True, 'modules': {'massdns': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/deepmagic.com-prefixes-top500.txt'}, 'ffuf': {'prefix_busting': True, 'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/Web-Content/raft-small-directories.txt', 'lines': 5000, 'max_depth': 0, 'extensions': ''}, 'http': {'url': '', 'bearer': '', 'method': 'POST', 'timeout': 10, 'siem_friendly': False}, 'websocket': {'url': '', 'preserve_graph': True}, 'neo4j': {'uri': 'bolt://localhost:7687'}, 'asn': {}, 'affiliates': {}, 'dastardly': {}, 'vhost': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'force_basehost': '', 'lines': 5000}, 'nuclei': {'version': '3.2.0', 'tags': 'musictraveler', 'templates': '', 'severity': '', 'ratelimit': 150, 'concurrency': 25, 'mode': 'manual', 'etags': '', 'budget': 1, 'silent': False, 'directory_only': True, 'retries': 1, 'batch_size': 200}, 'anubisdb': {'limit': 1000}, 'gitlab': {}, 'trufflehog': {'version': '3.75.1', 'only_verified': True, 'concurrency': 8}, 'httpx': {'threads': 50, 'in_scope_only': True, 'version': '1.2.5', 'max_response_size': 5242880, 'store_responses': False, 'probe_all_ips': False}, 'chaos': {}, 'threatminer': {}, 'shodan_dns': {}, 'bucket_google': {'permutations': False}, 'crt': {}, 'git': {}, 'bucket_azure': {'permutations': False}, 'docker_pull': {'all_tags': False, 'output_folder': ''}, 'sitedossier': {}, 'portscan': {'top_ports': 100, 'ports': '', 'rate': 300, 'wait': 5, 'ping_first': False, 'ping_only': False, 'adapter': '', 'adapter_ip': '', 'adapter_mac': '', 'router_mac': ''}, 'ntlm': {'try_all': False}, 'smuggler': {}, 'dehashed': {}, 'newsletters': {}, 'hackertarget': {}, 'bucket_digitalocean': {'permutations': False}, 'hunt': {}, 'git_clone': {'output_folder': ''}, 'wayback': {'urls': False, 'garbage_threshold': 10}, 'wappalyzer': {}, 'url_manipulation': {'allow_redirects': True}, 'rapiddns': {}, 'ipstack': {}, 'c99': {}, 'censys': {'max_pages': 5}, 'leakix': {}, 'emailformat': {}, 'paramminer_getparams': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'badsecrets': {}, 'bucket_amazon': {'permutations': False}, 'ffuf_shortnames': {'wordlist': '', 'wordlist_extensions': '', 'lines': 1000000, 'max_depth': 1, 'version': '2.0.0', 'extensions': '', 'ignore_redirects': True, 'find_common_prefixes': False, 'find_delimiters': True}, 'hunterio': {}, 'dockerhub': {}, 'binaryedge': {'max_records': 1000}, 'subdomaincenter': {}, 'wafw00f': {'generic_detect': True}, 'github_org': {'include_members': True, 'include_member_repos': False}, 'riddler': {}, 'crobat': {}, 'otx': {}, 'telerik': {'exploit_RAU_crypto': False}, 'credshed': {'credshed_url': ''}, 'iis_shortnames': {'detect_only': True, 'max_node_count': 50}, 'baddns': {'custom_nameservers': [], 'only_high_confidence': False, 'enable_references': False}, 'sublist3r': {}, 'virustotal': {}, 'columbus': {}, 'dnscaa': {'in_scope_only': True, 'dns_names': True, 'emails': True, 'urls': True}, 'generic_ssrf': {}, 'certspotter': {}, 'github_codesearch': {'limit': 100}, 'azure_realm': {}, 'dnscommonsrv': {'max_depth': 2}, 'myssl': {}, 'pgp': {'search_urls': ['https://keyserver.ubuntu.com/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'http://the.earth.li:11371/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'https://pgpkeys.eu/pks/lookup?search=<query>&op=index', 'https://pgp.mit.edu/pks/lookup?search=<query>&op=index']}, 'wpscan': {'enumerate': 'vp,vt,tt,cb,dbe,u,m', 'threads': 5, 'request_timeout': 60, 'connection_timeout': 30, 'disable_tls_checks': True, 'force': False}, 'gowitness': {'version': '2.4.2', 'threads': 0, 'timeout': 10, 'resolution_x': 1440, 'resolution_y': 900, 'output_path': '', 'social': False, 'idle_timeout': 1800}, 'social': {}, 'dnsdumpster': {}, 'viewdns': {}, 'bucket_file_enum': {'file_limit': 50}, 'github_workflows': {'num_logs': 1}, 'securitytrails': {}, 'oauth': {'try_all': False}, 'internetdb': {'show_open_ports': False}, 'bucket_firebase': {'permutations': False}, 'host_header': {}, 'baddns_zone': {'custom_nameservers': [], 'only_high_confidence': False}, 'code_repository': {}, 'azure_tenant': {}, 'ip2location': {'lang': ''}, 'bypass403': {}, 'fullhunt': {}, 'dnsbrute': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'max_depth': 5}, 'secretsdb': {'min_confidence': 99, 'signatures': 'https://raw.githubusercontent.com/blacklanternsecurity/secrets-patterns-db/master/db/rules-stable.yml'}, 'zoomeye': {'max_pages': 20, 'include_related': False}, 'robots': {'include_sitemap': False, 'include_allow': True, 'include_disallow': True}, 'paramminer_headers': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'ipneighbor': {'num_bits': 4}, 'unstructured': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'ica', 'indd', 'ini', 'key', 'pub', 'log', 'markdown', 'md', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'ignore_folders': ['.git']}, 'postman': {}, 'sslcert': {'timeout': 5.0, 'skip_non_ssl': True}, 'filedownload': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'exe', 'ica', 'indd', 'ini', 'jar', 'key', 'pub', 'log', 'markdown', 'md', 'msi', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'raw', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'tar', 'tar.gz', 'zip', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'max_filesize': '10MB', 'base_64_encoded_file': 'false'}, 'ajaxpro': {}, 'dnsbrute_mutations': {'max_mutations': 100}, 'dotnetnuke': {}, 'digitorus': {}, 'skymem': {}, 'passivetotal': {}, 'builtwith': {'redirects': True}, 'urlscan': {'urls': False}, 'bevigil': {'urls': False}, 'paramminer_cookies': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'fingerprintx': {'version': '1.1.4', 'skip_common_web': True}, 'speculate': {'max_hosts': 65536, 'ports': '80,443'}, 'excavate': {'retain_querystring': False, 'yara_max_match_data': 2000, 'custom_yara_rules': ''}, 'cloudcheck': {}, 'dnsresolve': {}, 'aggregate': {}, 'discord': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'slack': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'splunk': {'url': '', 'index': '', 'source': '', 'timeout': 10}, 'teams': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'subdomains': {'output_file': '', 'include_unresolved': False}, 'emails': {'output_file': ''}, 'txt': {'output_file': ''}, 'web_report': {'output_file': '', 'css_theme_file': 'https://cdnjs.cloudflare.com/ajax/libs/github-markdown-css/5.1.0/github-markdown.min.css'}, 'python': {}, 'csv': {'output_file': ''}, 'stdout': {'format': 'text', 'event_types': [], 'event_fields': [], 'in_scope_only': False, 'accept_dupes': True}, 'json': {'output_file': '', 'siem_friendly': False}, 'asset_inventory': {'output_file': '', 'use_previous': False, 'recheck': False, 'summary_netmask': 16}, 'testmodule1': {}, 'testmodule3': {}, 'testmodule4': {}, 'testmodule2': {}}, 'agent_url': 'ws://127.0.0.1:8765', 'debug': True}, 'modules': ['httpx', 'nuclei'], 'output_modules': ['python'], 'scan_name': 'testnucleiretriescustom_test_s9z2esnwkq', 'output_dir': None}
2024-07-23T02:43:55.7835363Z [TRCE] Preset: {'config': {'home': '/tmp/.bbot_test', 'keep_scans': 20, 'status_frequency': 15, 'file_blobs': False, 'folder_blobs': False, 'scope': {'report_distance': 0, 'search_distance': 0}, 'dns': {'disable': False, 'minimal': True, 'threads': 20, 'brute_threads': 1000, 'search_distance': 1, 'runaway_limit': 5, 'timeout': 1, 'retries': 1, 'wildcard_disable': False, 'wildcard_ignore': ['blacklanternsecurity.com', 'fakedomain', 'notreal', 'google', 'google.com', 'example.com', 'evilcorp.com', 'one'], 'wildcard_tests': 10, 'abort_threshold': 50, 'filter_ptrs': True, 'debug': False, 'omit_queries': ['SRV:mail.protection.outlook.com', 'CNAME:mail.protection.outlook.com', 'TXT:mail.protection.outlook.com']}, 'web': {'http_proxy': None, 'user_agent': 'BBOT Test User-Agent', 'spider_distance': 0, 'spider_depth': 1, 'spider_links_per_page': 25, 'http_timeout': 10, 'httpx_timeout': 5, 'http_headers': {'test': 'header'}, 'http_retries': 1, 'httpx_retries': 1, 'debug': False, 'http_max_redirects': 5, 'ssl_verify': False}, 'deps': {'ffuf': {'version': '2.1.0'}}, 'module_paths': [], 'speculate': False, 'excavate': True, 'aggregate': False, 'dnsresolve': True, 'cloudcheck': False, 'deps_behavior': 'abort_on_failure', 'url_querystring_remove': True, 'url_querystring_collapse': True, 'url_extension_blacklist': ['png', 'jpg', 'bmp', 'ico', 'jpeg', 'gif', 'svg', 'webp', 'css', 'woff', 'woff2', 'ttf', 'eot', 'sass', 'scss', 'mp3', 'm4a', 'wav', 'flac', 'mp4', 'mkv', 'avi', 'wmv', 'mov', 'flv', 'webm'], 'url_extension_httpx_only': ['js'], 'omit_event_types': [], 'interactsh_server': None, 'interactsh_disable': True, 'modules': {'massdns': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/deepmagic.com-prefixes-top500.txt'}, 'ffuf': {'prefix_busting': True, 'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/Web-Content/raft-small-directories.txt', 'lines': 5000, 'max_depth': 0, 'extensions': ''}, 'http': {'url': '', 'bearer': '', 'method': 'POST', 'timeout': 10, 'siem_friendly': False}, 'websocket': {'url': '', 'preserve_graph': True}, 'neo4j': {'uri': 'bolt://localhost:7687'}, 'asn': {}, 'affiliates': {}, 'dastardly': {}, 'vhost': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'force_basehost': '', 'lines': 5000}, 'nuclei': {'version': '3.2.0', 'tags': 'musictraveler', 'templates': '', 'severity': '', 'ratelimit': 150, 'concurrency': 25, 'mode': 'manual', 'etags': '', 'budget': 1, 'silent': False, 'directory_only': True, 'retries': 1, 'batch_size': 200}, 'anubisdb': {'limit': 1000}, 'gitlab': {}, 'trufflehog': {'version': '3.75.1', 'only_verified': True, 'concurrency': 8}, 'httpx': {'threads': 50, 'in_scope_only': True, 'version': '1.2.5', 'max_response_size': 5242880, 'store_responses': False, 'probe_all_ips': False}, 'chaos': {}, 'threatminer': {}, 'shodan_dns': {}, 'bucket_google': {'permutations': False}, 'crt': {}, 'git': {}, 'bucket_azure': {'permutations': False}, 'docker_pull': {'all_tags': False, 'output_folder': ''}, 'sitedossier': {}, 'portscan': {'top_ports': 100, 'ports': '', 'rate': 300, 'wait': 5, 'ping_first': False, 'ping_only': False, 'adapter': '', 'adapter_ip': '', 'adapter_mac': '', 'router_mac': ''}, 'ntlm': {'try_all': False}, 'smuggler': {}, 'dehashed': {}, 'newsletters': {}, 'hackertarget': {}, 'bucket_digitalocean': {'permutations': False}, 'hunt': {}, 'git_clone': {'output_folder': ''}, 'wayback': {'urls': False, 'garbage_threshold': 10}, 'wappalyzer': {}, 'url_manipulation': {'allow_redirects': True}, 'rapiddns': {}, 'ipstack': {}, 'c99': {}, 'censys': {'max_pages': 5}, 'leakix': {}, 'emailformat': {}, 'paramminer_getparams': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'badsecrets': {}, 'bucket_amazon': {'permutations': False}, 'ffuf_shortnames': {'wordlist': '', 'wordlist_extensions': '', 'lines': 1000000, 'max_depth': 1, 'version': '2.0.0', 'extensions': '', 'ignore_redirects': True, 'find_common_prefixes': False, 'find_delimiters': True}, 'hunterio': {}, 'dockerhub': {}, 'binaryedge': {'max_records': 1000}, 'subdomaincenter': {}, 'wafw00f': {'generic_detect': True}, 'github_org': {'include_members': True, 'include_member_repos': False}, 'riddler': {}, 'crobat': {}, 'otx': {}, 'telerik': {'exploit_RAU_crypto': False}, 'credshed': {'credshed_url': ''}, 'iis_shortnames': {'detect_only': True, 'max_node_count': 50}, 'baddns': {'custom_nameservers': [], 'only_high_confidence': False, 'enable_references': False}, 'sublist3r': {}, 'virustotal': {}, 'columbus': {}, 'dnscaa': {'in_scope_only': True, 'dns_names': True, 'emails': True, 'urls': True}, 'generic_ssrf': {}, 'certspotter': {}, 'github_codesearch': {'limit': 100}, 'azure_realm': {}, 'dnscommonsrv': {'max_depth': 2}, 'myssl': {}, 'pgp': {'search_urls': ['https://keyserver.ubuntu.com/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'http://the.earth.li:11371/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'https://pgpkeys.eu/pks/lookup?search=<query>&op=index', 'https://pgp.mit.edu/pks/lookup?search=<query>&op=index']}, 'wpscan': {'enumerate': 'vp,vt,tt,cb,dbe,u,m', 'threads': 5, 'request_timeout': 60, 'connection_timeout': 30, 'disable_tls_checks': True, 'force': False}, 'gowitness': {'version': '2.4.2', 'threads': 0, 'timeout': 10, 'resolution_x': 1440, 'resolution_y': 900, 'output_path': '', 'social': False, 'idle_timeout': 1800}, 'social': {}, 'dnsdumpster': {}, 'viewdns': {}, 'bucket_file_enum': {'file_limit': 50}, 'github_workflows': {'num_logs': 1}, 'securitytrails': {}, 'oauth': {'try_all': False}, 'internetdb': {'show_open_ports': False}, 'bucket_firebase': {'permutations': False}, 'host_header': {}, 'baddns_zone': {'custom_nameservers': [], 'only_high_confidence': False}, 'code_repository': {}, 'azure_tenant': {}, 'ip2location': {'lang': ''}, 'bypass403': {}, 'fullhunt': {}, 'dnsbrute': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'max_depth': 5}, 'secretsdb': {'min_confidence': 99, 'signatures': 'https://raw.githubusercontent.com/blacklanternsecurity/secrets-patterns-db/master/db/rules-stable.yml'}, 'zoomeye': {'max_pages': 20, 'include_related': False}, 'robots': {'include_sitemap': False, 'include_allow': True, 'include_disallow': True}, 'paramminer_headers': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'ipneighbor': {'num_bits': 4}, 'unstructured': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'ica', 'indd', 'ini', 'key', 'pub', 'log', 'markdown', 'md', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'ignore_folders': ['.git']}, 'postman': {}, 'sslcert': {'timeout': 5.0, 'skip_non_ssl': True}, 'filedownload': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'exe', 'ica', 'indd', 'ini', 'jar', 'key', 'pub', 'log', 'markdown', 'md', 'msi', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'raw', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'tar', 'tar.gz', 'zip', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'max_filesize': '10MB', 'base_64_encoded_file': 'false'}, 'ajaxpro': {}, 'dnsbrute_mutations': {'max_mutations': 100}, 'dotnetnuke': {}, 'digitorus': {}, 'skymem': {}, 'passivetotal': {}, 'builtwith': {'redirects': True}, 'urlscan': {'urls': False}, 'bevigil': {'urls': False}, 'paramminer_cookies': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'fingerprintx': {'version': '1.1.4', 'skip_common_web': True}, 'speculate': {'max_hosts': 65536, 'ports': '80,443'}, 'excavate': {'retain_querystring': False, 'yara_max_match_data': 2000, 'custom_yara_rules': ''}, 'cloudcheck': {}, 'dnsresolve': {}, 'aggregate': {}, 'discord': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'slack': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'splunk': {'url': '', 'index': '', 'source': '', 'timeout': 10}, 'teams': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'subdomains': {'output_file': '', 'include_unresolved': False}, 'emails': {'output_file': ''}, 'txt': {'output_file': ''}, 'web_report': {'output_file': '', 'css_theme_file': 'https://cdnjs.cloudflare.com/ajax/libs/github-markdown-css/5.1.0/github-markdown.min.css'}, 'python': {}, 'csv': {'output_file': ''}, 'stdout': {'format': 'text', 'event_types': [], 'event_fields': [], 'in_scope_only': False, 'accept_dupes': True}, 'json': {'output_file': '', 'siem_friendly': False}, 'asset_inventory': {'output_file': '', 'use_previous': False, 'recheck': False, 'summary_netmask': 16}, 'testmodule1': {}, 'testmodule3': {}, 'testmodule4': {}, 'testmodule2': {}}, 'agent_url': 'ws://127.0.0.1:8765', 'debug': True}, 'modules': ['httpx', 'nuclei'], 'output_modules': ['python'], 'scan_name': 'testnucleiretriescustom_test_s9z2esnwkq', 'output_dir': None}
2024-07-23T02:43:55.7866362Z HUGESUCCESS bbot.scanner:logger.py:132 Starting scan testnucleiretriescustom_test_s9z2esnwkq
2024-07-23T02:43:55.7867418Z VERBOSE  bbot.scanner:logger.py:132 Starting module worker loops
2024-07-23T02:43:56.0358572Z VERBOSE  bbot.scanner:logger.py:132 7 modules started
2024-07-23T02:43:56.0382462Z WARNING  asyncio:base_events.py:1982 Executing <Task pending name='Task-15955' coro=<_wrap_asyncgen_fixture.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.12/lib/python3.12/site-packages/pytest_asyncio/plugin.py:329> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:449> cb=[_run_until_complete_cb() at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:182] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/tasks.py:695> took 0.306 seconds
2024-07-23T02:43:56.0392918Z DEBUG    bbot.scanner:scanner.py:1020 Setting scan status to STARTING
2024-07-23T02:43:56.0396417Z DEBUG    bbot.scanner:scanner.py:1020 Setting scan status to RUNNING
2024-07-23T02:43:56.1269975Z VERBOSE  bbot.modules._scan_ingress:logger.py:132 Target: SCAN("{'id': 'SCAN:a6e14e25ecbcbe51ba7c87fe4eef36a66b1dd3ba', 'name': 'testnucleiretri...", module=TARGET, tags={'in-scope', 'target'})
2024-07-23T02:43:56.1975255Z VERBOSE  bbot.modules._scan_ingress:logger.py:132 Target: URL_UNVERIFIED("http://127.0.0.1:8888/", module=TARGET, tags={'dir', 'target', 'distance-1'})
2024-07-23T02:43:56.1995105Z WARNING  asyncio:base_events.py:1982 Executing <Task pending name='Task-16005' coro=<ScanIngress.init_events() running at /home/runner/work/bbot/bbot/bbot/scanner/manager.py:62> wait_for=<Future pending cb=[Task.task_wakeup()] created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/base_events.py:449> created at /opt/hostedtoolcache/Python/3.12.4/x64/lib/python3.12/asyncio/tasks.py:420> took 0.142 seconds
2024-07-23T02:43:56.2017136Z DEBUG    bbot.modules._scan_ingress:base.py:1234 Got SCAN("{'id': 'SCAN:a6e14e25ecbcbe51ba7c87fe4eef36a66b1dd3ba', 'name': 'testnucleiretri...", module=TARGET, tags={'in-scope', 'target'}) from TARGET
2024-07-23T02:43:56.2089812Z ##[error]The operation was canceled.
TheTechromancer commented 1 month ago

3.9

DEBUG    bbot.core.httpengine:engine.py:453 EngineServer HTTPEngine got message: {'c': 0, 'k': {'url': 'https://blacklanternsecurity.fakedomain:1234/events', 'method': 'PUT', 'auth': ('bbot_user', 'bbot_password'), 'headers': {'Authorization': 'Bearer auth_token'}, 'json': {'type': 'SCAN', 'id': 'SCAN:9281053be78e9279c8c2f579e424a856f44713d9', 'scope_description': 'in-scope', 'data': {'SCAN': {'id': 'SCAN:9281053be78e9279c8c2f579e424a856f44713d9', 'name': 'testhttpsiemfriendly_test_hmauismly7', 'target': {'seeds': ['blacklanternsecurity.com'], 'whitelist': ['blacklanternsecurity.com'], 'blacklist': [], 'strict_scope': False, 'hash': 'cffefd70a4eac5b8389a3c16987fb2ae91328c4c', 'seed_hash': '29b7be19a3f7633571a48c40f320d465c918c26b', 'whitelist_hash': '29b7be19a3f7633571a48c40f320d465c918c26b', 'blacklist_hash': 'da39a3ee5e6b4b0d3255bfef95601890afd80709', 'scope_hash': 'ef4a64d445f60a4ae47d81411d8994e40c3382d1'}, 'preset': {'config': {'home': '/tmp/.bbot_test', 'keep_scans': 20, 'status_frequency': 15, 'file_blobs': False, 'folder_blobs': False, 'scope': {'report_distance': 0, 'search_distance': 0}, 'dns': {'disable': False, 'minimal': True, 'threads': 20, 'brute_threads': 1000, 'search_distance': 1, 'runaway_limit': 5, 'timeout': 1, 'retries': 1, 'wildcard_disable': False, 'wildcard_ignore': ['blacklanternsecurity.com', 'fakedomain', 'notreal', 'google', 'google.com', 'example.com', 'evilcorp.com', 'one'], 'wildcard_tests': 10, 'abort_threshold': 50, 'filter_ptrs': True, 'debug': False, 'omit_queries': ['SRV:mail.protection.outlook.com', 'CNAME:mail.protection.outlook.com', 'TXT:mail.protection.outlook.com']}, 'web': {'http_proxy': None, 'user_agent': 'BBOT Test User-Agent', 'spider_distance': 0, 'spider_depth': 1, 'spider_links_per_page': 25, 'http_timeout': 10, 'httpx_timeout': 5, 'http_headers': {'test': 'header'}, 'http_retries': 1, 'httpx_retries': 1, 'debug': False, 'http_max_redirects': 5, 'ssl_verify': False}, 'deps': {'ffuf': {'version': '2.1.0'}}, 'module_paths': [], 'speculate': False, 'excavate': False, 'aggregate': False, 'dnsresolve': True, 'cloudcheck': False, 'deps_behavior': 'abort_on_failure', 'url_querystring_remove': True, 'url_querystring_collapse': True, 'url_extension_blacklist': ['png', 'jpg', 'bmp', 'ico', 'jpeg', 'gif', 'svg', 'webp', 'css', 'woff', 'woff2', 'ttf', 'eot', 'sass', 'scss', 'mp3', 'm4a', 'wav', 'flac', 'mp4', 'mkv', 'avi', 'wmv', 'mov', 'flv', 'webm'], 'url_extension_httpx_only': ['js'], 'omit_event_types': [], 'interactsh_server': None, 'interactsh_disable': False, 'modules': {'massdns': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/deepmagic.com-prefixes-top500.txt'}, 'ffuf': {'prefix_busting': True, 'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/Web-Content/raft-small-directories.txt', 'lines': 5000, 'max_depth': 0, 'extensions': ''}, 'http': {'url': 'https://blacklanternsecurity.fakedomain:1234/events', 'bearer': 'auth_token', 'method': 'PUT', 'timeout': 10, 'siem_friendly': True}, 'websocket': {'url': '', 'preserve_graph': True}, 'neo4j': {'uri': 'bolt://localhost:7687'}, 'slack': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'stdout': {'format': 'text', 'event_types': [], 'event_fields': [], 'in_scope_only': False, 'accept_dupes': True}, 'teams': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'discord': {'webhook_url': '', 'event_types': ['VULNERABILITY', 'FINDING'], 'min_severity': 'LOW'}, 'subdomains': {'output_file': '', 'include_unresolved': False}, 'emails': {'output_file': ''}, 'txt': {'output_file': ''}, 'json': {'output_file': '', 'siem_friendly': False}, 'python': {}, 'csv': {'output_file': ''}, 'splunk': {'url': '', 'index': '', 'source': '', 'timeout': 10}, 'asset_inventory': {'output_file': '', 'use_previous': False, 'recheck': False, 'summary_netmask': 16}, 'web_report': {'output_file': '', 'css_theme_file': 'https://cdnjs.cloudflare.com/ajax/libs/github-markdown-css/5.1.0/github-markdown.min.css'}, 'vhost': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'force_basehost': '', 'lines': 5000}, 'dastardly': {}, 'nuclei': {'version': '3.2.0', 'tags': '', 'templates': '', 'severity': '', 'ratelimit': 150, 'concurrency': 25, 'mode': 'manual', 'etags': '', 'budget': 1, 'silent': False, 'directory_only': True, 'retries': 0, 'batch_size': 200}, 'aggregate': {}, 'dnsresolve': {}, 'speculate': {'max_hosts': 65536, 'ports': '80,443'}, 'cloudcheck': {}, 'excavate': {'retain_querystring': False, 'yara_max_match_data': 2000, 'custom_yara_rules': ''}, 'sitedossier': {}, 'virustotal': {}, 'smuggler': {}, 'git_clone': {'output_folder': ''}, 'bucket_file_enum': {'file_limit': 50}, 'ip2location': {'lang': ''}, 'wappalyzer': {}, 'ntlm': {'try_all': False}, 'azure_realm': {}, 'bevigil': {'urls': False}, 'dnsbrute_mutations': {'max_mutations': 100}, 'censys': {'max_pages': 5}, 'docker_pull': {'all_tags': False, 'output_folder': ''}, 'fullhunt': {}, 'bypass403': {}, 'trufflehog': {'version': '3.75.1', 'only_verified': True, 'concurrency': 8}, 'chaos': {}, 'dnsdumpster': {}, 'urlscan': {'urls': False}, 'passivetotal': {}, 'github_codesearch': {'limit': 100}, 'portscan': {'top_ports': 100, 'ports': '', 'rate': 300, 'wait': 5, 'ping_first': False, 'ping_only': False, 'adapter': '', 'adapter_ip': '', 'adapter_mac': '', 'router_mac': ''}, 'hunt': {}, 'social': {}, 'oauth': {'try_all': False}, 'pgp': {'search_urls': ['https://keyserver.ubuntu.com/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'http://the.earth.li:11371/pks/lookup?fingerprint=on&op=vindex&search=<query>', 'https://pgpkeys.eu/pks/lookup?search=<query>&op=index', 'https://pgp.mit.edu/pks/lookup?search=<query>&op=index']}, 'dnscommonsrv': {'max_depth': 2}, 'hunterio': {}, 'securitytrails': {}, 'internetdb': {'show_open_ports': False}, 'httpx': {'threads': 50, 'in_scope_only': True, 'version': '1.2.5', 'max_response_size': 5242880, 'store_responses': False, 'probe_all_ips': False}, 'binaryedge': {'max_records': 1000}, 'iis_shortnames': {'detect_only': True, 'max_node_count': 50}, 'bucket_firebase': {'permutations': False}, 'secretsdb': {'min_confidence': 99, 'signatures': 'https://raw.githubusercontent.com/blacklanternsecurity/secrets-patterns-db/master/db/rules-stable.yml'}, 'azure_tenant': {}, 'rapiddns': {}, 'fingerprintx': {'version': '1.1.4', 'skip_common_web': True}, 'anubisdb': {'limit': 1000}, 'ajaxpro': {}, 'hackertarget': {}, 'crobat': {}, 'filedownload': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'exe', 'ica', 'indd', 'ini', 'jar', 'key', 'pub', 'log', 'markdown', 'md', 'msi', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'raw', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'tar', 'tar.gz', 'zip', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'max_filesize': '10MB', 'base_64_encoded_file': 'false'}, 'baddns_zone': {'custom_nameservers': [], 'only_high_confidence': False}, 'badsecrets': {}, 'dnsbrute': {'wordlist': 'https://raw.githubusercontent.com/danielmiessler/SecLists/master/Discovery/DNS/subdomains-top1million-5000.txt', 'max_depth': 5}, 'credshed': {'credshed_url': ''}, 'robots': {'include_sitemap': False, 'include_allow': True, 'include_disallow': True}, 'paramminer_getparams': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'emailformat': {}, 'dehashed': {}, 'dotnetnuke': {}, 'leakix': {}, 'dockerhub': {}, 'skymem': {}, 'ffuf_shortnames': {'wordlist': '', 'wordlist_extensions': '', 'lines': 1000000, 'max_depth': 1, 'version': '2.0.0', 'extensions': '', 'ignore_redirects': True, 'find_common_prefixes': False, 'find_delimiters': True}, 'github_workflows': {'num_logs': 1}, 'wayback': {'urls': False, 'garbage_threshold': 10}, 'c99': {}, 'host_header': {}, 'newsletters': {}, 'url_manipulation': {'allow_redirects': True}, 'gitlab': {}, 'code_repository': {}, 'myssl': {}, 'gowitness': {'version': '2.4.2', 'threads': 0, 'timeout': 10, 'resolution_x': 1440, 'resolution_y': 900, 'output_path': '', 'social': False, 'idle_timeout': 1800}, 'wpscan': {'enumerate': 'vp,vt,tt,cb,dbe,u,m', 'threads': 5, 'request_timeout': 60, 'connection_timeout': 30, 'disable_tls_checks': True, 'force': False}, 'git': {}, 'ipneighbor': {'num_bits': 4}, 'bucket_google': {'permutations': False}, 'digitorus': {}, 'builtwith': {'redirects': True}, 'viewdns': {}, 'bucket_amazon': {'permutations': False}, 'sublist3r': {}, 'paramminer_cookies': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'generic_ssrf': {}, 'certspotter': {}, 'subdomaincenter': {}, 'sslcert': {'timeout': 5.0, 'skip_non_ssl': True}, 'paramminer_headers': {'wordlist': '', 'recycle_words': False, 'skip_boring_words': True}, 'ipstack': {}, 'otx': {}, 'threatminer': {}, 'wafw00f': {'generic_detect': True}, 'crt': {}, 'github_org': {'include_members': True, 'include_member_repos': False}, 'columbus': {}, 'unstructured': {'extensions': ['bak', 'bash', 'bashrc', 'conf', 'cfg', 'crt', 'csv', 'db', 'sqlite', 'doc', 'docx', 'ica', 'indd', 'ini', 'key', 'pub', 'log', 'markdown', 'md', 'odg', 'odp', 'ods', 'odt', 'pdf', 'pem', 'pps', 'ppsx', 'ppt', 'pptx', 'ps1', 'rdp', 'sh', 'sql', 'swp', 'sxw', 'txt', 'vbs', 'wpd', 'xls', 'xlsx', 'xml', 'yml', 'yaml'], 'ignore_folders': ['.git']}, 'shodan_dns': {}, 'bucket_digitalocean': {'permutations': False}, 'telerik': {'exploit_RAU_crypto': False}, 'zoomeye': {'max_pages': 20, 'include_related': False}, 'dnscaa': {'in_scope_only': True, 'dns_names': True, 'emails': True, 'urls': True}, 'bucket_azure': {'permutations': False}, 'postman': {}, 'riddler': {}, 'baddns': {'custom_nameservers': [], 'only_high_confidence': False, 'enable_references': False}, 'asn': {}, 'affiliates': {}, 'testmodule1': {}, 'testmodule2': {}, 'testmodule3': {}, 'testmodule4': {}}, 'agent_url': 'ws://127.0.0.1:8765', 'debug': True}, 'output_modules': ['http', 'python'], 'scan_name': 'testhttpsiemfriendly_test_hmauismly7', 'output_dir': None}}}, 'web_spider_distance': 0, 'scope_distance': 0, 'scan': 'SCAN:9281053be78e9279c8c2f579e424a856f44713d9', 'timestamp': '2024-07-24T18:17:25.999750', 'parent': 'SCAN:9281053be78e9279c8c2f579e424a856f44713d9', 'tags': ['in-scope', 'target'], 'module': 'TARGET', 'module_sequence': 'TARGET', 'discovery_context': 'Scan testhttpsiemfriendly_test_hmauismly7 started at 2024-07-24 18:17:25.999750', 'discovery_path': []}, 'raise_error': True}}
DEBUG    bbot.core.httpengine:engine.py:496 EngineServer HTTPEngine: creating run-and-return coroutine for request()
DEBUG    bbot.core.httpengine:engine.py:499 EngineServer HTTPEngine: creating task for request() coroutine
DEBUG    bbot.core.httpengine:engine.py:502 EngineServer HTTPEngine: finished creating task for request() coroutine
TheTechromancer commented 1 month ago

Another hang during .bake().

I don't think this one had a CPU spike. So this is probably a different bug.

One slightly interesting thing about this traceback is that at least one interactsh poll loop seems to still be active, even though there aren't any in this test. The previous test enabled all modules, and forgot to ._cleanup(). This might have something to do with it.

This one especially is interesting, because it shows the exact moment when the deepcopy froze:

Traceback (most recent call last):
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/main.py", line 271, in wrap_session
    session.exitstatus = doit(config, session) or 0
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/main.py", line 325, in _main
    config.hook.pytest_runtestloop(session=session)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_hooks.py", line 513, in __call__
    return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_manager.py", line 120, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 182, in _multicall
    return outcome.get_result()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_result.py", line 100, in get_result
    raise exc.with_traceback(exc.__traceback__)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 103, in _multicall
    res = hook_impl.function(*args)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/main.py", line 350, in pytest_runtestloop
    item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_hooks.py", line 513, in __call__
    return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_manager.py", line 120, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 182, in _multicall
    return outcome.get_result()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_result.py", line 100, in get_result
    raise exc.with_traceback(exc.__traceback__)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 103, in _multicall
    res = hook_impl.function(*args)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 114, in pytest_runtest_protocol
    runtestprotocol(item, nextitem=nextitem)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 133, in runtestprotocol
    reports.append(call_and_report(item, "call", log))
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 222, in call_and_report
    call = call_runtest_hook(item, when, **kwds)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 261, in call_runtest_hook
    return CallInfo.from_call(
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 341, in from_call
    result: Optional[TResult] = func()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 262, in <lambda>
    lambda: ihook(item=item, **kwds), when=when, reraise=reraise
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_hooks.py", line 513, in __call__
    return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_manager.py", line 120, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 182, in _multicall
    return outcome.get_result()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_result.py", line 100, in get_result
    raise exc.with_traceback(exc.__traceback__)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 103, in _multicall
    res = hook_impl.function(*args)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/runner.py", line 169, in pytest_runtest_call
    item.runtest()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py", line 440, in runtest
    super().runtest()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/python.py", line 1792, in runtest
    self.ihook.pytest_pyfunc_call(pyfuncitem=self)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_hooks.py", line 513, in __call__
    return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_manager.py", line 120, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 182, in _multicall
    return outcome.get_result()
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_result.py", line 100, in get_result
    raise exc.with_traceback(exc.__traceback__)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pluggy/_callers.py", line 103, in _multicall
    res = hook_impl.function(*args)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/_pytest/python.py", line 194, in pytest_pyfunc_call
    result = testfunction(**testargs)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py", line 906, in inner
    _loop.run_until_complete(task)
  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 634, in run_until_complete
    self.run_forever()
  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 601, in run_forever
    self._run_once()
  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1897, in _run_once
    handle._run()
  File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/d_bbot/bbot/test/test_step_1/test_modules_basic.py", line 350, in test_modules_basic_stats
    scan = bbot_scanner(
  File "/d_bbot/bbot/scanner/scanner.py", line 133, in __init__
    self.preset = preset.bake(self)
  File "/d_bbot/bbot/scanner/preset/preset.py", line 387, in bake
    os_environ = baked_preset.environ.prepare()
  File "/d_bbot/bbot/scanner/preset/environ.py", line 89, in prepare
    environ["BBOT_TOOLS"] = str(self.preset.core.tools_dir)
  File "/d_bbot/bbot/core/core.py", line 60, in tools_dir
    return self.home / "tools"
  File "/d_bbot/bbot/core/core.py", line 52, in home
    return Path(self.config["home"]).expanduser().resolve()
  File "/d_bbot/bbot/core/core.py", line 82, in config
    self._config = OmegaConf.merge(self.default_config, self.custom_config)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/omegaconf/omegaconf.py", line 268, in merge
    target = copy.deepcopy(configs[0])
  File "/usr/local/lib/python3.9/copy.py", line 153, in deepcopy
    y = copier(memo)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/omegaconf/dictconfig.py", line 127, in __deepcopy__
    vc = copy.deepcopy(v, memo=memo)
  File "/usr/local/lib/python3.9/copy.py", line 153, in deepcopy
    y = copier(memo)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/omegaconf/dictconfig.py", line 127, in __deepcopy__
    vc = copy.deepcopy(v, memo=memo)
  File "/usr/local/lib/python3.9/copy.py", line 153, in deepcopy
    y = copier(memo)
  File "/root/.cache/pypoetry/virtualenvs/bbot-UrSCVixW-py3.9/lib/python3.9/site-packages/omegaconf/dictconfig.py", line 115, in __deepcopy__
    res.__dict__["_metadata"] = copy.deepcopy(self.__dict__["_metadata"], memo=memo)
  File "/usr/local/lib/python3.9/copy.py", line 172, in deepcopy
    y = _reconstruct(x, memo, *rv)
  File "/usr/local/lib/python3.9/copy.py", line 270, in _reconstruct
    state = deepcopy(state, memo)
  File "/usr/local/lib/python3.9/copy.py", line 146, in deepcopy
    y = copier(x, memo)
  File "/usr/local/lib/python3.9/copy.py", line 230, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
  File "/usr/local/lib/python3.9/copy.py", line 172, in deepcopy
    y = _reconstruct(x, memo, *rv)
  File "/usr/local/lib/python3.9/copy.py", line 263, in _reconstruct
    args = (deepcopy(arg, memo) for arg in args)
KeyboardInterrupt

Very strange.

TheTechromancer commented 1 month ago

3.9

This test run succeeded, but took over an hour:

image

Now check this out:

2024-07-24T22:22:42.4273438Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
2024-07-24T22:22:42.4274946Z ~~~~~~~~~~~~~~~~~~~~~ Stack of Thread-12 (140251034273344) ~~~~~~~~~~~~~~~~~~~~~
2024-07-24T22:22:42.4276848Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2024-07-24T22:22:42.4278140Z     self._bootstrap_inner()
2024-07-24T22:22:42.4279303Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2024-07-24T22:22:42.4280111Z     self.run()
2024-07-24T22:22:42.4280707Z   File "/home/runner/work/bbot/bbot/bbot/core/helpers/process.py", line 27, in run
2024-07-24T22:22:42.4281317Z     super().run()
2024-07-24T22:22:42.4281805Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 917, in run
2024-07-24T22:22:42.4282388Z     self._target(*self._args, **self._kwargs)
2024-07-24T22:22:42.4282977Z   File "/home/runner/work/bbot/bbot/bbot/core/engine.py", line 279, in server_process
2024-07-24T22:22:42.4283524Z     future.result()
2024-07-24T22:22:42.4284116Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/concurrent/futures/_base.py", line 441, in result
2024-07-24T22:22:42.4285040Z     self._condition.wait(timeout)
2024-07-24T22:22:42.4285595Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 312, in wait
2024-07-24T22:22:42.4286135Z     waiter.acquire()
2024-07-24T22:22:42.4286511Z ~~~~~~~~~~~~~~~~~ Stack of QueueFeederThread (140251853559360) ~~~~~~~~~~~~~~~~~
2024-07-24T22:22:42.4287733Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2024-07-24T22:22:42.4288589Z     self._bootstrap_inner()
2024-07-24T22:22:42.4289202Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2024-07-24T22:22:42.4289808Z     self.run()
2024-07-24T22:22:42.4290279Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 917, in run
2024-07-24T22:22:42.4290869Z     self._target(*self._args, **self._kwargs)
2024-07-24T22:22:42.4291532Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/multiprocessing/queues.py", line 231, in _feed
2024-07-24T22:22:42.4292135Z     nwait()
2024-07-24T22:22:42.4292594Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 312, in wait
2024-07-24T22:22:42.4293140Z     waiter.acquire()
2024-07-24T22:22:42.4293594Z ~~~~~~~~~~~~~~~~~~~~~ Stack of Thread-1 (140251892192832) ~~~~~~~~~~~~~~~~~~~~~~
2024-07-24T22:22:42.4294294Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2024-07-24T22:22:42.4294864Z     self._bootstrap_inner()
2024-07-24T22:22:42.4295569Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2024-07-24T22:22:42.4296308Z     self.run()
2024-07-24T22:22:42.4296799Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/threading.py", line 917, in run
2024-07-24T22:22:42.4297644Z     self._target(*self._args, **self._kwargs)
2024-07-24T22:22:42.4298291Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/logging/handlers.py", line 1537, in _monitor
2024-07-24T22:22:42.4298904Z     record = self.dequeue(True)
2024-07-24T22:22:42.4299507Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/logging/handlers.py", line 1486, in dequeue
2024-07-24T22:22:42.4300114Z     return self.queue.get(block)
2024-07-24T22:22:42.4300710Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/multiprocessing/queues.py", line 103, in get
2024-07-24T22:22:42.4301326Z     res = self._recv_bytes()
2024-07-24T22:22:42.4301970Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/multiprocessing/connection.py", line 216, in recv_bytes
2024-07-24T22:22:42.4302647Z     buf = self._recv_bytes(maxlength)
2024-07-24T22:22:42.4303328Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/multiprocessing/connection.py", line 414, in _recv_bytes
2024-07-24T22:22:42.4303991Z     buf = self._recv(4)
2024-07-24T22:22:42.4304583Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/multiprocessing/connection.py", line 379, in _recv
2024-07-24T22:22:42.4305223Z     chunk = read(handle, remaining)
2024-07-24T22:22:42.4305621Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
TheTechromancer commented 1 month ago

The above timeout happened twice during the test. Each time it took 20 minutes, but on the third time somehow it succeeded.

What does this mean? Is this a race condition in the logging library? Maybe. Both stack traces list three threads. One is our server_process thread, one is the logger's QueueFeederThread, and the other is our logging QueueHandler.

Both timeouts look identical. In other words, the three threads died in the exact same place. They were all in an idle state, listening for connections. This doesn't necessarily imply a bug.

What's so strange though is that the test itself fails in two entirely different places:

The first time, it fails during test_dns_raw_records, after this line:

2024-07-24T22:02:41.5245975Z DEBUG    bbot.core.dnsengine:engine.py:502 EngineServer DNSEngine: finished creating task for resolve_raw_batch() coroutine

The second time it fails during test_docs, directly after the previous task, which somehow escaped being destroyed until now:

2024-07-24T22:22:51.0695677Z task: <Task pending name='Task-1917' coro=<test_dns_raw_records() done, defined at /home/runner/work/bbot/bbot/bbot/test/test_step_1/test_dns.py:349> wait_for=<Future finished result=None created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /home/runner/.cache/pypoetry/virtualenvs/bbot-pd-UZ8Fz-py3.9/lib/python3.9/site-packages/pytest_asyncio/plugin.py:904>

Also destroyed at this time:

task: <Task pending name='Task-1928' coro=<Scanner._status_ticker() running at /home/runner/work/bbot/bbot/bbot/scanner/scanner.py:1151> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ed6e0c820>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

task: <Task pending name='Task-1928' coro=<Scanner._status_ticker() running at /home/runner/work/bbot/bbot/bbot/scanner/scanner.py:1151> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ed6e0c820>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

task: <Task pending name='_scan_ingress._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1447> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec3564100>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1437> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33f5910>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

task: <Task pending name='_scan_ingress._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1447> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec3564100>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1437> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33f5910>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1437> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec3542e80>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec34adc10>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33c6640>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33c6b20>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33c6fa0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33fc2e0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33fc430>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1480> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec33fc5e0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1437> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec3542ee0>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>
task: <Task pending name='dnsresolve._worker()' coro=<InterceptModule._worker() running at /home/runner/work/bbot/bbot/bbot/modules/base.py:1437> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f8ec3564070>()] created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py:429> created at /opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/tasks.py:361>

These are followed by a flurry of errors like this:

2024-07-24T22:42:47.3816334Z CRITICAL bbot.modules._scan_ingress:base.py:1411 Traceback (most recent call last):
2024-07-24T22:42:47.3816647Z   File "/home/runner/work/bbot/bbot/bbot/modules/base.py", line 1437, in _worker
2024-07-24T22:42:47.3816784Z     incoming = await self.get_incoming_event()
2024-07-24T22:42:47.3817170Z   File "/home/runner/work/bbot/bbot/bbot/scanner/manager.py", line 153, in get_incoming_event
2024-07-24T22:42:47.3817308Z     raise asyncio.queues.QueueEmpty()
2024-07-24T22:42:47.3817418Z asyncio.queues.QueueEmpty
2024-07-24T22:42:47.3817423Z 
2024-07-24T22:42:47.3817652Z During handling of the above exception, another exception occurred:
2024-07-24T22:42:47.3817657Z 
2024-07-24T22:42:47.3817837Z Traceback (most recent call last):
2024-07-24T22:42:47.3818150Z   File "/home/runner/work/bbot/bbot/bbot/modules/base.py", line 1447, in _worker
2024-07-24T22:42:47.3818279Z     await asyncio.sleep(0.1)
2024-07-24T22:42:47.3818437Z GeneratorExit
2024-07-24T22:42:47.3818445Z 

...

2024-07-24T22:42:47.3821457Z CRITICAL bbot.modules.dnsresolve:base.py:1411 Critical failure in intercept module dnsresolve: Event loop is closed
2024-07-24T22:42:47.3821737Z TRACE    bbot.modules.dnsresolve:base.py:1397 Traceback (most recent call last):
2024-07-24T22:42:47.3822109Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/queues.py", line 166, in get
2024-07-24T22:42:47.3822269Z     await getter
2024-07-24T22:42:47.3822351Z GeneratorExit
2024-07-24T22:42:47.3822356Z 
2024-07-24T22:42:47.3822588Z During handling of the above exception, another exception occurred:
2024-07-24T22:42:47.3822593Z 
2024-07-24T22:42:47.3822709Z Traceback (most recent call last):
2024-07-24T22:42:47.3823022Z   File "/home/runner/work/bbot/bbot/bbot/modules/base.py", line 1437, in _worker
2024-07-24T22:42:47.3823167Z     incoming = await self.get_incoming_event()
2024-07-24T22:42:47.3823533Z   File "/home/runner/work/bbot/bbot/bbot/modules/base.py", line 1508, in get_incoming_event
2024-07-24T22:42:47.3823680Z     return await self.incoming_event_queue.get()
2024-07-24T22:42:47.3824055Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/queues.py", line 168, in get
2024-07-24T22:42:47.3824249Z     getter.cancel()  # Just in case getter is not done yet.
2024-07-24T22:42:47.3824674Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py", line 751, in call_soon
2024-07-24T22:42:47.3824841Z     self._check_closed()
2024-07-24T22:42:47.3825287Z   File "/opt/hostedtoolcache/Python/3.9.19/x64/lib/python3.9/asyncio/base_events.py", line 515, in _check_closed
2024-07-24T22:42:47.3875566Z ##[error]    raise RuntimeError('Event loop is closed')
2024-07-24T22:42:47.3882801Z RuntimeError: Event loop is closed
TheTechromancer commented 1 month ago

If we look back to the place where that scan first froze:

2024-07-24T22:02:41.5245975Z DEBUG    bbot.core.dnsengine:engine.py:502 EngineServer DNSEngine: finished creating task for resolve_raw_batch() coroutine

Does this correlate to any of the tracebacks we see?

After the first few, we see a bunch of Task was destroyed but it is pending! errors for all the modules. The GeneratorExit we keep seeing is just because our async queue is no longer in operation.

Do none of these errors give us a hint as to where the freeze actually happened?

TheTechromancer commented 1 month ago

Okay. I managed to attach to the frozen process while it was running (stuck at 100% CPU), and this is the traceback:

python_traceback.txt

This looks to be a bug in cpython. Issue opened upstream: https://github.com/python/cpython/issues/122296

TheTechromancer commented 1 month ago

Fixed in https://github.com/blacklanternsecurity/bbot/pull/1555.