metalbear-co / mirrord

Connect your local process and your cloud environment, and run local code in cloud conditions.
https://mirrord.dev
MIT License
3.82k stars 104 forks source link

Remote DNS fails for outgoing UDP over IPv6 messages #418

Open t4lz opened 2 years ago

t4lz commented 2 years ago

Bug Description

Outgoing UDP messages fail if destination is specified by name, not address, because of a DNS error on the agent.

Steps to Reproduce

  1. Checkout a Node.js script that sends out 1 UDP message, e.g. by running:
    git remote add talz git@github.com:t4lz/mirrord.git
    git fetch talz outgoing-udp-ipv6
    git checkout talz/outgoing-udp-ipv6 -- tests/node-e2e/outgoing/test_outgoing_traffic_udp6_client.mjs
  2. Run that node script with mirrord with any host name (here it's localhost):
    MIRRORD_AGENT_RUST_LOG=trace RUST_LOG=mirrord=trace target/debug/mirrord exec -c --pod-name <YOUR-POD-NAME> --no-fs node tests/node-e2e/outgoing/test_outgoing_traffic_udp6_client.mjs 31415 localhost
  3. The script throws an error because DNS failed.

Backtrace

file:///Users/tal/Documents/projects/mirrord/tests/node-e2e/outgoing/test_outgoing_traffic_udp6_client.mjs:22
        throw err
        ^

Error: getaddrinfo ENOTFOUND localhost
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:111:26) {
  errno: -3007,
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'localhost'
}

Node.js v18.9.0

Relevant Logs

Local logs:

