WVMQWENWS_6D91C42F
source=WEBVM
time=2026-11-08T07:36:10+00:00
stage=PI_WRAPPER_FINISHED
[2026-11-08T07:31:55+00:00] PI_WRAPPER_STARTED tag=WVMQWENWS_6D91C42F script=pi.py
[2026-11-08T07:32:06+00:00] PI_IMPL_FETCHED source=main characters=37466
[2026-11-08T07:32:07+00:00] booting.
[2026-11-08T07:32:08+00:00] booting..
[2026-11-08T07:32:09+00:00] IO_LOOP_SOURCE_FETCHED file=controller.py attempt=1/10 characters=36755
[2026-11-08T07:32:10+00:00] IO_LOOP_SOURCE_FETCHED file=agent.py attempt=1/10 characters=10376
[2026-11-08T07:32:11+00:00] IO_LOOP_SOURCE_FETCHED file=tcp_socks5.py attempt=1/10 characters=19424
[2026-11-08T07:32:11+00:00] RX_TX_PROOF_SKIPPED already_validated=1 override=WEBVM_RUN_RX_TX_PROOF=1
[2026-11-08T07:32:12+00:00] TCP_LINK_CONTROLLER_START kernel_id=simonday/webvm-tcp-link
[2026-11-08T07:32:15+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-08T07:32:14.969+00:00", "timeout_seconds": 900}
[2026-11-08T07:32:15+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-08T07:32:14.978+00:00", "timeout_seconds": 20}
[2026-11-08T07:32:36+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 20948.21, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:32:35.933+00:00"}
[2026-11-08T07:32: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-08T07:32:35.938+00:00", "timeout_seconds": 20}
[2026-11-08T07:32:56+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 20207.415, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:32:56.147+00:00"}
[2026-11-08T07:32:56+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 41176.32, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T07:32:56.153+00:00"}
[2026-11-08T07:32:56+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-08T07:32:56.155+00:00"}
[2026-11-08T07:32:56+00:00] TCP_LINK_INSTALL_RETRY_PATCH_APPLIED attempts=6
[2026-11-08T07:32:57+00:00] IO_LOOP_CONTROLLER {"event": "POC_FILES_WRITTEN", "notebook_bytes": 34079, "service": "tailscale-serve-tcp-to-http-connect-socks5", "time": "2026-11-08T07:32:56.943+00:00"}
[2026-11-08T07:32:57+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-08T07:32:56.946+00:00", "timeout_seconds": 300}
[2026-11-08T07:33:29+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-tcp-link-run/kernel"], "duration_ms": 32264.14, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Kernel version 11 successfully pushed.  Please check progress at https://www.kaggle.com/code/simonday/webvm-tcp-link\n", "time": "2026-11-08T07:33:29.211+00:00"}
[2026-11-08T07:33:35+00:00] IO_LOOP_CONTROLLER {"event": "KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-tcp-link", "time": "2026-11-08T07:33:29.217+00:00"}
[2026-11-08T07:33:35+00:00] IO_LOOP_CONTROLLER {"event": "TCP_LINK_KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-tcp-link", "local_port": 8889, "service": "tailscale-serve-tcp-to-http-connect-socks5", "tailnet_port": 18088, "time": "2026-11-08T07:33:29.219+00:00", "wait_for_completion": false}
[2026-11-08T07:33:35+00:00] TCP_LINK_KERNEL_SUBMITTED kernel_id=simonday/webvm-tcp-link local_port=8889 tailnet_port=18088
[2026-11-08T07:33:35+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-08T07:33:29.223+00:00", "timeout_seconds": 15}
[2026-11-08T07:33:44+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15338.025, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:33:44.562+00:00"}
[2026-11-08T07:33:44+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-08T07:33:44.568+00:00", "timeout_seconds": 15}
[2026-11-08T07:34:00+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15347.405, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:33:59.934+00:00"}
[2026-11-08T07:34:00+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 30745.15, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T07:33:59.966+00:00"}
[2026-11-08T07:34:00+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-08T07:33:59.970+00:00", "waited_seconds": 30.7}
[2026-11-08T07:34:05+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-08T07:34:04.996+00:00", "timeout_seconds": 15}
[2026-11-08T07:34:21+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15986.97, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:34:20.985+00:00"}
[2026-11-08T07:34:21+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-08T07:34:20.990+00:00", "timeout_seconds": 15}
[2026-11-08T07:34:36+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 15260.585, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:34:36.258+00:00"}
[2026-11-08T07:34:38+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 31280.0, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T07:34:36.266+00:00"}
[2026-11-08T07:34:38+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-08T07:34:36.272+00:00", "waited_seconds": 67.1}
[2026-11-08T07:34:41+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-08T07:34:41.280+00:00", "timeout_seconds": 15}
[2026-11-08T07:34:58+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 17037.235, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:34:58.319+00:00"}
[2026-11-08T07:34:58+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-08T07:34:58.324+00:00", "timeout_seconds": 15}
[2026-11-08T07:35:14+00:00] IO_LOOP_CONTROLLER {"attempt": "proxy_bypass", "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "duration_ms": 16142.145, "event": "API_REQUEST_TIMEOUT", "output_tail": "", "time": "2026-11-08T07:35:14.481+00:00"}
[2026-11-08T07:35:14+00:00] IO_LOOP_CONTROLLER {"attempts": 2, "command": ["kaggle", "kernels", "status", "simonday/webvm-tcp-link"], "elapsed_ms": 33242.335, "event": "API_REQUEST_EXHAUSTED", "read_only": true, "reason": "all permitted attempts timed out", "time": "2026-11-08T07:35:14.519+00:00"}
[2026-11-08T07:35:14+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-08T07:35:14.524+00:00", "waited_seconds": 105.3}
[2026-11-08T07:35:19+00:00] IO_LOOP_CONTROLLER {"event": "TCP_LINK_STARTUP_PENDING", "kernel_id": "simonday/webvm-tcp-link", "status_tail": "", "time": "2026-11-08T07:35:19.542+00:00", "waited_seconds": 110.3}
[2026-11-08T07:35:19+00:00] TCP_LINK_STARTUP_PENDING kernel_id=simonday/webvm-tcp-link
[2026-11-08T07:35:19+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "output", "simonday/webvm-tcp-link", "-p", "/home/user/kaggle-tcp-link-run/output/tcp_link_status_pending", "-o", "--file-pattern", "^tcp_link_status\\\\.json$"], "event": "API_REQUEST_START", "proxy_vars_removed": false, "time": "2026-11-08T07:35:19.564+00:00", "timeout_seconds": 45}
[2026-11-08T07:35:44+00:00] IO_LOOP_CONTROLLER {"attempt": "configured_environment", "command": ["kaggle", "kernels", "output", "simonday/webvm-tcp-link", "-p", "/home/user/kaggle-tcp-link-run/output/tcp_link_status_pending", "-o", "--file-pattern", "^tcp_link_status\\\\.json$"], "duration_ms": 24188.741, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "", "time": "2026-11-08T07:35:43.754+00:00"}
[2026-11-08T07:35:47+00:00] IO_LOOP_CONTROLLER {"event": "TCP_LINK_PENDING_ARTIFACT_MISSING", "kernel_id": "simonday/webvm-tcp-link", "output_exit_code": 0, "output_tail": "", "time": "2026-11-08T07:35:43.769+00:00"}
[2026-11-08T07:35:47+00:00] TCP_LINK_CONTROLLER_EXIT returncode=0
[2026-11-08T07:35:47+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=1/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:35:49+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=2/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:35:54+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=3/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:35:59+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=4/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:36:04+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=5/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:36:09+00:00] TCP_LINK_REMOTE_PROBE_WAIT attempt=6/6 reason=peer_proxy_config_not_ready
[2026-11-08T07:36:09+00:00] TCP_LINK_REMOTE_CONNECTIVITY_UNVERIFIED reason=peer_proxy_config_missing
[2026-11-08T07:36:10+00:00] PI_WRAPPER_FINISHED returncode=0