WVMQWENWS_6D91C42F
source=WEBVM
time=2026-11-07T13:19:56+00:00
stage=PI_WRAPPER_FINISHED
[2026-11-07T13:16:00+00:00] PI_WRAPPER_STARTED tag=WVMQWENWS_6D91C42F script=pi.py
[2026-11-07T13:16:12+00:00] PI_IMPL_FETCHED source=main characters=29694
[2026-11-07T13:16:13+00:00] booting.
[2026-11-07T13:16:13+00:00] booting..
[2026-11-07T13:16:14+00:00] IO_LOOP_SOURCE_FETCHED file=controller.py attempt=1/10 characters=16432
[2026-11-07T13:16:15+00:00] IO_LOOP_SOURCE_FETCHED file=agent.py attempt=1/10 characters=4423
[2026-11-07T13:16:15+00:00] IO_LOOP_CONTROLLER_START dataset_id=simonday/webvm-io-loop-rx kernel_id=simonday/webvm-io-loop-proof
[2026-11-07T13:16:18+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-07T13:16:17.973+00:00", "timeout_seconds": 900}
[2026-11-07T13:16:18+00:00] IO_LOOP_CONTROLLER {"checksum": "d7c6aaa61d31c1d172e5a2ddf9feb607b03c05b09859e8eb55c0dd421d8e4659", "event": "POC_FILES_WRITTEN", "notebook_bytes": 6301, "payload": "WEBVM_IO_LOOP_HELLO_V1", "request_id": "io-loop-proof-20261107T131617982849Z", "rx_bytes": 255, "sequence": 1, "time": "2026-11-07T13:16:18.130+00:00"}
[2026-11-07T13:16:41+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "status", "simonday/webvm-io-loop-rx"], "event": "API_REQUEST_START", "time": "2026-11-07T13:16:18.132+00:00", "timeout_seconds": 60}
[2026-11-07T13:16:41+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "status", "simonday/webvm-io-loop-rx"], "duration_ms": 23155.035, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "ready", "time": "2026-11-07T13:16:41.290+00:00"}
[2026-11-07T13:17:12+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RX_DATASET_EXISTENCE_PROBE", "exists": true, "time": "2026-11-07T13:16:41.295+00:00"}
[2026-11-07T13:17:16+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-07T13:16:41.301+00:00", "timeout_seconds": 300}
[2026-11-07T13:17:16+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": 31150.79, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Starting upload for file rx_message.json\n\n  0%|          | 0.00/255 [00:00<?, ?B/s]\n100%|██████████| 255/255 [00:01<00:00, 151B/s]\n100%|██████████| 255/255 [00:02<00:00, 101B/s]\nUpload successful: rx_message.json (255B)\nDataset version is being created. Please check progress at https://www.kaggle.com/datasets/simonday/webvm-io-loop-rx\n", "time": "2026-11-07T13:17:12.452+00:00"}
[2026-11-07T13:17:42+00:00] IO_LOOP_CONTROLLER {"dataset_id": "simonday/webvm-io-loop-rx", "event": "RX_RESOURCE_PUBLISHED", "message_checksum": "d7c6aaa61d31c1d172e5a2ddf9feb607b03c05b09859e8eb55c0dd421d8e4659", "time": "2026-11-07T13:17:12.462+00:00"}
[2026-11-07T13:17:42+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "download", "simonday/webvm-io-loop-rx", "-f", "rx_message.json", "-p", "/home/user/kaggle-io-loop-run/output/published_rx_verify", "--unzip", "-o"], "event": "API_REQUEST_START", "time": "2026-11-07T13:17:12.466+00:00", "timeout_seconds": 90}
[2026-11-07T13:17:42+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "datasets", "download", "simonday/webvm-io-loop-rx", "-f", "rx_message.json", "-p", "/home/user/kaggle-io-loop-run/output/published_rx_verify", "--unzip", "-o"], "duration_ms": 29418.355, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Dataset URL: https://www.kaggle.com/datasets/simonday/webvm-io-loop-rx\nLicense(s): CC0-1.0\nDownloading rx_message.json to /home/user/kaggle-io-loop-run/output/published_rx_verify\n\n  0%|          | 0.00/255 [00:00<?, ?B/s]\n100%|██████████| 255/255 [00:00<00:00, 4.19kB/s]\n\n", "time": "2026-11-07T13:17:41.885+00:00"}
[2026-11-07T13:18:07+00:00] IO_LOOP_CONTROLLER {"checksum": "d7c6aaa61d31c1d172e5a2ddf9feb607b03c05b09859e8eb55c0dd421d8e4659", "dataset_id": "simonday/webvm-io-loop-rx", "event": "RX_PUBLICATION_VERIFIED", "file": "/home/user/kaggle-io-loop-run/output/published_rx_verify/rx_message.json", "request_id": "io-loop-proof-20261107T131617982849Z", "time": "2026-11-07T13:17:41.913+00:00"}
[2026-11-07T13:18:08+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-io-loop-run/kernel"], "event": "API_REQUEST_START", "time": "2026-11-07T13:17:41.918+00:00", "timeout_seconds": 300}
[2026-11-07T13:18:08+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "push", "-p", "/home/user/kaggle-io-loop-run/kernel"], "duration_ms": 25940.611, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "Kernel version 5 successfully pushed.  Please check progress at https://www.kaggle.com/code/simonday/webvm-io-loop-proof\n", "time": "2026-11-07T13:18:07.860+00:00"}
[2026-11-07T13:18:30+00:00] IO_LOOP_CONTROLLER {"event": "KERNEL_SUBMITTED", "kernel_id": "simonday/webvm-io-loop-proof", "time": "2026-11-07T13:18:07.871+00:00"}
[2026-11-07T13:18:32+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "event": "API_REQUEST_START", "time": "2026-11-07T13:18:07.873+00:00", "timeout_seconds": 60}
[2026-11-07T13:18:32+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "duration_ms": 22484.219, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.RUNNING\"\n", "time": "2026-11-07T13:18:30.357+00:00"}
[2026-11-07T13:18:40+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-07T13:18:30.370+00:00"}
[2026-11-07T13:18:40+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "event": "API_REQUEST_START", "time": "2026-11-07T13:18:40.393+00:00", "timeout_seconds": 60}
[2026-11-07T13:19:05+00:00] IO_LOOP_CONTROLLER {"command": ["kaggle", "kernels", "status", "simonday/webvm-io-loop-proof"], "duration_ms": 24726.634, "event": "API_REQUEST_RESULT", "exit_code": 0, "output_tail": "simonday/webvm-io-loop-proof has status \"KernelWorkerStatus.ERROR\"\n", "time": "2026-11-07T13:19:05.119+00:00"}
[2026-11-07T13:19:28+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-07T13:19:05.140+00:00"}
[2026-11-07T13:19:28+00:00] IO_LOOP_CONTROLLER {"event": "EXECUTION_NOT_COMPLETE", "final_status": "ERROR", "time": "2026-11-07T13:19:05.148+00:00"}
[2026-11-07T13:19:28+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-07T13:19:05.151+00:00", "timeout_seconds": 300}
[2026-11-07T13:19:28+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": 23707.221, "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-07T13:19:28.859+00:00"}
[2026-11-07T13:19:29+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-07T13:19:28.998+00:00"}
[2026-11-07T13:19:53+00:00] IO_LOOP_CONTROLLER {"bytes": 5707, "content": "e,log_output=True,stdout_file=sys.stdout,stderr_file=sys.stderr,allow_errors=False,timeout=43200)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.61408357,\"data\":\"                                      ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614088868,\"data\":\"  File \\\"/usr/local/lib/python3.13/dist-packages/papermill/execute.py\\\", line 131, in execute_notebook\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614095485,\"data\":\"    raise_for_execution_errors(nb, output_path)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614105174,\"data\":\"    ~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614108011999999,\"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\":14.614110996,\"data\":\"    raise error\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.61411366,\"data\":\"papermill.exceptions.PapermillExecutionError: \\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.61411631,\"data\":\"---------------------------------------------------------------------------\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614119132,\"data\":\"Exception encountered at \\\"In [1]\\\":\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614121912,\"data\":\"---------------------------------------------------------------------------\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614124565000001,\"data\":\"FileNotFoundError                         Traceback (most recent call last)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614127216,\"data\":\"/tmp/ipykernel_16/261442210.py in \\u003ccell line: 0\\u003e()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614130157,\"data\":\"     82 \\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614132875,\"data\":\"     83 if __name__ == \\\"__main__\\\":\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614135615,\"data\":\"---\\u003e 84     main()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614138305,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614140929,\"data\":\"/tmp/ipykernel_16/261442210.py in main()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614157917,\"data\":\"     34             log(\\\"RX_PATH_DISCOVERED\\\", path=str(rx_path))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614161075,\"data\":\"     35     if not rx_path.is_file():\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614163715,\"data\":\"---\\u003e 36         raise FileNotFoundError(\\\"RX message not found at \\\" + str(rx_path))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614166603,\"data\":\"     37     raw = rx_path.read_bytes()\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614169222,\"data\":\"     38     message = json.loads(raw.decode(\\\"utf-8\\\"))\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614171969000001,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.61417452,\"data\":\"FileNotFoundError: RX message not found at /kaggle/input/webvm-io-loop-rx/rx_message.json\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":14.614177327,\"data\":\"\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":17.902674022,\"data\":\"/usr/local/lib/python3.13/dist-packages/mistune.py:435: SyntaxWarning: invalid escape sequence '\\\\|'\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":17.902716935,\"data\":\"  cells[i][c] = re.sub('\\\\\\\\\\\\\\\\\\\\|', '|', cell)\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":18.177448827,\"data\":\"/usr/local/lib/python3.13/dist-packages/nbconvert/filters/filter_links.py:36: SyntaxWarning: invalid escape sequence '\\\\_'\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":18.177495414,\"data\":\"  text = re.sub(r'_', '\\\\_', text) # Escape underscores in display text\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":19.260242314,\"data\":\"[NbConvertApp] Converting notebook __notebook__.ipynb to notebook\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":19.356288398,\"data\":\"[NbConvertApp] Writing 10075 bytes to __notebook__.ipynb\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":22.879788691999998,\"data\":\"[NbConvertApp] Converting notebook __notebook__.ipynb to html\\n\"}\n,{\"stream_name\":\"stderr\",\"time\":23.609158898,\"data\":\"[NbConvertApp] Writing 297759 bytes to __results__.html\\n\"}\n]", "event": "FAILURE_ARTIFACT_CONTENT", "file": "webvm-io-loop-proof.log", "time": "2026-11-07T13:19:29.010+00:00"}
[2026-11-07T13:19:56+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-07T13:19:29.014+00:00", "timeout_seconds": 120}
[2026-11-07T13:19:56+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": 24483.879, "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-07T13:19:53.499+00:00"}
[2026-11-07T13:19:56+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-07T13:19:53.510+00:00"}
[2026-11-07T13:19:56+00:00] Traceback (most recent call last):
[2026-11-07T13:19:56+00:00]   File "/home/user/kaggle-io-loop/controller.py", line 274, in <module>
[2026-11-07T13:19:56+00:00]     main()
[2026-11-07T13:19:56+00:00]   File "/home/user/kaggle-io-loop/controller.py", line 261, in main
[2026-11-07T13:19:56+00:00]     raise RuntimeError("Kaggle kernel did not complete successfully: " + str(final_status or "timeout") +
[2026-11-07T13:19:56+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-07T13:19:56+00:00] IO_LOOP_CONTROLLER_EXIT returncode=1
[2026-11-07T13:19:56+00:00] Traceback (most recent call last):
[2026-11-07T13:19:56+00:00]   File "/home/user/examples/python3/pi.py", line 65, in <module>
[2026-11-07T13:19:56+00:00]     main()
[2026-11-07T13:19:56+00:00]   File "https://raw.githubusercontent.com/scatterp2/webvm/main/examples/python3/pi_impl.py", line 755, in main
[2026-11-07T13:19:56+00:00]   File "https://raw.githubusercontent.com/scatterp2/webvm/main/examples/python3/pi_impl.py", line 740, in run_io_loop_proof
[2026-11-07T13:19:56+00:00] RuntimeError: Kaggle API-mediated IO loop proof failed with exit code 1
[2026-11-07T13:19:56+00:00] PI_WRAPPER_FINISHED returncode=1