2022-09-14T15:18:03.237300Z  INFO mirrord: Launching "node" with arguments ["node-e2e/outgoing/test_outgoing_traffic_udp6_client.mjs", "31415", "localhost"]
2022-09-14T15:18:03.387298Z DEBUG mirrord: Extracted library file to "/tmp/rzdlrrnynu-libmirrord_layer.dylib"
2022-09-14T15:18:03.734698Z  INFO mirrord_layer: Initializing mirrord-layer!
2022-09-14T15:18:03.735157Z  INFO mirrord_layer: Using port `49327` for communication
2022-09-14T15:18:03.739719Z  WARN mirrord_layer::pod_api: Accepting invalid certificates
2022-09-14T15:18:03.753042Z  INFO mirrord_layer::pod_api: No container name specified, defaulting to first container found
2022-09-14T15:18:03.761252Z DEBUG mirrord_layer::pod_api: Pod Phase = "Pending"
2022-09-14T15:18:03.774265Z DEBUG mirrord_layer::pod_api: Pod Phase = "Pending"
2022-09-14T15:18:04.922583Z DEBUG mirrord_layer::pod_api: Pod Phase = "Running"
2022-09-14T15:18:04.959247Z TRACE mirrord_layer: replace -> hooking "close"
2022-09-14T15:18:04.960537Z TRACE mirrord_layer: replace -> hooked "close" true
2022-09-14T15:18:04.960590Z TRACE mirrord_layer::socket::hooks: replace -> hooking "socket"
2022-09-14T15:18:04.960791Z TRACE mirrord_layer::socket::hooks: replace -> hooked "socket" true
2022-09-14T15:18:04.960815Z TRACE mirrord_layer::socket::hooks: replace -> hooking "bind"
2022-09-14T15:18:04.960978Z TRACE mirrord_layer::socket::hooks: replace -> hooked "bind" true
2022-09-14T15:18:04.961012Z TRACE mirrord_layer::socket::hooks: replace -> hooking "listen"
2022-09-14T15:18:04.961150Z TRACE mirrord_layer::socket::hooks: replace -> hooked "listen" true
2022-09-14T15:18:04.961168Z TRACE mirrord_layer::socket::hooks: replace -> hooking "connect"
2022-09-14T15:18:04.961306Z TRACE mirrord_layer::socket::hooks: replace -> hooked "connect" true
2022-09-14T15:18:04.961323Z TRACE mirrord_layer::socket::hooks: replace -> hooking "fcntl"
2022-09-14T15:18:04.961594Z TRACE mirrord_layer::socket::hooks: replace -> hooked "fcntl" true
2022-09-14T15:18:04.961626Z TRACE mirrord_layer::socket::hooks: replace -> hooking "dup"
2022-09-14T15:18:04.961759Z TRACE mirrord_layer::socket::hooks: replace -> hooked "dup" true
2022-09-14T15:18:04.961776Z TRACE mirrord_layer::socket::hooks: replace -> hooking "dup2"
2022-09-14T15:18:04.961907Z TRACE mirrord_layer::socket::hooks: replace -> hooked "dup2" true
2022-09-14T15:18:04.961923Z TRACE mirrord_layer::socket::hooks: replace -> hooking "getpeername"
2022-09-14T15:18:04.962054Z TRACE mirrord_layer::socket::hooks: replace -> hooked "getpeername" true
2022-09-14T15:18:04.962085Z TRACE mirrord_layer::socket::hooks: replace -> hooking "getsockname"
2022-09-14T15:18:04.962221Z TRACE mirrord_layer::socket::hooks: replace -> hooked "getsockname" true
2022-09-14T15:18:04.962242Z TRACE mirrord_layer::socket::hooks: replace -> hooking "accept"
2022-09-14T15:18:04.962421Z TRACE mirrord_layer::socket::hooks: replace -> hooked "accept" true
2022-09-14T15:18:04.962443Z TRACE mirrord_layer::socket::hooks: replace -> hooking "getaddrinfo"
2022-09-14T15:18:04.963418Z TRACE mirrord_layer::socket::hooks: replace -> hooked "getaddrinfo" true
2022-09-14T15:18:04.963448Z TRACE mirrord_layer::socket::hooks: replace -> hooking "freeaddrinfo"
2022-09-14T15:18:04.963754Z TRACE mirrord_layer::socket::hooks: replace -> hooked "freeaddrinfo" true
2022-09-14T15:18:04.964036Z  INFO mirrord_layer::go_env: replace -> hooking "runtime.goenvs_unix"
2022-09-14T15:18:04.972369Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse {
    "PY_SERV_PORT_80_TCP": "tcp://10.111.166.213:80",
    "PYTHON_VERSION": "3.9.13",
    "PY_SERV_SERVICE_PORT_HTTP": "80",
    "PY_SERV_PORT": "tcp://10.111.166.213:80",
    "PY_SERV_PORT_31415_UDP_PORT": "31415",
    "PY_SERV_SERVICE_HOST": "10.111.166.213",
    "KUBERNETES_PORT_443_TCP_ADDR": "10.96.0.1",
    "PY_SERV_PORT_80_TCP_PROTO": "tcp",
    "PYTHON_GET_PIP_URL": "https://github.com/pypa/get-pip/raw/6ce3639da143c5d79b44f94b04080abf2531fd6e/public/get-pip.py",
    "PY_SERV_PORT_80_TCP_ADDR": "10.111.166.213",
    "PY_SERV_PORT_80_TCP_PORT": "80",
    "LANG": "C.UTF-8",
    "KUBERNETES_PORT": "tcp://10.96.0.1:443",
    "KUBERNETES_SERVICE_HOST": "10.96.0.1",
    "PYTHON_GET_PIP_SHA256": "ba3ab8267d91fd41c58dbce08f76db99f747f716d85ce1865813842bb035524d",
    "HOSTNAME": "py-serv-deployment-ff89b5974-bzmq4",
    "PYTHON_PIP_VERSION": "22.0.4",
    "KUBERNETES_PORT_443_TCP_PROTO": "tcp",
    "MIRRORD_FAKE_VAR_FIRST": "mirrord.is.running",
    "KUBERNETES_SERVICE_PORT": "443",
    "PY_SERV_PORT_31415_UDP": "udp://10.111.166.213:31415",
    "PY_SERV_SERVICE_PORT": "80",
    "PY_SERV_PORT_31415_UDP_PROTO": "udp",
    "KUBERNETES_SERVICE_PORT_HTTPS": "443",
    "PY_SERV_PORT_31415_UDP_ADDR": "10.111.166.213",
    "KUBERNETES_PORT_443_TCP": "tcp://10.96.0.1:443",
    "MIRRORD_FAKE_VAR_SECOND": "7777",
    "GPG_KEY": "E3FF2839C048B25C084DEBE9B26995E310250568",
    "KUBERNETES_PORT_443_TCP_PORT": "443",
    "PY_SERV_SERVICE_PORT_OUTGOING_UDP_NODE": "31415",
    "PYTHON_SETUPTOOLS_VERSION": "58.1.0",
}!
2022-09-14T15:18:04.972489Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_80_TCP" value "tcp://10.111.166.213:80"
2022-09-14T15:18:04.972558Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PYTHON_VERSION" value "3.9.13"
2022-09-14T15:18:04.972568Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_SERVICE_PORT_HTTP" value "80"
2022-09-14T15:18:04.972576Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT" value "tcp://10.111.166.213:80"
2022-09-14T15:18:04.972582Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_31415_UDP_PORT" value "31415"
2022-09-14T15:18:04.972589Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_SERVICE_HOST" value "10.111.166.213"
2022-09-14T15:18:04.972595Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_PORT_443_TCP_ADDR" value "10.96.0.1"
2022-09-14T15:18:04.972602Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_80_TCP_PROTO" value "tcp"
2022-09-14T15:18:04.972608Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PYTHON_GET_PIP_URL" value "https://github.com/pypa/get-pip/raw/6ce3639da143c5d79b44f94b04080abf2531fd6e/public/get-pip.py"
2022-09-14T15:18:04.972616Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_80_TCP_ADDR" value "10.111.166.213"
2022-09-14T15:18:04.972622Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_80_TCP_PORT" value "80"
2022-09-14T15:18:04.972628Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "LANG" value "C.UTF-8"
2022-09-14T15:18:04.972634Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_PORT" value "tcp://10.96.0.1:443"
2022-09-14T15:18:04.972640Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_SERVICE_HOST" value "10.96.0.1"
2022-09-14T15:18:04.972647Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PYTHON_GET_PIP_SHA256" value "ba3ab8267d91fd41c58dbce08f76db99f747f716d85ce1865813842bb035524d"
2022-09-14T15:18:04.972654Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "HOSTNAME" value "py-serv-deployment-ff89b5974-bzmq4"
2022-09-14T15:18:04.972755Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PYTHON_PIP_VERSION" value "22.0.4"
2022-09-14T15:18:04.972766Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_PORT_443_TCP_PROTO" value "tcp"
2022-09-14T15:18:04.972772Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "MIRRORD_FAKE_VAR_FIRST" value "mirrord.is.running"
2022-09-14T15:18:04.972779Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_SERVICE_PORT" value "443"
2022-09-14T15:18:04.972785Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_31415_UDP" value "udp://10.111.166.213:31415"
2022-09-14T15:18:04.972792Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_SERVICE_PORT" value "80"
2022-09-14T15:18:04.972799Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_31415_UDP_PROTO" value "udp"
2022-09-14T15:18:04.972805Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_SERVICE_PORT_HTTPS" value "443"
2022-09-14T15:18:04.972811Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_PORT_31415_UDP_ADDR" value "10.111.166.213"
2022-09-14T15:18:04.972818Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_PORT_443_TCP" value "tcp://10.96.0.1:443"
2022-09-14T15:18:04.972826Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "MIRRORD_FAKE_VAR_SECOND" value "7777"
2022-09-14T15:18:04.972835Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "GPG_KEY" value "E3FF2839C048B25C084DEBE9B26995E310250568"
2022-09-14T15:18:04.972843Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "KUBERNETES_PORT_443_TCP_PORT" value "443"
2022-09-14T15:18:04.972851Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PY_SERV_SERVICE_PORT_OUTGOING_UDP_NODE" value "31415"
2022-09-14T15:18:04.972860Z DEBUG mirrord_layer: DaemonMessage::GetEnvVarsResponse set key "PYTHON_SETUPTOOLS_VERSION" value "58.1.0"
2022-09-14T15:18:04.973865Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 0 | cmd 3
2022-09-14T15:18:04.973890Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.973900Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 1 | cmd 3
2022-09-14T15:18:04.973906Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.973912Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 2 | cmd 3
2022-09-14T15:18:04.973917Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.973940Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 0 | cmd 2
2022-09-14T15:18:04.973946Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.973951Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 1 | cmd 2
2022-09-14T15:18:04.973957Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.973962Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 2 | cmd 2
2022-09-14T15:18:04.973967Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.973972Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 3 | cmd 2
2022-09-14T15:18:04.973977Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.973982Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 4 | cmd 2
2022-09-14T15:18:04.973987Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.973992Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 5 | cmd 2
2022-09-14T15:18:04.974065Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974075Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 6 | cmd 2
2022-09-14T15:18:04.974082Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974087Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 7 | cmd 2
2022-09-14T15:18:04.974092Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974097Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 8 | cmd 2
2022-09-14T15:18:04.974103Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974107Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 9 | cmd 2
2022-09-14T15:18:04.974113Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974133Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 10 | cmd 2
2022-09-14T15:18:04.974143Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974149Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 11 | cmd 2
2022-09-14T15:18:04.974154Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 12 | cmd 2
2022-09-14T15:18:04.974160Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 13 | cmd 2
2022-09-14T15:18:04.974166Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 14 | cmd 2
2022-09-14T15:18:04.974171Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 15 | cmd 2
2022-09-14T15:18:04.974177Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 16 | cmd 2
2022-09-14T15:18:04.974276Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 11 | cmd 2
2022-09-14T15:18:04.974284Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974295Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 12 | cmd 2
2022-09-14T15:18:04.974301Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974314Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 13 | cmd 2
2022-09-14T15:18:04.974321Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974332Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 14 | cmd 2
2022-09-14T15:18:04.974337Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974343Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 15 | cmd 2
2022-09-14T15:18:04.974348Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974356Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 16 | cmd 2
2022-09-14T15:18:04.974362Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974366Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 17 | cmd 2
2022-09-14T15:18:04.974372Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974423Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 18 | cmd 2
2022-09-14T15:18:04.974435Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974442Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 19 | cmd 2
2022-09-14T15:18:04.974448Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974452Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 20 | cmd 2
2022-09-14T15:18:04.974458Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974465Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 21 | cmd 2
2022-09-14T15:18:04.974470Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974475Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 22 | cmd 2
2022-09-14T15:18:04.974480Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974675Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 23 | cmd 2
2022-09-14T15:18:04.974682Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974691Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 24 | cmd 2
2022-09-14T15:18:04.974696Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974701Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 25 | cmd 2
2022-09-14T15:18:04.974707Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974714Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 26 | cmd 2
2022-09-14T15:18:04.974720Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.974724Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 27 | cmd 2
2022-09-14T15:18:04.974730Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.995319Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 1 | cmd 3
2022-09-14T15:18:04.995333Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.996942Z TRACE mirrord_layer::socket::hooks: dup2_detour -> oldfd 28 | newfd 1
2022-09-14T15:18:04.996960Z TRACE mirrord_layer::socket::hooks: dup2_detour -> result 1
2022-09-14T15:18:04.996987Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 1 | cmd 2
2022-09-14T15:18:04.997000Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.997592Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 0 | cmd 3
2022-09-14T15:18:04.997602Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.998547Z TRACE mirrord_layer::socket::hooks: dup2_detour -> oldfd 30 | newfd 0
2022-09-14T15:18:04.998562Z TRACE mirrord_layer::socket::hooks: dup2_detour -> result 0
2022-09-14T15:18:04.998568Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 0 | cmd 2
2022-09-14T15:18:04.998573Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:04.998692Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 2 | cmd 3
2022-09-14T15:18:04.998702Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 65538
2022-09-14T15:18:04.999624Z TRACE mirrord_layer::socket::hooks: dup2_detour -> oldfd 31 | newfd 2
2022-09-14T15:18:04.999634Z TRACE mirrord_layer::socket::hooks: dup2_detour -> result 2
2022-09-14T15:18:04.999639Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 2 | cmd 2
2022-09-14T15:18:04.999645Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:05.002074Z TRACE mirrord_layer::socket::hooks: socket_detour -> domain 30 | type:2 | protocol 0
2022-09-14T15:18:05.002085Z TRACE mirrord_layer::socket::ops: socket -> domain 30 | type:2 | protocol 0
2022-09-14T15:18:05.002120Z DEBUG mirrord_layer::socket::ops: socket -> socket_fd 32 | new_socket UserSocket {
    domain: 30,
    type_: 2,
    protocol: 0,
    state: Initialized,
    kind: Udp(
        2,
    ),
}
2022-09-14T15:18:05.002139Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> fd 32 | cmd 2
2022-09-14T15:18:05.002145Z TRACE mirrord_layer::socket::hooks: fcntl_detour -> result 0
2022-09-14T15:18:05.002154Z TRACE mirrord_layer::socket::hooks: bind_detour -> sockfd 32 | raw_address sockaddr {
    sa_len: 28,
    sa_family: 30,
    sa_data: [
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
        0,
    ],
}
2022-09-14T15:18:05.002168Z DEBUG mirrord_layer::socket::ops: bind -> sockfd 32 | address SockAddr {
    ss_len: 28,
    ss_family: 30,
    len: 28,
}
2022-09-14T15:18:05.002192Z  WARN mirrord_layer::socket::hooks: bind_detour -> bypassed with BypassedPort(
    0,
)
2022-09-14T15:18:05.002759Z TRACE mirrord_layer::socket::hooks: getaddrinfo_detour -> raw_node 0x0000600002e60070 | raw_service 0x0000000000000000 | raw_hints addrinfo {
    ai_flags: 0,
    ai_family: 30,
    ai_socktype: 1,
    ai_protocol: 0,
    ai_addrlen: 0,
    ai_canonname: 0x0000000000000000,
    ai_addr: 0x0000000000000000,
    ai_next: 0x0000000000000000,
} | out? false
2022-09-14T15:18:05.002782Z DEBUG mirrord_layer::socket::ops: getaddrinfo -> node Some(
    "localhost",
) | service None | hints Some(
    AddrInfoHint {
        ai_family: 30,
        ai_socktype: 1,
        ai_protocol: 0,
        ai_flags: 0,
    },
)
2022-09-14T15:18:05.002860Z TRACE mirrord_layer: Layer::handle_hook_message -> hook_message GetAddrInfoHook(GetAddrInfoHook { node: Some("localhost"), service: None, hints: Some(AddrInfoHint { ai_family: 30, ai_socktype: 1, ai_protocol: 0, ai_flags: 0 }), hook_channel_tx: Sender { inner: Some(Inner { state: State { is_complete: false, is_closed: false, is_rx_task_set: true, is_tx_task_set: false } }) } })
2022-09-14T15:18:05.002876Z TRACE mirrord_layer: HookMessage::GetAddrInfo
2022-09-14T15:18:05.004145Z TRACE mirrord_layer: DaemonMessage::GetAddrInfoResponse Err(
    DnsFailure(
        -6,
    ),
)
2022-09-14T15:18:05.004181Z TRACE mirrord_layer::error: dns failed with code -6    
2022-09-14T15:18:05.004201Z TRACE mirrord_layer::socket::hooks: result: 11

