Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] container timeouts and no dns traffic for website loader #31

Open
GangGreenTemperTatum opened this issue Jan 22, 2025 · 2 comments · May be fixed by #32
Open

[BUG] container timeouts and no dns traffic for website loader #31

GangGreenTemperTatum opened this issue Jan 22, 2025 · 2 comments · May be fixed by #32
Assignees
Labels
bug Something isn't working

Comments

@GangGreenTemperTatum
Copy link
Contributor

GangGreenTemperTatum commented Jan 22, 2025

Bug Description

currently testing, received reports that when testing the website loader the container times out and zero dns traffic to --url is observed

Steps to Reproduce

dyana trace --loader website --url facebook.com <-- times out`

Expected Behavior

we should see all traffic including the dns and container should not timeout

Screenshots

NA see console output

Environment

NA

Additional Context

see #19

Console Output

(dyana-cli-py3.12) ➜  dyana git:(main) dyana trace --loader website --url facebook.com
🐳 loader: initializing loader website
👁️‍🗨️  tracer: initializing ...
👁️‍🗨️  tracer: started ...
🍿 loader: required bridged network access
🍿 loader: executing with arguments ['--url', 'facebook.com'] ...
🍿 loader: timeout reached, killing container
👁️‍🗨️  tracer: stopping ...
🗃  saving 9112 events to trace.json

Platform       : macOS-15.2-arm64-arm-64bit
Loader         : website
Arguments      : facebook.com
Started at     : 2025-01-22T11:41:22.112662
Ended at       : 2025-01-22T11:42:23.262292
Total Events   : 9112

Errors:

  * timeout: timeout reached, killing container


Process Executions:
* 1 python3 -> execve /usr/local/bin/python3 ['python3', '-W', 'ignore', 'main.py', '--url', 'facebook.com']
  * 7 chromedriver -> execve /usr/bin/chromedriver ['/usr/bin/chromedriver', '--port=36433']
    * 15 chrome -> execve /usr/lib/chromium/chrome ['/usr/lib/chromium/chrome', '--allow-pre-commit-input', 
'--disable-background-networking', '--disable-client-side-phishing-detection', '--disable-default-apps', 
'--disable-dev-shm-usage', '--disable-hang-monitor', '--disable-popup-blocking', '--disable-prompt-on-repost', 
'--disable-sync', '--enable-automation', '--enable-logging', '--headless=new', '--log-level=0', '--no-first-run', 
'--no-sandbox', '--no-service-autorun', '--password-store=basic', '--remote-debugging-port=0', '--test-type=webdriver',
'--use-mock-keychain', '--user-data-dir=/tmp/.org.chromium.Chromium.bgkdhe', '--window-size=1920,1080', 'data:,']
      * 25 chromium -> execve /usr/lib/chromium/chromium ['/usr/lib/chromium/chromium', '--type=zygote', 
'--no-zygote-sandbox', '--no-sandbox', '--enable-logging', '--headless=new', '--log-level=0', '--string-annotations', 
'--crashpad-handler-pid=0', '--enable-crash-reporter=,', '--noerrdialogs', 
'--user-data-dir=/tmp/.org.chromium.Chromium.bgkdhe', '--change-stack-guard-on-fork=enable']
      * 26 chromium -> execve /usr/lib/chromium/chromium ['/usr/lib/chromium/chromium', '--type=zygote', 
'--no-sandbox', '--enable-logging', '--headless=new', '--log-level=0', '--string-annotations', 
'--crashpad-handler-pid=0', '--enable-crash-reporter=,', '--noerrdialogs', 
'--user-data-dir=/tmp/.org.chromium.Chromium.bgkdhe', '--change-stack-guard-on-fork=enable']
      * 53 exe -> execve /proc/self/exe ['/proc/self/exe', '--type=utility', 
'--utility-sub-type=network.mojom.NetworkService', '--lang=en-US', '--service-sandbox-type=none', '--no-sandbox', 
'--disable-dev-shm-usage', '--use-angle=swiftshader-webgl', '--string-annotations', '--crashpad-handler-pid=0', 
'--enable-crash-reporter=,', '--noerrdialogs', '--user-data-dir=/tmp/.org.chromium.Chromium.bgkdhe', 
'--change-stack-guard-on-fork=enable', '--shared-files=v8_context_snapshot_data:100', 
'--field-trial-handle=3,i,12371618600324607627,6571217153886660505,262144', '--disable-features=PaintHolding', 
'--variations-seed-version', '--enable-logging', '--log-level=0']
  * 12 chromedriver -> execve /usr/bin/chromedriver ['/usr/bin/chromedriver', '--port=36433']
  * 23 chrome_crashpad -> execve /usr/lib/chromium/chrome_crashpad_handler 
['/usr/lib/chromium/chrome_crashpad_handler', '--no-periodic-tasks', 
'--monitor-self-annotation=ptype=crashpad-handler', '--database=/root/.config/chromium/Crash Reports', 
'--annotation=lsb-release=Alpine Linux v3.21', '--annotation=plat=Linux', '--annotation=prod=Chrome_Linux', 
'--annotation=ver=131.0.6778.264', '--initial-client-fd=4', '--shared-client-connection']
* 20 chrome_crashpad -> execve /usr/lib/chromium/chrome_crashpad_handler ['/usr/lib/chromium/chrome_crashpad_handler', 
'--monitor-self', '--monitor-self-annotation=ptype=crashpad-handler', '--database=/root/.config/chromium/Crash 
Reports', '--annotation=lsb-release=Alpine Linux v3.21', '--annotation=plat=Linux', '--annotation=prod=Chrome_Linux', 
'--annotation=ver=131.0.6778.264', '--initial-client-fd=5', '--shared-client-connection']

Network Activity:
  * [1] python3 -> connect 127.0.0.1:65535
  * [1] python3 -> connect [::1]:65535
  * [1] python3 -> connect [::1]:36433
  * [1] python3 -> connect 127.0.0.1:36433
  * [15] ThreadPoolSingl -> connect ?
  * [15] Bluez D-Bus thr -> connect ?
  * [44] chromium -> connect ?
  * [44] chromium -> connect /tmp/.X11-unix/X99
  * [44] chromium -> connect 127.0.0.1:65535
  * [44] chromium -> connect [::1]:65535
  * [44] chromium -> connect [::1]:6099
  * [44] chromium -> connect 127.0.0.1:6099
  * [7] ChromeDriver IO -> connect [2001:4860:4860::8888]:443
  * [7] ChromeDriver IO -> connect [::1]:38045
  * [7] ChromeDriver IO -> connect 127.0.0.1:38045
  * [15] BatteryStatusNo -> connect ?
  * [7] ChromeDriver IO -> connect 127.0.0.1:65535
  * [7] ChromeDriver IO -> connect [::1]:65535
  * [84] chromium -> connect ?
  * [84] chromium -> connect /tmp/.X11-unix/X99
  * [84] chromium -> connect 127.0.0.1:65535
  * [84] chromium -> connect [::1]:65535
  * [84] chromium -> connect [::1]:6099
  * [84] chromium -> connect 127.0.0.1:6099
  * [53] Chrome_ChildIOT -> connect [2001:4860:4860::8888]:443
  * [15] ThreadPoolForeg -> connect 127.0.0.1:65535
  * [15] ThreadPoolForeg -> connect [::1]:65535
  * [15] ThreadPoolForeg | dns | question=accounts.google.com
  * [157] init | dns | answer=accounts.google.com=172.253.62.84
  * [157] init | dns | answer=accounts.google.com=2607:f8b0:4004:c07::54
  * [15] ThreadPoolForeg -> connect [2607:f8b0:4004:c07::54]:65535
  * [15] ThreadPoolForeg -> connect 172.253.62.84:65535
  * [53] Chrome_ChildIOT -> connect [2607:f8b0:4004:c07::54]:443
  * [53] Chrome_ChildIOT -> connect 172.253.62.84:443
  * [102] chromium -> connect ?
  * [102] chromium -> connect /tmp/.X11-unix/X99
  * [102] chromium -> connect 127.0.0.1:65535
  * [102] chromium -> connect [::1]:65535
  * [102] chromium -> connect [::1]:6099
  * [102] chromium -> connect 127.0.0.1:6099
  * [112] chromium -> connect ?
  * [112] chromium -> connect /tmp/.X11-unix/X99
  * [112] chromium -> connect 127.0.0.1:65535
  * [112] chromium -> connect [::1]:65535
  * [112] chromium -> connect [::1]:6099
  * [112] chromium -> connect 127.0.0.1:6099
  * [15] ThreadPoolForeg | dns | question=optimizationguide-pa.googleapis.com
  * [157] init | dns | answer=optimizationguide-pa.googleapis.com=142.251.32.74, 
optimizationguide-pa.googleapis.com=142.251.33.170, optimizationguide-pa.googleapis.com=142.251.41.42, 
optimizationguide-pa.googleapis.com=172.217.1.10, optimizationguide-pa.googleapis.com=172.217.165.10, 
optimizationguide-pa.googleapis.com=142.251.41.74
  * [157] init | dns | answer=optimizationguide-pa.googleapis.com=2607:f8b0:400b:803::200a, 
optimizationguide-pa.googleapis.com=2607:f8b0:400b:807::200a, 
optimizationguide-pa.googleapis.com=2607:f8b0:400b:802::200a, 
optimizationguide-pa.googleapis.com=2607:f8b0:400b:804::200a
  * [15] ThreadPoolForeg -> connect [2607:f8b0:400b:803::200a]:65535
  * [15] ThreadPoolForeg -> connect [2607:f8b0:400b:807::200a]:65535
  * [15] ThreadPoolForeg -> connect [2607:f8b0:400b:802::200a]:65535
  * [15] ThreadPoolForeg -> connect [2607:f8b0:400b:804::200a]:65535
  * [15] ThreadPoolForeg -> connect 142.251.32.74:65535
  * [15] ThreadPoolForeg -> connect 142.251.33.170:65535
  * [15] ThreadPoolForeg -> connect 142.251.41.42:65535
  * [15] ThreadPoolForeg -> connect 172.217.1.10:65535
  * [15] ThreadPoolForeg -> connect 172.217.165.10:65535
  * [15] ThreadPoolForeg -> connect 142.251.41.74:65535
  * [53] Chrome_ChildIOT -> connect [2607:f8b0:400b:803::200a]:443
  * [53] Chrome_ChildIOT -> connect [2607:f8b0:400b:807::200a]:443
  * [53] Chrome_ChildIOT -> connect [2607:f8b0:400b:802::200a]:443
  * [53] Chrome_ChildIOT -> connect [2607:f8b0:400b:804::200a]:443
  * [53] Chrome_ChildIOT -> connect 172.217.1.10:443

File Accesses:
  * /app
  * /app/__pycache__/dyana.cpython-310.pyc.281472917591728
  * /app/dyana.py
  * /app/main.py
  * /docker/overlay2/a056a93237be2cf0d2eed4eb148f62752c47ce1ff6c14886b27f152e676ac151/work/work/#2c35
  * /docker/overlay2/a056a93237be2cf0d2eed4eb148f62752c47ce1ff6c14886b27f152e676ac151/work/work/#2c36
  * /proc
  * /root/.config/chromium/Crash Reports/settings.dat
  * /root/.pki/nssdb
  * /root/.pki/nssdb/cert9.db
  * /root/.pki/nssdb/cert9.db-journal
  * /root/.pki/nssdb/key4.db
  * /root/.pki/nssdb/key4.db-journal
  * /root/.pki/nssdb/pkcs11.txt
  * /usr/bin/chromedriver
  * self/fd/

  * 723 accesses to /usr/local/lib/*
  * 1436 accesses to /usr/lib/*
  * 2 accesses to /lib/*
  * 18 accesses to /dev/*
  * 340 accesses to /proc/*
  * 58 accesses to /sys/*
  * 27 accesses to /etc/*
  * 5370 accesses to /usr/share/*
  * 477 accesses to /tmp/*
  * 25 accesses to /var/*```

