WVMQWENWS_6D91C42F
source=WEBVM
time=2026-11-07T12:59:33+00:00
stage=PI_WRAPPER_FINISHED
[2026-11-07T12:55:27+00:00] PI_WRAPPER_STARTED tag=WVMQWENWS_6D91C42F script=pi.py
[2026-11-07T12:55:37+00:00] PI_IMPL_FETCHED source=main characters=29694
[2026-11-07T12:55:38+00:00] booting.
[2026-11-07T12:55:39+00:00] booting..
[2026-11-07T12:55:40+00:00] IO_LOOP_SOURCE_FETCHED file=controller.py attempt=1/10 characters=14178
[2026-11-07T12:55:41+00:00] IO_LOOP_SOURCE_FETCHED file=agent.py attempt=1/10 characters=4423
[2026-11-07T12:55:41+00:00] IO_LOOP_CONTROLLER_START dataset_id=simonday/webvm-io-loop-rx kernel_id=simonday/webvm-io-loop-proof
[2026-11-07T12:55:44+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RUN_BEGIN", "kernel_id": "simonday/webvm-io-loop-proof", "poll_seconds": 10, "time": "2026-11-07T12:55:44.528+00:00", "timeout_seconds": 900}
[2026-11-07T12:55:45+00:00] IO_LOOP_CONTROLLER {"checksum": "b7ef52d4fa791d943cf73fed5cb5eac1600acbb3eae57929bdfbc9c6d7f7c87a", "event": "POC_FILES_WRITTEN", "notebook_bytes": 6301, "payload": "WEBVM_IO_LOOP_HELLO_V1", "request_id": "io-loop-proof-0001", "rx_bytes": 237, "sequence": 1, "time": "2026-11-07T12:55:45.385+00:00"}
[2026-11-07T12:56:44+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "status", "simonday/webvm-io-loop-rx"], "event": "API_REQUEST_START", "time": "2026-11-07T12:55:45.387+00:00", "timeout_seconds": 60}
[2026-11-07T12:56:48+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "status", "simonday/webvm-io-loop-rx"], "duration_ms": 58452.015, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "ready", "time": "2026-11-07T12:56:43.841+00:00"}
[2026-11-07T12:57:14+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RX_DATASET_EXISTENCE_PROBE", "exists": true, "time": "2026-11-07T12:56:43.847+00:00"}
[2026-11-07T12:57:14+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "version", "-p", "/home/user/kaggle-io-loop-run/dataset", "-m", "WebVM IO loop RX message sequence 1", "-r", "skip"], "event": "API_REQUEST_START", "time": "2026-11-07T12:56:44.014+00:00", "timeout_seconds": 300}
[2026-11-07T12:57:14+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "version", "-p", "/home/user/kaggle-io-loop-run/dataset", "-m", "WebVM IO loop RX message sequence 1", "-r", "skip"], "duration_ms": 29919.905, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Starting upload for file rx_message.json\n\n  0%|          | 0.00/237 [00:00<?, ?B/s]\n100%|██████████| 237/237 [00:01<00:00, 237B/s]\n100%|██████████| 237/237 [00:01<00:00, 121B/s]\nUpload successful: rx_message.json (237B)\nDataset version is being created. Please check progress at https://www.kaggle.com/datasets/simonday/webvm-io-loop-rx\n", "time": "2026-11-07T12:57:13.934+00:00"}
[2026-11-07T12:57:42+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RX_RESOURCE_PUBLISHED", "message_checksum": "b7ef52d4fa791d943cf73fed5cb5eac1600acbb3eae57929bdfbc9c6d7f7c87a", "time": "2026-11-07T12:57:13.952+00:00"}
[2026-11-07T12:57:42+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-io-loop-run/kernel"], "event": "API_REQUEST_START", "time": "2026-11-07T12:57:13.959+00:00", "timeout_seconds": 300}
[2026-11-07T12:57:42+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-io-loop-run/kernel"], "duration_ms": 28676.005, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Kernel version 3 successfully pushed.  Please check progress at https://www.kaggle.com/code/simonday/webvm-io-loop-proof\n", "time": "2026-11-07T12:57:42.636+00:00"}
[2026-11-07T12:58:07+00:00] IO_LOOP_CONTROLLER {"event": "KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-io-loop-proof", "time": "2026-11-07T12:57:42.642+00:00"}
[2026-11-07T12:58:09+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "event": "API_REQUEST_START", "time": "2026-11-07T12:57:42.644+00:00", "timeout_seconds": 60}
[2026-11-07T12:58:09+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "duration_ms": 24374.905, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.RUNNING\"\n", "time": "2026-11-07T12:58:07.019+00:00"}
[2026-11-07T12:58:17+00:00] IO_LOOP_CONTROLLER {"event": "EXECUTION_STATUS", "exit_code": 0, "kernel_id": "simonday/webvm-io-loop-proof", "status": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.RUNNING\"", "time": "2026-11-07T12:58:07.042+00:00"}
[2026-11-07T12:58:17+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "event": "API_REQUEST_START", "time": "2026-11-07T12:58:17.074+00:00", "timeout_seconds": 60}
[2026-11-07T12:58:40+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "duration_ms": 23585.565, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.ERROR\"\n", "time": "2026-11-07T12:58:40.661+00:00"}
[2026-11-07T12:59:05+00:00] IO_LOOP_CONTROLLER {"event": "EXECUTION_STATUS", "exit_code": 0, "kernel_id": "simonday/webvm-io-loop-proof", "status": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.ERROR\"", "time": "2026-11-07T12:58:40.666+00:00"}
[2026-11-07T12:59:05+00:00] IO_LOOP_CONTROLLER {"event": "EXECUTION_NOT_COMPLETE", "final_status": "ERROR", "time": "2026-11-07T12:58:40.669+00:00"}
[2026-11-07T12:59:05+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "output", "simonday/webvm-io-loop-proof", "-p", "/home/user/kaggle-io-loop-run/output/diagnostics", "-o"], "event": "API_REQUEST_START", "time": "2026-11-07T12:58:40.672+00:00", "timeout_seconds": 300}
[2026-11-07T12:59:05+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "output", "simonday/webvm-io-loop-proof", "-p", "/home/user/kaggle-io-loop-run/output/diagnostics", "-o"], "duration_ms": 24482.166, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Kernel log downloaded to /home/user/kaggle-io-loop-run/output/diagnostics/webvm-io-loop-proof.log \n", "time": "2026-11-07T12:59:05.155+00:00"}
[2026-11-07T12:59:30+00:00] IO_LOOP_CONTROLLER {"event": "FAILURE_ARTIFACTS_DOWNLOAD", "exit_code": 0, "files": ["webvm-io-loop-proof.log"], "output_tail": "Kernel log downloaded to /home/user/kaggle-io-loop-run/output/diagnostics/webvm-io-loop-proof.log \n", "time": "2026-11-07T12:59:05.178+00:00"}
[2026-11-07T12:59:33+00:00] IO_LOOP_CONTROLLER {"bytes": 5665, "content": "k__.ipynb\\\",progress_bar=False,log_output=True,stdout_file=sys.stdout,stderr_file=sys.stderr,allow_errors=False,timeout=43200)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916855279,\"data\":\"                                      ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916860963,\"data\":\"  File \\\"/usr/local/lib/python3.13/dist-packages/papermill/execute.py\\\", line 131, in execute_notebook\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916866033,\"data\":\"    raise_for_execution_errors(nb, output_path)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916870791000001,\"data\":\"    ~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916876027,\"data\":\"  File \\\"/usr/local/lib/python3.13/dist-packages/papermill/execute.py\\\", line 251, in raise_for_execution_errors\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916880908,\"data\":\"    raise error\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916885522,\"data\":\"papermill.exceptions.PapermillExecutionError: \\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916890271,\"data\":\"---------------------------------------------------------------------------\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.91689511,\"data\":\"Exception encountered at \\\"In [1]\\\":\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916899743,\"data\":\"---------------------------------------------------------------------------\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916904171,\"data\":\"FileNotFoundError                         Traceback (most recent call last)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916908906,\"data\":\"/tmp/ipykernel_16/261442210.py in \\u003ccell line: 0\\u003e()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916913687,\"data\":\"     82 \\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.91691828,\"data\":\"     83 if __name__ == \\\"__main__\\\":\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916923092,\"data\":\"---\\u003e 84     main()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916927843,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916932235,\"data\":\"/tmp/ipykernel_16/261442210.py in main()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916950004,\"data\":\"     34             log(\\\"RX_PATH_DISCOVERED\\\", path=str(rx_path))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916955182,\"data\":\"     35     if not rx_path.is_file():\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916960133,\"data\":\"---\\u003e 36         raise FileNotFoundError(\\\"RX message not found at \\\" + str(rx_path))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916964411,\"data\":\"     37     raw = rx_path.read_bytes()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916967416,\"data\":\"     38     message = json.loads(raw.decode(\\\"utf-8\\\"))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916970536000001,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916973358,\"data\":\"FileNotFoundError: RX message not found at /kaggle/input/webvm-io-loop-rx/rx_message.json\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":9.916978027999999,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":12.747037156,\"data\":\"/usr/local/lib/python3.13/dist-packages/mistune.py:435: SyntaxWarning: invalid escape sequence '\\\\|'\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":12.747071529,\"data\":\"  cells[i][c] = re.sub('\\\\\\\\\\\\\\\\\\\\|', '|', cell)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":12.941105906,\"data\":\"/usr/local/lib/python3.13/dist-packages/nbconvert/filters/filter_links.py:36: SyntaxWarning: invalid escape sequence '\\\\_'\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":12.941132708,\"data\":\"  text = re.sub(r'_', '\\\\_', text) # Escape underscores in display text\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":13.806573758,\"data\":\"[NbConvertApp] Converting notebook __notebook__.ipynb to notebook\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":13.900536646,\"data\":\"[NbConvertApp] Writing 10075 bytes to __notebook__.ipynb\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":17.081789317,\"data\":\"[NbConvertApp] Converting notebook __notebook__.ipynb to html\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":17.737228527,\"data\":\"[NbConvertApp] Writing 297759 bytes to __results__.html\\n\"}\n]", "event": "FAILURE_ARTIFACT_CONTENT", "file": "webvm-io-loop-proof.log", "time": "2026-11-07T12:59:05.188+00:00"}
[2026-11-07T12:59:33+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "pull", "simonday/webvm-io-loop-proof", "-p", "/home/user/kaggle-io-loop-run/output/kernel_source", "-m"], "event": "API_REQUEST_START", "time": "2026-11-07T12:59:05.191+00:00", "timeout_seconds": 120}
[2026-11-07T12:59:33+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "pull", "simonday/webvm-io-loop-proof", "-p", "/home/user/kaggle-io-loop-run/output/kernel_source", "-m"], "duration_ms": 24699.025, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Source code and metadata downloaded to /home/user/kaggle-io-loop-run/output/kernel_source\n", "time": "2026-11-07T12:59:29.891+00:00"}
[2026-11-07T12:59:33+00:00] IO_LOOP_CONTROLLER {"event": "FAILURE_KERNEL_SOURCE_PULL", "exit_code": 0, "files": ["kernel-metadata.json", "webvm-io-loop-proof.ipynb"], "output_tail": "Source code and metadata downloaded to /home/user/kaggle-io-loop-run/output/kernel_source\n", "time": "2026-11-07T12:59:29.910+00:00"}
[2026-11-07T12:59:33+00:00] Traceback (most recent call last):
[2026-11-07T12:59:33+00:00]   File "/home/user/kaggle-io-loop/controller.py", line 239, in <module>
[2026-11-07T12:59:33+00:00]     main()
[2026-11-07T12:59:33+00:00]   File "/home/user/kaggle-io-loop/controller.py", line 226, in main
[2026-11-07T12:59:33+00:00]     raise RuntimeError("Kaggle kernel did not complete successfully: " + str(final_status or "timeout") +
[2026-11-07T12:59:33+00:00] RuntimeError: Kaggle kernel did not complete successfully: ERROR; diagnostics=/home/user/kaggle-io-loop-run/output/diagnostics; kernel_source=/home/user/kaggle-io-loop-run/output/kernel_source
[2026-11-07T12:59:33+00:00] IO_LOOP_CONTROLLER_EXIT returncode=1
[2026-11-07T12:59:33+00:00] Traceback (most recent call last):
[2026-11-07T12:59:33+00:00]   File "/home/user/examples/python3/pi.py", line 65, in <module>
[2026-11-07T12:59:33+00:00]     main()
[2026-11-07T12:59:33+00:00]   File "https://raw.githubusercontent.com/scatterp2/webvm/main/examples/python3/pi_impl.py", line 755, in main
[2026-11-07T12:59:33+00:00]   File "https://raw.githubusercontent.com/scatterp2/webvm/main/examples/python3/pi_impl.py", line 740, in run_io_loop_proof
[2026-11-07T12:59:33+00:00] RuntimeError: Kaggle API-mediated IO loop proof failed with exit code 1
[2026-11-07T12:59:33+00:00] PI_WRAPPER_FINISHED returncode=1