Agent logs:

2022-09-14T15:18:04.331856Z DEBUG mirrord_agent: main -> Initializing mirrord-agent.
2022-09-14T15:18:04.332030Z DEBUG mirrord_agent: starting with args Args { container_id: Some("c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c"), container_runtime: Some("docker"), communicate_port: 49327, communication_timeout: 30, interface: "eth0", ephemeral_container: false }
2022-09-14T15:18:04.332060Z TRACE mio::poll: registering event source with poller: token=Token(1), interests=READABLE | WRITABLE    
2022-09-14T15:18:04.332090Z DEBUG bollard::uri: Parsing uri: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c/json?size=false, client_type: Unix, socket: /var/run/docker.sock    
2022-09-14T15:18:04.332094Z DEBUG bollard::docker: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c/json?size=false    
2022-09-14T15:18:04.332102Z DEBUG bollard::docker: request: Request { method: GET, uri: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c/json?size=false, version: HTTP/1.1, headers: {"content-type": "application/json"}, body: Body(Empty) }    
2022-09-14T15:18:04.332985Z TRACE mio::poll: registering event source with poller: token=Token(2), interests=READABLE | WRITABLE    
2022-09-14T15:18:04.333308Z TRACE hyper::client::conn: client handshake Http1
2022-09-14T15:18:04.333325Z TRACE hyper::client::client: handshake complete, spawning background dispatcher task
2022-09-14T15:18:04.333448Z TRACE want: signal: Want    
2022-09-14T15:18:04.333466Z TRACE want: signal found waiting giver, notifying    
2022-09-14T15:18:04.333477Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Busy }
2022-09-14T15:18:04.333500Z TRACE want: poll_want: taker wants!    
2022-09-14T15:18:04.333581Z TRACE encode_headers: hyper::proto::h1::role: Client::encode method=GET, body=None
2022-09-14T15:18:04.333607Z DEBUG hyper::proto::h1::io: flushed 189 bytes
2022-09-14T15:18:04.333610Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy }
2022-09-14T15:18:04.333989Z TRACE hyper::proto::h1::conn: Conn::read_head
2022-09-14T15:18:04.334031Z TRACE hyper::proto::h1::io: received 8192 bytes
2022-09-14T15:18:04.334042Z TRACE parse_headers: hyper::proto::h1::role: Response.parse bytes=8192
2022-09-14T15:18:04.334046Z TRACE parse_headers: hyper::proto::h1::role: Response.parse Complete(211)
2022-09-14T15:18:04.334055Z DEBUG hyper::proto::h1::io: parsed 7 headers
2022-09-14T15:18:04.334057Z DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
2022-09-14T15:18:04.334062Z TRACE hyper::proto::h1::decode: decode; state=Chunked(Size, 0)
2022-09-14T15:18:04.334064Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334065Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334066Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334067Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334067Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334069Z TRACE hyper::proto::h1::decode: Chunk size is 8162
2022-09-14T15:18:04.334070Z DEBUG hyper::proto::h1::decode: incoming chunked header: 0x1FE2 (8162 bytes)
2022-09-14T15:18:04.334071Z TRACE hyper::proto::h1::decode: Chunked read, remaining=8162
2022-09-14T15:18:04.334073Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Body(Chunked(Body, 187)), writing: KeepAlive, keep_alive: Busy }
2022-09-14T15:18:04.334176Z TRACE hyper::proto::h1::decode: decode; state=Chunked(Body, 187)
2022-09-14T15:18:04.334182Z TRACE hyper::proto::h1::decode: Chunked read, remaining=187
2022-09-14T15:18:04.334190Z TRACE hyper::proto::h1::io: received 194 bytes
2022-09-14T15:18:04.334194Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Body(Chunked(BodyCr, 0)), writing: KeepAlive, keep_alive: Busy }
2022-09-14T15:18:04.334292Z TRACE hyper::proto::h1::decode: decode; state=Chunked(BodyCr, 0)
2022-09-14T15:18:04.334312Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334313Z TRACE hyper::proto::h1::decode: Read chunk hex size
2022-09-14T15:18:04.334315Z TRACE hyper::proto::h1::decode: Chunk size is 0
2022-09-14T15:18:04.334316Z TRACE hyper::proto::h1::decode: end of chunked
2022-09-14T15:18:04.334318Z DEBUG hyper::proto::h1::conn: incoming body completed
2022-09-14T15:18:04.334320Z TRACE hyper::proto::h1::conn: maybe_notify; read_from_io blocked
2022-09-14T15:18:04.334439Z TRACE hyper::proto::h1::dispatch: client tx closed
2022-09-14T15:18:04.334447Z TRACE hyper::proto::h1::conn: State::close_read()
2022-09-14T15:18:04.334448Z TRACE hyper::proto::h1::conn: State::close_write()
2022-09-14T15:18:04.334449Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
2022-09-14T15:18:04.334450Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
2022-09-14T15:18:04.334543Z DEBUG bollard::docker: Decoded into string: {"Id":"c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c","Created":"2022-09-14T08:02:38.302815463Z","Path":"python3","Args":["app.py"],"State":{"Status":"running","Running":true,"Paused":false,"Restarting":false,"OOMKilled":false,"Dead":false,"Pid":7080,"ExitCode":0,"Error":"","StartedAt":"2022-09-14T08:02:38.439143379Z","FinishedAt":"0001-01-01T00:00:00Z"},"Image":"sha256:a2ff62dffc21c36b7766038ed1ddca9c5f256e96f218ab9cd1717b0755b1e578","ResolvConfPath":"/var/lib/docker/containers/8236b42f2a37488a3f734b9bda6d9c5afaa546fa846985a9f2b5dd72e4dfc571/resolv.conf","HostnamePath":"/var/lib/docker/containers/8236b42f2a37488a3f734b9bda6d9c5afaa546fa846985a9f2b5dd72e4dfc571/hostname","HostsPath":"/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/etc-hosts","LogPath":"/var/lib/docker/containers/c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c/c3c8df6a64eb6c33412665a8f9bebb42491bc4f97e56a3171c1d92143881e30c-json.log","Name":"/k8s_py-serv_py-serv-deployment-ff89b5974-bzmq4_default_9088f639-646f-4f4b-a989-8d45f2d36bc9_0","RestartCount":0,"Driver":"overlay2","Platform":"linux","MountLabel":"","ProcessLabel":"","AppArmorProfile":"","ExecIDs":null,"HostConfig":{"Binds":["/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/volumes/kubernetes.io~projected/kube-api-access-hwhb4:/var/run/secrets/kubernetes.io/serviceaccount:ro","/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/etc-hosts:/etc/hosts","/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/containers/py-serv/bf69a0a6:/dev/termination-log"],"ContainerIDFile":"","LogConfig":{"Type":"json-file","Config":{}},"NetworkMode":"container:8236b42f2a37488a3f734b9bda6d9c5afaa546fa846985a9f2b5dd72e4dfc571","PortBindings":null,"RestartPolicy":{"Name":"no","MaximumRetryCount":0},"AutoRemove":false,"VolumeDriver":"","VolumesFrom":null,"CapAdd":null,"CapDrop":null,"CgroupnsMode":"private","Dns":null,"DnsOptions":null,"DnsSearch":null,"ExtraHosts":null,"GroupAdd":null,"IpcMode":"container:8236b42f2a37488a3f734b9bda6d9c5afaa546fa846985a9f2b5dd72e4dfc571","Cgroup":"","Links":null,"OomScoreAdj":1000,"PidMode":"","Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"SecurityOpt":["seccomp=unconfined"],"UTSMode":"","UsernsMode":"","ShmSize":67108864,"Runtime":"runc","ConsoleSize":[0,0],"Isolation":"","CpuShares":2,"Memory":0,"NanoCpus":0,"CgroupParent":"/kubepods/kubepods/besteffort/pod9088f639-646f-4f4b-a989-8d45f2d36bc9","BlkioWeight":0,"BlkioWeightDevice":null,"BlkioDeviceReadBps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteIOps":null,"CpuPeriod":100000,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpusetCpus":"","CpusetMems":"","Devices":[],"DeviceCgroupRules":null,"DeviceRequests":null,"KernelMemory":0,"KernelMemoryTCP":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":null,"OomKillDisable":null,"PidsLimit":null,"Ulimits":null,"CpuCount":0,"CpuPercent":0,"IOMaximumIOps":0,"IOMaximumBandwidth":0,"MaskedPaths":["/proc/acpi","/proc/kcore","/proc/keys","/proc/latency_stats","/proc/timer_list","/proc/timer_stats","/proc/sched_debug","/proc/scsi","/sys/firmware"],"ReadonlyPaths":["/proc/asound","/proc/bus","/proc/fs","/proc/irq","/proc/sys","/proc/sysrq-trigger"]},"GraphDriver":{"Data":{"LowerDir":"/var/lib/docker/overlay2/b0cd254171ffdbca0fc42c34a2fbbe504021868393c67e89c7023204b08585e7-init/diff:/var/lib/docker/overlay2/b47310dfa8c6b3f527a91aa6bebda65cd6a0060be076ebef10a1c8bdf2c44326/diff:/var/lib/docker/overlay2/cf3357f2da7906ff093ed2ed5abd6bb7a26aa7504fb9310eb0b8e67b2cc51112/diff:/var/lib/docker/overlay2/d657cccdd50b6c3035da021db2bb82f9cb9926164d327367db3cff888680d612/diff:/var/lib/docker/overlay2/7d8fd4433b2c97a6a1fb3b98ec0decbb2f39a3ad799c10e44ca34df82fc602c4/diff:/var/lib/docker/overlay2/9faf3a2e9703d61fa9dc17ed5a5f5ce02144e56697283d5fe741c10bbe60a0c5/diff:/var/lib/docker/overlay2/64257859ea3bc8138ca13f664a5b5d0328c7100efbfd7d171e3f1e585531d7d1/diff:/var/lib/docker/overlay2/a58c8920f2534b22b99e9557cf9aa788559067af16d8416f94128ffe5fae296a/diff:/var/lib/docker/overlay2/a55a839b2cdc0e18f2a32ae337ea2d1c049227557a27c021292dc8a08a1676b8/diff","MergedDir":"/var/lib/docker/overlay2/b0cd254171ffdbca0fc42c34a2fbbe504021868393c67e89c7023204b08585e7/merged","UpperDir":"/var/lib/docker/overlay2/b0cd254171ffdbca0fc42c34a2fbbe504021868393c67e89c7023204b08585e7/diff","WorkDir":"/var/lib/docker/overlay2/b0cd254171ffdbca0fc42c34a2fbbe504021868393c67e89c7023204b08585e7/work"},"Name":"overlay2"},"Mounts":[{"Type":"bind","Source":"/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/volumes/kubernetes.io~projected/kube-api-access-hwhb4","Destination":"/var/run/secrets/kubernetes.io/serviceaccount","Mode":"ro","RW":false,"Propagation":"rprivate"},{"Type":"bind","Source":"/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/etc-hosts","Destination":"/etc/hosts","Mode":"","RW":true,"Propagation":"rprivate"},{"Type":"bind","Source":"/var/lib/kubelet/pods/9088f639-646f-4f4b-a989-8d45f2d36bc9/containers/py-serv/bf69a0a6","Destination":"/dev/termination-log","Mode":"","RW":true,"Propagation":"rprivate"}],"Config":{"Hostname":"py-serv-deployment-ff89b5974-bzmq4","Domainname":"","User":"0","AttachStdin":false,"AttachStdout":false,"AttachStderr":false,"Tty":false,"OpenStdin":false,"StdinOnce":false,"Env":["MIRRORD_FAKE_VAR_FIRST=mirrord.is.running","MIRRORD_FAKE_VAR_SECOND=7777","KUBERNETES_PORT=tcp://10.96.0.1:443","PY_SERV_SERVICE_PORT=80","PY_SERV_PORT=tcp://10.111.166.213:80","PY_SERV_PORT_80_TCP=tcp://10.111.166.213:80","PY_SERV_PORT_31415_UDP=udp://10.111.166.213:31415","PY_SERV_PORT_31415_UDP_ADDR=10.111.166.213","KUBERNETES_SERVICE_PORT_HTTPS=443","KUBERNETES_PORT_443_TCP=tcp://10.96.0.1:443","KUBERNETES_PORT_443_TCP_ADDR=10.96.0.1","PY_SERV_SERVICE_PORT_HTTP=80","KUBERNETES_PORT_443_TCP_PROTO=tcp","PY_SERV_SERVICE_PORT_OUTGOING_UDP_NODE=31415","PY_SERV_PORT_80_TCP_ADDR=10.111.166.213","PY_SERV_PORT_31415_UDP_PORT=31415","KUBERNETES_SERVICE_HOST=10.96.0.1","KUBERNETES_SERVICE_PORT=443","KUBERNETES_PORT_443_TCP_PORT=443","PY_SERV_SERVICE_HOST=10.111.166.213","PY_SERV_PORT_80_TCP_PROTO=tcp","PY_SERV_PORT_80_TCP_PORT=80","PY_SERV_PORT_31415_UDP_PROTO=udp","PATH=/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin","LANG=C.UTF-8","GPG_KEY=E3FF2839C048B25C084DEBE9B26995E310250568","PYTHON_VERSION=3.9.13","PYTHON_PIP_VERSION=22.0.4","PYTHON_SETUPTOOLS_VERSION=58.1.0","PYTHON_GET_PIP_URL=https://github.com/pypa/get-pip/raw/6ce3639da143c5d79b44f94b04080abf2531fd6e/public/get-pip.py","PYTHON_GET_PIP_SHA256=ba3ab8267d91fd41c58dbce08f76db99f747f716d85ce1865813842bb035524d"],"Cmd":null,"Healthcheck":{"Test":["NONE"]},"Image":"ghcr.io/metalbear-co/mirrord-pytest@sha256:c9d7727ec5adbe1a6dc9b8868b48da6e037a12965b8529bcaebab3a10fb3e5c0","Volumes":null,"WorkingDir":"/app","Entrypoint":["python3","app.py"],"OnBuild":null,"Labels":{"annotation.io.kubernetes.container.hash":"b02bf32d","annotation.io.kubernetes.container.ports":"[{\"containerPort\":80,\"protocol\":\"TCP\"}]","annotation.io.kubernetes.container.restartCount":"0","annotation.io.kubernetes.container.terminationMessagePath":"/dev/termination-log","annotation.io.kubernetes.container.terminationMessagePolicy":"File","annotation.io.kubernetes.pod.terminationGracePeriod":"30","io.kubernetes.container.logpath":"/var/log/pods/default_py-serv-deployment-ff89b5974-bzmq4_9088f639-646f-4f4b-a989-8d45f2d36bc9/py-serv/0.log","io.kubernetes.container.name":"py-serv","io.kubernetes.docker.type":"container","io.kubernetes.pod.name":"py-serv-deployment-ff89b5974-bzmq4","io.kubernetes.pod.namespace":"default","io.kubernetes.pod.uid":"9088f639-646f-4f4b-a989-8d45f2d36bc9","io.kubernetes.sandbox.id":"8236b42f2a37488a3f734b9bda6d9c5afaa546fa846985a9f2b5dd72e4dfc571"}},"NetworkSettings":{"Bridge":"","SandboxID":"","HairpinMode":false,"LinkLocalIPv6Address":"","LinkLocalIPv6PrefixLen":0,"Ports":{},"SandboxKey":"","SecondaryIPAddresses":null,"SecondaryIPv6Addresses":null,"EndpointID":"","Gateway":"","GlobalIPv6Address":"","GlobalIPv6PrefixLen":0,"IPAddress":"","IPPrefixLen":0,"IPv6Gateway":"","MacAddress":"","Networks":{}}}

2022-09-14T15:18:04.334768Z  INFO mirrord_agent: agent ready
2022-09-14T15:18:04.334786Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
2022-09-14T15:18:04.334820Z TRACE hyper::proto::h1::conn: shut down IO complete
2022-09-14T15:18:04.334821Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
2022-09-14T15:18:04.334823Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:04.334829Z TRACE want: signal: Closed    
2022-09-14T15:18:04.334877Z DEBUG mirrord_agent::runtime: set_namespace -> fd 10
2022-09-14T15:18:04.334896Z DEBUG mirrord_agent::runtime: set_namespace -> fd 21
2022-09-14T15:18:04.334899Z DEBUG mirrord_agent::sniffer: preparing sniffer
2022-09-14T15:18:04.334900Z DEBUG mirrord_agent::sniffer: prepare_sniffer -> Preparing interface.
2022-09-14T15:18:04.347711Z TRACE mio::poll: registering event source with poller: token=Token(1), interests=READABLE    
2022-09-14T15:18:04.959096Z TRACE mio::poll: registering event source with poller: token=Token(16777218), interests=READABLE | WRITABLE    
2022-09-14T15:18:04.959162Z DEBUG mirrord_agent: start -> Connection accepted from 127.0.0.1:35026
2022-09-14T15:18:04.959202Z DEBUG mirrord_agent::file: Agent root path >> "/proc/7080/root"
2022-09-14T15:18:04.959338Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
2022-09-14T15:18:04.959341Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
2022-09-14T15:18:04.959344Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
2022-09-14T15:18:04.959439Z DEBUG mirrord_agent::runtime: set_namespace -> fd 35
2022-09-14T15:18:04.959448Z DEBUG mirrord_agent::runtime: set_namespace -> fd 36
2022-09-14T15:18:04.959449Z DEBUG mirrord_agent::runtime: set_namespace -> fd 37
2022-09-14T15:18:04.959451Z DEBUG mirrord_agent::steal: preparing steal
2022-09-14T15:18:04.959461Z TRACE mio::poll: registering event source with poller: token=Token(1), interests=READABLE | WRITABLE    
2022-09-14T15:18:04.963159Z DEBUG mirrord_agent::steal: finished preparing steal
2022-09-14T15:18:04.971438Z TRACE actix_codec::framed: attempting to decode a frame    
2022-09-14T15:18:04.971448Z TRACE actix_codec::framed: frame decoded from buffer    
2022-09-14T15:18:04.971450Z DEBUG mirrord_agent: client_handler -> client sent message GetEnvVarsRequest(GetEnvVarsRequest { env_vars_filter: {}, env_vars_select: {"*"} })
2022-09-14T15:18:04.971453Z DEBUG mirrord_agent: ClientMessage::GetEnvVarsRequest client id 0 filter {} select {"*"}
2022-09-14T15:18:04.971455Z TRACE mirrord_agent: select_env_vars -> environ_path "/proc/7080/environ" filter_env_vars {} select_env_vars {
    "*",
}
2022-09-14T15:18:04.971677Z TRACE mirrord_agent: respond -> response GetEnvVarsResponse(
    Ok(
        {
            "PY_SERV_SERVICE_HOST": "10.111.166.213",
            "KUBERNETES_PORT_443_TCP_ADDR": "10.96.0.1",
            "KUBERNETES_SERVICE_PORT_HTTPS": "443",
            "KUBERNETES_PORT": "tcp://10.96.0.1:443",
            "MIRRORD_FAKE_VAR_FIRST": "mirrord.is.running",
            "PY_SERV_PORT": "tcp://10.111.166.213:80",
            "PYTHON_GET_PIP_SHA256": "ba3ab8267d91fd41c58dbce08f76db99f747f716d85ce1865813842bb035524d",
            "PY_SERV_PORT_31415_UDP_PORT": "31415",
            "PYTHON_PIP_VERSION": "22.0.4",
            "PYTHON_SETUPTOOLS_VERSION": "58.1.0",
            "PY_SERV_SERVICE_PORT_HTTP": "80",
            "PY_SERV_SERVICE_PORT": "80",
            "PY_SERV_PORT_80_TCP_ADDR": "10.111.166.213",
            "GPG_KEY": "E3FF2839C048B25C084DEBE9B26995E310250568",
            "PY_SERV_PORT_31415_UDP": "udp://10.111.166.213:31415",
            "PY_SERV_PORT_80_TCP_PROTO": "tcp",
            "KUBERNETES_PORT_443_TCP_PROTO": "tcp",
            "PY_SERV_PORT_80_TCP_PORT": "80",
            "KUBERNETES_SERVICE_HOST": "10.96.0.1",
            "PYTHON_GET_PIP_URL": "https://github.com/pypa/get-pip/raw/6ce3639da143c5d79b44f94b04080abf2531fd6e/public/get-pip.py",
            "KUBERNETES_PORT_443_TCP": "tcp://10.96.0.1:443",
            "KUBERNETES_SERVICE_PORT": "443",
            "MIRRORD_FAKE_VAR_SECOND": "7777",
            "HOSTNAME": "py-serv-deployment-ff89b5974-bzmq4",
            "KUBERNETES_PORT_443_TCP_PORT": "443",
            "PY_SERV_SERVICE_PORT_OUTGOING_UDP_NODE": "31415",
            "PY_SERV_PORT_31415_UDP_PROTO": "udp",
            "LANG": "C.UTF-8",
            "PY_SERV_PORT_80_TCP": "tcp://10.111.166.213:80",
            "PYTHON_VERSION": "3.9.13",
            "PY_SERV_PORT_31415_UDP_ADDR": "10.111.166.213",
        },
    ),
)
2022-09-14T15:18:04.971717Z TRACE actix_codec::framed: flushing framed transport    
2022-09-14T15:18:04.971718Z TRACE actix_codec::framed: writing; remaining=1217    
2022-09-14T15:18:04.971729Z TRACE actix_codec::framed: framed transport flushed    
2022-09-14T15:18:04.971731Z TRACE actix_codec::framed: attempting to decode a frame    
2022-09-14T15:18:05.003555Z TRACE actix_codec::framed: attempting to decode a frame    
2022-09-14T15:18:05.003567Z TRACE actix_codec::framed: frame decoded from buffer    
2022-09-14T15:18:05.003569Z DEBUG mirrord_agent: client_handler -> client sent message GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost"), service: None, hints: Some(AddrInfoHint { ai_family: 30, ai_socktype: 1, ai_protocol: 0, ai_flags: 0 }) })
2022-09-14T15:18:05.003584Z TRACE mirrord_agent: waiting for answer from dns thread
2022-09-14T15:18:05.003590Z TRACE mirrord_agent::dns: get_addr_info -> request GetAddrInfoRequest {
    node: Some(
        "localhost",
    ),
    service: None,
    hints: Some(
        AddrInfoHint {
            ai_family: 30,
            ai_socktype: 1,
            ai_protocol: 0,
            ai_flags: 0,
        },
    ),
}
2022-09-14T15:18:05.003710Z TRACE mirrord_agent: GetAddrInfoRequest -> response Err(
    DnsFailure(
        -6,
    ),
)
2022-09-14T15:18:05.003716Z TRACE mirrord_agent: respond -> response GetAddrInfoResponse(
    Err(
        DnsFailure(
            -6,
        ),
    ),
)
2022-09-14T15:18:05.003720Z TRACE actix_codec::framed: flushing framed transport    
2022-09-14T15:18:05.003721Z TRACE actix_codec::framed: writing; remaining=4    
2022-09-14T15:18:05.003793Z TRACE actix_codec::framed: framed transport flushed    
2022-09-14T15:18:05.003799Z TRACE actix_codec::framed: attempting to decode a frame    
2022-09-14T15:18:05.008543Z DEBUG mirrord_agent: Client 0 disconnected
2022-09-14T15:18:05.008641Z DEBUG mirrord_agent: client closing
2022-09-14T15:18:05.008646Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:05.008675Z DEBUG mirrord_agent::steal: rx closed, breaking
2022-09-14T15:18:05.008680Z DEBUG mirrord_agent::steal: TCP Stealer exiting
2022-09-14T15:18:05.008682Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:05.008693Z DEBUG mirrord_agent::steal: steal exiting
2022-09-14T15:18:05.008768Z DEBUG mirrord_agent::sniffer: packet_worker -> empty ports, setting dummy bpf
2022-09-14T15:18:05.009009Z  WARN mirrord_agent::outgoing: interceptor_task -> no messages left
2022-09-14T15:18:05.009038Z  WARN mirrord_agent::outgoing::udp: interceptor_task -> no messages left
2022-09-14T15:18:05.009059Z DEBUG mirrord_agent: ClientConnectionHandler::start -> Client 0 disconnected
2022-09-14T15:18:05.009261Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:05.009267Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:05.011403Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:35.010734Z DEBUG mirrord_agent: start_agent -> main thread timeout, no clients connected
2022-09-14T15:18:35.010822Z DEBUG mirrord_agent: start_agent -> shutting down start
2022-09-14T15:18:35.010926Z DEBUG mirrord_agent::sniffer: TCPConnectionSniffer exiting
2022-09-14T15:18:35.010956Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:35.028700Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:35.029142Z DEBUG mirrord_agent: shutdown done
2022-09-14T15:18:35.029183Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:35.029219Z  INFO mirrord_agent: main -> mirrord-agent `start` exiting successfully.
2022-09-14T15:18:35.029570Z TRACE mio::poll: deregistering event source from poller    
2022-09-14T15:18:35.029655Z TRACE mio::poll: deregistering event source from poller    

Your operating system and version

macOS Monterey 12.5.1

Local process

/opt/homebrew/bin/node: Mach-O 64-bit executable arm64

Local process version

No response

Additional Info

I do not know if this issue is limited to attempts to send UDP messages.

t4lz commented 2 years ago

Running directly on the target pod with kubectl exec -it <POD-NAME> -- /bin/bash and installing nc (apt update && apt install netcat-openbsd), nc -u -6 <HOST> <PORT> fails, so maybe this is not a bug in mirrord? I guess we can install node on the pod and run the same script and verify we get the same result.

meowjesty commented 2 years ago

This fails with a different reason now:

2022-10-26T17:45:48.154344Z DEBUG ThreadId(24) getaddrinfo: mirrord_layer::socket::ops: getaddrinfo -> result 0x00007f1cd8002480 rawish_node=Some("localhost") rawish_service=None raw_hints=Some(addrinfo { ai_flags: 0, ai_family: 10, ai_socktype: 1, ai_protocol: 0, ai_addrlen: 0, ai_addr: 0x0, ai_canonname: 0x0, ai_next: 0x0 })
2022-10-26T17:45:48.154413Z TRACE ThreadId(24) getaddrinfo: mirrord_layer::socket::ops: exit rawish_node=Some("localhost") rawish_service=None raw_hints=Some(addrinfo { ai_flags: 0, ai_family: 10, ai_socktype: 1, ai_protocol: 0, ai_addrlen: 0, ai_addr: 0x0, ai_canonname: 0x0, ai_next: 0x0 })
file:///home/meowjesty/dev/metalbear/playground/test_outgoing_traffic_udp6_client.mjs:22
        throw err
        ^

Error: send EINVAL localhost:31415
    at doSend (node:dgram:713:16)
    at defaultTriggerAsyncIdScope (node:internal/async_hooks:466:18)
    at GetAddrInfoReqWrap.afterDns [as callback] (node:dgram:659:5)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:109:8) {
  errno: -22,
  code: 'EINVAL',
  syscall: 'send',
  address: 'localhost',
  port: 31415
}
2022-10-26T17:51:02.042132Z TRACE ThreadId(03) handle_client_message: mirrord_agent: GetAddrInfoRequest -> response GetAddrInfoResponse(
    Ok(
        DnsLookup(
            [
                LookupRecord {
                    name: "localhost",
                    ip: 127.0.0.1,
                },
            ],
        ),
    ),
) GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") })
2022-10-26T17:51:02.042143Z TRACE ThreadId(03) handle_client_message:respond: mirrord_agent: enter GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") }) response=GetAddrInfoResponse(GetAddrInfoResponse(Ok(DnsLookup([LookupRecord { name: "localhost", ip: 127.0.0.1 }]))))
2022-10-26T17:51:02.042156Z TRACE ThreadId(03) handle_client_message:respond: actix_codec::framed: flushing framed transport     GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") }) response=GetAddrInfoResponse(GetAddrInfoResponse(Ok(DnsLookup([LookupRecord { name: "localhost", ip: 127.0.0.1 }]))))
2022-10-26T17:51:02.042158Z TRACE ThreadId(03) handle_client_message:respond: actix_codec::framed: writing; remaining=18     GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") }) response=GetAddrInfoResponse(GetAddrInfoResponse(Ok(DnsLookup([LookupRecord { name: "localhost", ip: 127.0.0.1 }]))))
2022-10-26T17:51:02.042168Z TRACE ThreadId(03) handle_client_message:respond: actix_codec::framed: framed transport flushed     GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") }) response=GetAddrInfoResponse(GetAddrInfoResponse(Ok(DnsLookup([LookupRecord { name: "localhost", ip: 127.0.0.1 }]))))
2022-10-26T17:51:02.042177Z TRACE ThreadId(03) handle_client_message:respond: mirrord_agent: exit GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") }) response=GetAddrInfoResponse(GetAddrInfoResponse(Ok(DnsLookup([LookupRecord { name: "localhost", ip: 127.0.0.1 }]))))
2022-10-26T17:51:02.042180Z TRACE ThreadId(03) handle_client_message: mirrord_agent: exit GetAddrInfoRequest(GetAddrInfoRequest { node: Some("localhost") })