WVMQWENWS_6D91C42F
source=WEBVM
time=2026-11-08T10:07:55+00:00
stage=PI_HEARTBEAT
[2026-11-08T10:03:02+00:00] PI_WRAPPER_STARTED tag=WVMQWENWS_6D91C42F script=pi.py
[2026-11-08T10:03:09+00:00] PI_IMPL_FETCHED source=main characters=37586
[2026-11-08T10:03:10+00:00] booting.
[2026-11-08T10:03:10+00:00] booting..
[2026-11-08T10:03:11+00:00] IO_LOOP_SOURCE_FETCHED file=controller.py attempt=1/10 characters=41060
[2026-11-08T10:03:12+00:00] IO_LOOP_SOURCE_FETCHED file=agent.py attempt=1/10 characters=10376
[2026-11-08T10:03:13+00:00] IO_LOOP_SOURCE_FETCHED file=tcp_socks5.py attempt=1/10 characters=19424
[2026-11-08T10:03:13+00:00] RX_TX_PROOF_SKIPPED already_validated=1 override=WEBVM_RUN_RX_TX_PROOF=1
[2026-11-08T10:03:13+00:00] TCP_LINK_CONTROLLER_START kernel_id=simonday/webvm-tcp-link
[2026-11-08T10:03:16+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RUN_BEGIN", "kernel_id": "simonday/webvm-tcp-link", "poll_seconds": 10, "time": "2026-11-08T10:03:16.223+00:00", "timeout_seconds": 900}
[2026-11-08T10:03:16+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:03:16.234+00:00", "timeout_seconds": 20}
[2026-11-08T10:03:36+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 20263.331, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:03:36.506+00:00"}
[2026-11-08T10:03:36+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:03:36.511+00:00", "timeout_seconds": 20}
[2026-11-08T10:03:58+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 21887.406, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:03:58.400+00:00"}
[2026-11-08T10:03:58+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 42176.33, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:03:58.408+00:00"}
[2026-11-08T10:03:58+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_PREDEPLOY_STATUS_UNKNOWN", "kernel_id": "simonday/webvm-tcp-link", "note": "Continuing with the explicit deployment request", "time": "2026-11-08T10:03:58.412+00:00"}
[2026-11-08T10:03:59+00:00] IO_LOOP_CONTROLLER {"event": "POC_FILES_WRITTEN", "notebook_bytes": 27457, "service": "plain-python-tcp-echo-listener", "time": "2026-11-08T10:03:59.218+00:00"}
[2026-11-08T10:03:59+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-tcp-link-run/kernel"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:03:59.223+00:00", "timeout_seconds": 300}
[2026-11-08T10:04:25+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-tcp-link-run/kernel"], "duration_ms": 25321.46, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Kernel version 19 successfully pushed.  Please check progress at https://www.kaggle.com/code/simonday/webvm-tcp-link\n", "time": "2026-11-08T10:04:24.549+00:00"}
[2026-11-08T10:04:31+00:00] IO_LOOP_CONTROLLER {"event": "KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-tcp-link", "time": "2026-11-08T10:04:24.562+00:00"}
[2026-11-08T10:04:31+00:00] IO_LOOP_CONTROLLER {"event": "TCP_LINK_KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-tcp-link", "local_port": 8889, "service": "plain-python-tcp-echo-listener", "time": "2026-11-08T10:04:24.564+00:00", "wait_for_completion": false}
[2026-11-08T10:04:31+00:00] TCP_LINK_KERNEL_SUBMITTED kernel_id=simonday/webvm-tcp-link local_port=8889 service=plain-python-tcp-echo-listener
[2026-11-08T10:04:31+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:04:24.581+00:00", "timeout_seconds": 15}
[2026-11-08T10:04:40+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15377.759, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:04:39.960+00:00"}
[2026-11-08T10:04:40+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:04:39.965+00:00", "timeout_seconds": 15}
[2026-11-08T10:04:55+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15252.526, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:04:55.219+00:00"}
[2026-11-08T10:04:55+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 30656.355, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:04:55.223+00:00"}
[2026-11-08T10:04:55+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_STATUS_POLL_TIMEOUT", "kernel_id": "simonday/webvm-tcp-link", "note": "Retrying until the startup deadline instead of aborting the controller", "time": "2026-11-08T10:04:55.226+00:00", "waited_seconds": 30.7}
[2026-11-08T10:05:00+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:05:00.346+00:00", "timeout_seconds": 15}
[2026-11-08T10:05:15+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15319.91, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:05:15.666+00:00"}
[2026-11-08T10:05:15+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:05:15.677+00:00", "timeout_seconds": 15}
[2026-11-08T10:05:31+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15280.926, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:05:30.966+00:00"}
[2026-11-08T10:05:31+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 30700.055, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:05:30.975+00:00"}
[2026-11-08T10:05:31+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_STATUS_POLL_TIMEOUT", "kernel_id": "simonday/webvm-tcp-link", "note": "Retrying until the startup deadline instead of aborting the controller", "time": "2026-11-08T10:05:30.979+00:00", "waited_seconds": 66.4}
[2026-11-08T10:05:36+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:05:35.990+00:00", "timeout_seconds": 15}
[2026-11-08T10:05:52+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 16426.371, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:05:52.419+00:00"}
[2026-11-08T10:05:52+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:05:52.425+00:00", "timeout_seconds": 15}
[2026-11-08T10:06:07+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15311.539, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:06:07.757+00:00"}
[2026-11-08T10:06:07+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 31800.895, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:06:07.789+00:00"}
[2026-11-08T10:06:07+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_STATUS_POLL_TIMEOUT", "kernel_id": "simonday/webvm-tcp-link", "note": "Retrying until the startup deadline instead of aborting the controller", "time": "2026-11-08T10:06:07.799+00:00", "waited_seconds": 103.2}
[2026-11-08T10:06:12+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:06:12.823+00:00", "timeout_seconds": 15}
[2026-11-08T10:06:28+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15238.1, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:06:28.063+00:00"}
[2026-11-08T10:06:28+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:06:28.073+00:00", "timeout_seconds": 15}
[2026-11-08T10:06:44+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15969.234, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:06:44.051+00:00"}
[2026-11-08T10:06:46+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 31251.17, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:06:44.062+00:00"}
[2026-11-08T10:06:46+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_STATUS_POLL_TIMEOUT", "kernel_id": "simonday/webvm-tcp-link", "note": "Retrying until the startup deadline instead of aborting the controller", "time": "2026-11-08T10:06:44.067+00:00", "waited_seconds": 139.5}
[2026-11-08T10:06:49+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:06:49.185+00:00", "timeout_seconds": 15}
[2026-11-08T10:07:04+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15224.636, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:07:04.412+00:00"}
[2026-11-08T10:07:04+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:07:04.419+00:00", "timeout_seconds": 15}
[2026-11-08T10:07:19+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15325.995, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:07:19.765+00:00"}
[2026-11-08T10:07:19+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 30622.731, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T10:07:19.805+00:00"}
[2026-11-08T10:07:19+00:00] IO_LOOP_CONTROLLER {"error": "Kaggle read-only API command timed out in configured and proxy-bypass attempts: kaggle kernels status simonday/webvm-tcp-link", "event": "TCP_LINK_STATUS_POLL_TIMEOUT", "kernel_id": "simonday/webvm-tcp-link", "note": "Retrying until the startup deadline instead of aborting the controller", "time": "2026-11-08T10:07:19.811+00:00", "waited_seconds": 175.2}
[2026-11-08T10:07:24+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T10:07:24.828+00:00", "timeout_seconds": 15}
[2026-11-08T10:07:40+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15234.83, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:07:40.065+00:00"}
[2026-11-08T10:07:40+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "event": "API_REQUEST_START", "proxy_vars_removed": true, "time": "2026-11-08T10:07:40.071+00:00", "timeout_seconds": 15}
[2026-11-08T10:07:55+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15296.475, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T10:07:55.385+00:00"}