Bug report logs e185205776dc4e3b9f617df4578bb2ac.log

logs/e185205776dc4e3b9f617df4578bb2ac.log

@@ -0,0 +1,200 @@
+2026-06-17 08:42:08,324 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=X1C, prot_c=False)
+2026-06-17 08:42:08,352 INFO [backend.app.services.bambu_ftp] [-] FTP connecting to [IP] for upload (model=X1C, mode=prot_p, socket_timeout=30.0s)...
+2026-06-17 08:42:08,488 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=X1C, prot_c=False)
+2026-06-17 08:42:08,488 INFO [backend.app.services.bambu_ftp] [-] FTP connected to [IP]
+2026-06-17 08:42:08,489 INFO [backend.app.services.bambu_ftp] [-] FTP uploading /app/data/archive/2/20260616_115159_Isaac Listening Stations X1C Prints (0626)_plate_12/Isaac Listening Stations X1C Prints (0626)_plate_12.gcode.3mf (2661402 bytes) to /Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf
+2026-06-17 08:42:08,550 INFO [backend.app.services.bambu_ftp] [-] FTP data channel ready in 0.1s (PASV + TLS handshake)
+2026-06-17 08:42:15,121 INFO [backend.app.api.routes.printers] [4a9c77d3] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:42:15,140 INFO [backend.app.api.routes.printers] [3c75df9a] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:42:15,177 INFO [backend.app.api.routes.printers] [93cb3f4c] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:42:15,226 INFO [backend.app.api.routes.printers] [02dcc85f] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:42:42,631 WARNING [backend.app.services.bambu_ftp] [-] FTP STOR returned error_temp for /Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf but file is intact on the printer (2661402 bytes match) — proceeding: 426 Failure reading network stream.
+2026-06-17 08:42:42,631 INFO [backend.app.services.bambu_ftp] [-] FTP upload complete: /Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf (2661402 bytes in 34.1s, 76 KB/s)
+2026-06-17 08:42:42,631 INFO [backend.app.services.bambu_ftp] [-] FTP mode cached for [IP]: prot_p
+2026-06-17 08:42:42,640 INFO [backend.app.main] [-] Registered expected print: printer=1, file=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf, archive=241, ams_mapping=[-1, 2, 0], plate_id=12
+2026-06-17 08:42:42,660 INFO [backend.app.services.print_scheduler] [-] Queue item 206: Status set to 'printing', sending print command...
+2026-06-17 08:42:42,660 INFO [backend.app.services.printer_manager] [-] PRINT COMMAND: printer=1, file=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf, caller=print_scheduler.py:317:check_queue
+2026-06-17 08:42:42,660 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Sending print command: {"print": {"sequence_id": "20000", "command": "project_file", "param": "Metadata/plate_12.gcode", "url": "ftp://Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf", "file": "Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12.3mf", "md5": "", "bed_type": "auto", "timelapse": false, "bed_leveling": true, "auto_bed_leveling": 1, "flow_cali": false, "vibration_cali": true, "layer_inspect": false, "use_ams": true, "cfg": "0", "extrude_cali_flag": 0, "extrude_cali_manual_mode": 0, "nozzle_offset_cali": 0, "subtask_name": "Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12", "profile_id": "0", "project_id": "1439819297", "subtask_id": "1439819297", "task_id": "1439819297", "ams_mapping": [-1, 2, 0], "ams_mapping2": [{"ams_id": 255, "slot_id": 255}, {"ams_id": 0, "slot_id": 2}, {"ams_id": 0, "slot_id": 0}]}}
+2026-06-17 08:42:42,661 INFO [backend.app.services.print_scheduler] [-] Queue item 206: Print started successfully - Isaac Listening Stations X1C Prints (0626)_plate_12.gcode.3mf
+2026-06-17 08:42:42,671 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=FINISH, awaiting_plate_clear=False
+2026-06-17 08:42:42,672 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:42:42,672 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:42:42,686 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Captured ams_mapping from print command: [-1, 2, 0]
+2026-06-17 08:42:50,526 INFO [backend.app.services.mqtt_relay] [4eef5cdc] MQTT relay disabled
+2026-06-17 08:42:50,547 INFO [uvicorn.access] [-] [IP]:36382 - "PUT /api/v1/settings/ HTTP/1.1" 200
+2026-06-17 08:42:57,589 INFO [backend.app.services.mqtt_relay] [106251cf] MQTT relay disabled
+2026-06-17 08:42:57,609 INFO [uvicorn.access] [-] [IP]:51450 - "PUT /api/v1/settings/ HTTP/1.1" 200
+2026-06-17 08:43:12,570 INFO [backend.app.api.routes.printers] [69520b45] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:43:12,583 INFO [backend.app.api.routes.printers] [60e6b27a] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:43:12,640 INFO [backend.app.api.routes.printers] [36d77115] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:43:12,651 INFO [backend.app.api.routes.printers] [0726b323] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:43:12,749 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:43:12,771 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=FINISH, awaiting_plate_clear=False
+2026-06-17 08:43:12,771 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:43:12,771 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:43:19,820 INFO [backend.app.api.routes.printers] [ccaaa8f8] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:43:21,831 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] PRINT START detected - file: /data/Metadata/plate_12.gcode, subtask: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12, is_new: True, is_file_change: False
+2026-06-17 08:43:21,832 INFO [backend.app.main] [-] [CALLBACK] on_print_start called for printer 1, data keys: ['filename', 'subtask_name', 'remaining_time', 'raw_data', 'ams_mapping']
+2026-06-17 08:43:21,858 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Skipped trays with invalid remain% for printer 1: AMS0-T0(remain=-1), AMS0-T2(remain=-1), AMS0-T3(remain=-1), AMS128-T0(remain=-1)
+2026-06-17 08:43:21,858 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1: mapping=[65535, 2, 0], tray_now=255, last_loaded_tray=0
+2026-06-17 08:43:21,858 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1: mapping-related keys: {'mapping': [65535, 2, 0], 'ams_extruder_map': {'0': 0, '128': 0}}
+2026-06-17 08:43:21,859 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1 AMS 0: T0(type=PETG, color=000000FF, now=?, tar=?), T1(type=PLA-S, color=00000000, now=?, tar=?), T2(type=PETG, color=000000FF, now=?, tar=?), T3(type=PETG, color=000000FF, now=?, tar=?)
+2026-06-17 08:43:21,859 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1 AMS 128: T0(type=, color=, now=?, tar=?)
+2026-06-17 08:43:21,863 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Snapshotted 4 spool assignments for printer 1: {'0-0': 20, '0-1': 15, '0-2': 22, '0-3': 19}
+2026-06-17 08:43:21,868 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Captured start remain% for printer 1 (2 trays): {'0-1': 53, '255-0': 0}
+2026-06-17 08:43:21,885 INFO [backend.app.main] [-] [PLATE CHECK] printer_id=1, plate_detection_enabled=False
+2026-06-17 08:43:21,885 INFO [backend.app.main] [-] [CALLBACK] Print start detected - filename: /data/Metadata/plate_12.gcode, subtask: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:43:21,885 INFO [backend.app.main] [-] Using expected archive 241 for print (skipping duplicate)
+2026-06-17 08:43:21,903 INFO [backend.app.main] [-] [ENERGY] No smart plug for printer 1 (archive 241)
+2026-06-17 08:43:21,916 INFO [backend.app.main] [-] [SNAPSHOT] Using buffered frame for printer 1: 58566 bytes
+2026-06-17 08:43:21,916 INFO [backend.app.services.notification_service] [-] on_print_start called for printer 1 ([PRINTER])
+2026-06-17 08:43:21,928 INFO [backend.app.services.notification_service] [-] Found 1 providers for print_start: ["Juanpi's Notifications"]
+2026-06-17 08:43:22,105 INFO [backend.app.api.routes.printers] [a119ae8d] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:43:22,106 INFO [backend.app.api.routes.printers] [a119ae8d] Cover using cached 3MF from /app/data/archive/2/20260616_115159_Isaac Listening Stations X1C Prints (0626)_plate_12/Isaac Listening Stations X1C Prints (0626)_plate_12.gcode.3mf (avoided duplicate FTP)
+2026-06-17 08:43:22,106 INFO [backend.app.api.routes.printers] [a119ae8d] Downloaded file size: 2661402 bytes
+2026-06-17 08:43:22,177 INFO [backend.app.services.notification_service] [-] Sent notification via Juanpi's Notifications
+2026-06-17 08:43:22,191 INFO [backend.app.main] [-] Loaded 1 printable objects for printer 1
+2026-06-17 08:43:22,343 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=X1C, prot_c=False)
+2026-06-17 08:43:22,998 INFO [backend.app.main] [-] [TIMELAPSE] Baseline at print start: 571 video files for printer 1
+2026-06-17 08:43:23,109 INFO [backend.app.api.routes.printers] [e09d9867] Cover: resolved plate 4 before download (subtask=Push_Assembly_Filler_(Prod))
+2026-06-17 08:43:23,109 INFO [backend.app.api.routes.printers] [e09d9867] Cover using cached 3MF from /app/data/archive/3/20260508_185503_Push Assembly Filler (Prod).gcode/aa589044ac0f46e2a12d927006cdf96b.3mf (avoided duplicate FTP)
+2026-06-17 08:43:23,109 INFO [backend.app.api.routes.printers] [e09d9867] Downloaded file size: 12377173 bytes
+2026-06-17 08:43:42,820 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:43:42,837 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:43:42,837 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:43:42,837 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:43:52,872 INFO [backend.app.api.routes.camera] [4fb04ab1] Camera viewer detached from printer-3 (subscribers=0)
+2026-06-17 08:43:52,882 INFO [backend.app.api.routes.camera] [ab2d846b] Camera viewer detached from printer-1 (subscribers=0)
+2026-06-17 08:43:53,023 INFO [uvicorn.access] [-] [IP]:38964 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-06-17 08:43:53,052 INFO [backend.app.api.routes.camera] [7388a029] Camera viewer detached from printer-2 (subscribers=0)
+2026-06-17 08:43:53,110 INFO [backend.app.api.routes.printers] [2b707b33] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:43:53,118 INFO [backend.app.api.routes.camera] [e8816153] Using RTSP protocol for X1C
+2026-06-17 08:43:53,118 INFO [backend.app.api.routes.camera] [e8816153] Camera viewer attached to printer-2 (subscribers=1)
+2026-06-17 08:43:53,124 INFO [backend.app.api.routes.printers] [dd7d2632] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:43:53,254 INFO [backend.app.api.routes.camera] [db24d93b] Using RTSP protocol for H2C
+2026-06-17 08:43:53,254 INFO [backend.app.api.routes.camera] [db24d93b] Camera viewer attached to printer-3 (subscribers=1)
+2026-06-17 08:43:53,273 INFO [backend.app.api.routes.camera] [dbaef7b7] Using RTSP protocol for X1C
+2026-06-17 08:43:53,273 INFO [backend.app.api.routes.camera] [dbaef7b7] Camera viewer attached to printer-1 (subscribers=1)
+2026-06-17 08:44:02,133 INFO [backend.app.main] [-] Recorded 5 AMS sensor history entries
+2026-06-17 08:44:12,899 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:44:12,943 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:44:12,944 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:44:12,944 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:44:43,042 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:44:43,075 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:44:43,076 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:44:43,076 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:13,140 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:45:13,162 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:13,162 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:13,162 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:43,215 INFO [backend.app.services.print_scheduler] [-] Queue check: found 19 pending items: [(182, None, 138, None), (183, None, 138, None), (184, None, 138, None), (208, 2, 241, None), (209, 2, 241, None), (210, 2, 241, None), (211, 2, 241, None), (212, 2, 241, None), (213, 2, 241, None), (214, 2, 241, None), (215, 2, 241, None), (216, 2, 241, None), (217, 2, 241, None), (218, 2, 241, None), (219, 2, 241, None), (220, 2, 241, None), (221, 2, 241, None), (222, 2, 241, None), (223, 2, 241, None)]
+2026-06-17 08:45:43,237 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:43,238 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:43,238 INFO [backend.app.services.print_scheduler] [-] Queue: printer 3 not available — connected=True, state=RUNNING, awaiting_plate_clear=False
+2026-06-17 08:45:58,236 INFO [backend.app.api.routes.camera] [db24d93b] Camera viewer detached from printer-3 (subscribers=0)
+2026-06-17 08:45:58,248 INFO [backend.app.api.routes.camera] [dbaef7b7] Camera viewer detached from printer-1 (subscribers=0)
+2026-06-17 08:45:58,401 INFO [uvicorn.access] [-] [IP]:41810 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-06-17 08:45:58,429 INFO [backend.app.api.routes.camera] [e8816153] Camera viewer detached from printer-2 (subscribers=0)
+2026-06-17 08:45:58,492 INFO [backend.app.api.routes.printers] [ba7f044a] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:45:58,492 INFO [backend.app.api.routes.camera] [3f01d65c] Using RTSP protocol for X1C
+2026-06-17 08:45:58,493 INFO [backend.app.api.routes.camera] [3f01d65c] Camera viewer attached to printer-2 (subscribers=1)
+2026-06-17 08:45:58,497 INFO [backend.app.api.routes.printers] [41a8bb55] Cover: resolved plate 12 before download (subtask=Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12)
+2026-06-17 08:45:58,653 INFO [backend.app.api.routes.camera] [db2b1d08] Using RTSP protocol for H2C
+2026-06-17 08:45:58,654 INFO [backend.app.api.routes.camera] [db2b1d08] Camera viewer attached to printer-3 (subscribers=1)
+2026-06-17 08:45:58,664 INFO [backend.app.api.routes.camera] [2a73d104] Using RTSP protocol for X1C
+2026-06-17 08:45:58,664 INFO [backend.app.api.routes.camera] [2a73d104] Camera viewer attached to printer-1 (subscribers=1)
+2026-06-17 08:45:59,644 INFO [backend.app.api.routes.support] [8db93e86] Log level changed to DEBUG
+2026-06-17 08:45:59,644 INFO [backend.app.api.routes.bug_report] [8db93e86] Bug report: enabled debug logging
+2026-06-17 08:45:59,645 DEBUG [backend.app.services.bambu_mqtt] [8db93e86] [[SERIAL]] Requesting status update (pushall)
+2026-06-17 08:45:59,645 DEBUG [backend.app.services.bambu_mqtt] [8db93e86] [[SERIAL]] Requesting status update (pushall)
+2026-06-17 08:45:59,646 DEBUG [backend.app.services.bambu_mqtt] [8db93e86] [[SERIAL]] Requesting status update (pushall)
+2026-06-17 08:45:59,649 INFO [uvicorn.access] [-] [IP]:39626 - "POST /api/v1/bug-report/start-logging HTTP/1.1" 200
+2026-06-17 08:45:59,725 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_[USER]er_detector': True, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': False, 'spaghetti_detector': False}
+2026-06-17 08:45:59,725 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_[USER]er_detector', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-06-17 08:45:59,725 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_12.gcode, subtask_name: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:45:59,725 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '11', 'ams_exist_bits_raw': '11', 'cali_id': 0, 'cali_stat': 0, 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': 'f', 'tray_is_bbl_bits': 'f', 'tray_now': '0', 'tray_pre': '0', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 7819}
+2026-06-17 08:45:59,725 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 0
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 2 new units, 2 total
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1001 -> extruder 0
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x2004 -> extruder 0
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0, '128': 0}
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=1 (switch_state bits 12-14: 0)
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 35°C (heater OFF)
+2026-06-17 08:45:59,726 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-06-17 08:45:59,727 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=35.0, heating=False, respect_local=False
+2026-06-17 08:45:59,727 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 35.0, target: 0.0, heating: False
+2026-06-17 08:45:59,727 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-06-17 08:45:59,727 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'agora_service': 'disable', 'brtc_service': 'enable', 'bs_state': 0, 'ipcam_dev': '1', 'ipcam_record': 'enable', 'laser_preview_res': 7, 'mode_bits': 2, 'resolution': '720p', 'rtsp_url': 'rtsps://[IP]:322/streaming/live/1', 'timelapse': 'disable', 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-06-17 08:45:59,728 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -45dBm
+2026-06-17 08:45:59,728 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-06-17 08:45:59,729 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [65535, 2, 0]
+2026-06-17 08:45:59,729 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_12.gcode, subtask: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:46:00,000 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_[USER]er_detector': True, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-06-17 08:46:00,000 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_[USER]er_detector', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-06-17 08:46:00,000 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_12.gcode, subtask_name: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:46:00,000 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '11', 'ams_exist_bits_raw': '11', 'cali_id': 0, 'cali_stat': 0, 'insert_flag': False, 'power_on_flag': False, 'tray_exist_bits': 'f', 'tray_is_bbl_bits': 'f', 'tray_now': '255', 'tray_pre': '255', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 245717}
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 255
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 2 new units, 2 total
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1001 -> extruder 0
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x2004 -> extruder 0
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0, '128': 0}
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 258 (main=1, sub=2)
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-06-17 08:46:00,001 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=524289 (switch_state bits 12-14: 0)
+2026-06-17 08:46:00,002 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 31°C (heater OFF)
+2026-06-17 08:46:00,002 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-06-17 08:46:00,004 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=31.0, heating=False, respect_local=False
+2026-06-17 08:46:00,005 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 31.0, target: 0.0, heating: False
+2026-06-17 08:46:00,005 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: [{'attr': 201326848, 'code': 65546}, {'attr': 83886336, 'code': 196612}]
+2026-06-17 08:46:00,006 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'agora_service': 'disable', 'brtc_service': 'enable', 'bs_state': 0, 'ipcam_dev': '1', 'ipcam_record': 'enable', 'laser_preview_res': 7, 'mode_bits': 2, 'resolution': '1080p', 'rtsp_url': 'rtsps://[IP]:322/streaming/live/1', 'timelapse': 'disable', 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-06-17 08:46:00,006 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -54dBm
+2026-06-17 08:46:00,006 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-06-17 08:46:00,006 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [65535, 2, 0]
+2026-06-17 08:46:00,006 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_12.gcode, subtask: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:46:00,467 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_[USER]er_detector': True, 'cfg': 1780887, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-06-17 08:46:00,467 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_[USER]er_detector', 'cfg', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-06-17 08:46:00,467 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 1780887 (binary: 0b110110010110010010111)
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_4.gcode, subtask_name: Push_Assembly_Filler_(Prod)
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '1', 'ams_exist_bits_raw': '1', 'cali_id': 255, 'cali_stat': 0, 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': 'f', 'tray_is_bbl_bits': 'f', 'tray_now': '0', 'tray_pre': '0', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 39676}
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 0
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 1 new units, 1 total
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1003 -> extruder 0
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0}
+2026-06-17 08:46:00,468 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-06-17 08:46:00,469 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-06-17 08:46:00,469 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=2 (switch_state bits 12-14: 0)
+2026-06-17 08:46:00,469 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 36°C (heater OFF)
+2026-06-17 08:46:00,470 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-06-17 08:46:00,470 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=36.0, heating=False, respect_local=False
+2026-06-17 08:46:00,470 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 36.0, target: 0.0, heating: False
+2026-06-17 08:46:00,471 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: [{'attr': 50370048, 'code': 196609}]
+2026-06-17 08:46:00,471 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'agora_service': 'disable', 'brtc_service': 'enable', 'bs_state': 0, 'cap_pic_enable': 'invalid', 'ipcam_dev': '1', 'ipcam_record': 'enable', 'laser_preview_res': 6, 'mode_bits': 2, 'resolution': '1080p', 'rtsp_url': 'rtsps://[IP]:322/streaming/live/1', 'timelapse': 'disable', 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-06-17 08:46:00,471 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -50dBm
+2026-06-17 08:46:00,472 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}, {'mode': 'on', 'node': 'chamber_light2'}]
+2026-06-17 08:46:00,472 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [0]
+2026-06-17 08:46:00,472 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_4.gcode, subtask: Push_Assembly_Filler_(Prod)
+2026-06-17 08:46:00,786 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_[USER]er_detector': True, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': False, 'spaghetti_detector': False}
+2026-06-17 08:46:00,786 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_[USER]er_detector', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-06-17 08:46:00,792 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_12.gcode, subtask_name: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12
+2026-06-17 08:46:00,793 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '11', 'ams_exist_bits_raw': '11', 'cali_id': 0, 'cali_stat': 0, 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': 'f', 'tray_is_bbl_bits': 'f', 'tray_now': '0', 'tray_pre': '0', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 7819}
+2026-06-17 08:46:00,793 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 0
+2026-06-17 08:46:00,794 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 2 new units, 2 total
+2026-06-17 08:46:00,794 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1001 -> extruder 0
+2026-06-17 08:46:00,794 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x2004 -> extruder 0
+2026-06-17 08:46:00,795 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0, '128': 0}
+2026-06-17 08:46:00,795 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-06-17 08:46:00,795 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-06-17 08:46:00,796 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=1 (switch_state bits 12-14: 0)
+2026-06-17 08:46:00,796 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 35°C (heater OFF)
+2026-06-17 08:46:00,797 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-06-17 08:46:00,798 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=35.0, heating=False, respect_local=False
+2026-06-17 08:46:00,799 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 35.0, target: 0.0, heating: False
+2026-06-17 08:46:00,799 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-06-17 08:46:00,800 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'agora_service': 'disable', 'brtc_service': 'enable', 'bs_state': 0, 'ipcam_dev': '1', 'ipcam_record': 'enable', 'laser_preview_res': 7, 'mode_bits': 2, 'resolution': '720p', 'rtsp_url': 'rtsps://[IP]:322/streaming/live/1', 'timelapse': 'disable', 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-06-17 08:46:00,801 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -45dBm
+2026-06-17 08:46:00,801 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-06-17 08:46:00,801 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [65535, 2, 0]
+2026-06-17 08:46:00,802 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_12.gcode, subtask: Isaac_Listening_Stations_X1C_Prints_(0626)_plate_12