Update debug:

it seems from looking at the trace, the container is timing out because Chrome is getting stuck in DNS resolution and Google service connections, but not actually reaching Facebook.

i'm going to see if i can disable non-critical Chrome features that contact Google services (which are causing delays), plus:

  • explicit handling for page load timeouts
  • reduce the default timeouts to fail faster
  • error tracking for timeouts

the reason the trace completes while the container times out is because the tracer is still capturing events even though Chrome is stuck. The container timeout is happening at a higher level in the loader management code, while the trace captures everything up until that point

@GangGreenTemperTatum GangGreenTemperTatum added the bug Something isn't working label Jan 22, 2025
@GangGreenTemperTatum GangGreenTemperTatum self-assigned this Jan 22, 2025
@GangGreenTemperTatum
Copy link
Contributor Author

GangGreenTemperTatum commented Jan 22, 2025

quick update check-in: this is a very strange issue, i could not replicate this when i built the feature and no longer cannot replicate this after coming back to investigate and haven't restarted the docker engine or disconnected from a network

Image

i'll continue to iterate, test etc
for note taking, around the time of being able to record this issue almost on demand, i was also seeing strange docker-related problems / random rate-limit errors

❌ error: 500 Server Error for http+docker://localhost/v1.47/images/create?tag=latest&fromImage=aquasec%2Ftracee: 
Internal Server Error ("Head "https://registry-1.docker.io/v2/aquasec/tracee/manifests/latest": context deadline 
exceeded")
  * [155] init | dns | answer=accounts.google.com=74.125.192.84
  * [155] init | dns | question=accounts.google.com
  * [53] Chrome_ChildIOT -> connect 74.125.192.84:443
  * [14] ThreadPoolForeg | dns | question=optimizationguide-pa.googleapis.com
  * [155] init | dns | answer=optimizationguide-pa.googleapis.com=142.251.41.42, 
optimizationguide-pa.googleapis.com=142.251.41.74, 
optimizationguide-pa.googleapis.com=142.251.33.170, 
optimizationguide-pa.googleapis.com=172.217.1.10, 
optimizationguide-pa.googleapis.com=142.251.32.74
  * [155] init | dns | question=optimizationguide-pa.googleapis.com
  * [53] Chrome_ChildIOT -> connect 142.251.41.42:443

i did check the docker status page during this and couldn't see any immediate issues

@GangGreenTemperTatum GangGreenTemperTatum linked a pull request Jan 22, 2025 that will close this issue
@GangGreenTemperTatum
Copy link
Contributor Author

related note: during live troubleshooting with a buddy with a separate issue, i noticed that he encountered this issue too for a different loader:

❌ error: 500 Server Error for http+docker://localhost/v1.47/images/create?tag=latest&fromImage=aquasec%2Ftracee:
Internal Server Error ("Head "https://registry-1.docker.io/v2/aquasec/tracee/manifests/latest": context deadline
exceeded")

root-cause: looks to be when docker desktop lacks connectivity to the hub (i think)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant