Bug report logs 4b890a3bae4f4cbcb2f38ba274da18a8.log

logs/4b890a3bae4f4cbcb2f38ba274da18a8.log

@@ -0,0 +1,200 @@
+2026-10-11 16:59:54,646 INFO [backend.app.main] [-] [FINISH-PHOTO-MOMENT] captured external-camera frame (376485 bytes)
+2026-10-11 16:59:54,647 INFO [backend.app.main] [-] [PHOTO-BG] Saved stage-22 pre-captured frame: finish_20261011_165954_16575bd9.jpg (376485 bytes)
+2026-10-11 16:59:54,651 INFO [backend.app.main] [-] [PHOTO-BG] Saved: finish_20261011_165954_16575bd9.jpg
+2026-10-11 16:59:54,651 INFO [backend.app.main] [-] [PHOTO-NOTIFY] Photo task returned: finish_20261011_165954_16575bd9.jpg
+2026-10-11 16:59:54,651 INFO [backend.app.main] [-] [NOTIFY-BG] Starting notifications for printer 3, photo=finish_20261011_165954_16575bd9.jpg
+2026-10-11 16:59:54,657 INFO [backend.app.main] [-] [NOTIFY-BG] Loaded finish photo bytes: 376485 bytes
+2026-10-11 16:59:54,657 INFO [backend.app.services.notification_service] [-] on_print_complete called for printer 3 (A1), status=completed
+2026-10-11 16:59:54,659 INFO [backend.app.services.notification_service] [-] Found 1 providers for on_print_complete: ['ntfy.sh Push']
+2026-10-11 16:59:54,825 INFO [backend.app.services.notification_service] [-] Sent notification via ntfy.sh Push
+2026-10-11 16:59:54,827 INFO [backend.app.main] [-] [NOTIFY-BG] Completed
+2026-10-11 17:00:00,195 INFO [backend.app.services.smart_plug_manager] [-] Captured 1 energy snapshot(s)
+2026-10-11 17:00:23,281 INFO [backend.app.services.layer_timelapse] [-] Created timelapse video: /var/print_storage/bambuddy/timelapse_frames/3/timelapse_20261011_161627.mp4 (146 frames)
+2026-10-11 17:00:23,296 INFO [backend.app.services.layer_timelapse] [-] Cleaned up timelapse frames for session 20261011_161627
+2026-10-11 17:00:23,296 INFO [backend.app.main] [-] [LAYER-TL] Attaching timelapse /var/print_storage/bambuddy/timelapse_frames/3/timelapse_20261011_161627.mp4 to archive 318
+2026-10-11 17:00:23,319 INFO [backend.app.main] [-] [LAYER-TL] Layer timelapse attached successfully
+2026-10-11 17:01:51,953 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/library/files?generate_stl_thumbnails=true HTTP/1.1" 200
+2026-10-11 17:02:04,393 INFO [backend.app.api.routes.print_queue] [d3267b42] Added library file 30 to queue for 4
+2026-10-11 17:02:04,396 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/queue/ HTTP/1.1" 200
+2026-10-11 17:02:06,307 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(17, 4, None, 30)]
+2026-10-11 17:02:06,328 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 unavailable — an upload to it is still in flight (now: connected=True, state=FINISH, awaiting_plate_clear=True)
+2026-10-11 17:02:06,329 INFO [backend.app.services.print_scheduler] [-] Queue: printer 4 reserved — selected for dispatch in this pass
+2026-10-11 17:02:06,331 INFO [backend.app.services.print_scheduler] [-] Launching 1 upload(s) (pool 1/4 in flight)
+2026-10-11 17:02:06,335 INFO [backend.app.services.print_scheduler] [-] Starting queue item 17
+2026-10-11 17:02:06,521 INFO [backend.app.services.print_scheduler] [-] Queue item 17: Created archive 319 from library file 30
+2026-10-11 17:02:06,523 INFO [backend.app.services.print_scheduler] [-] Queue item 17: preheat skipped -- the loaded filaments derive no chamber target, so there is nothing to soak for (override=inherit model=[PRINTER])
+2026-10-11 17:02:06,526 INFO [backend.app.services.print_scheduler] [-] Queue item 17: FTP upload starting - printer=[PRINTER] ([PRINTER]), ip=[IP], file=Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf, local_path=/var/print_storage/bambuddy/archive/4/20261011_170206_Library table Gridfinity - Base front left (white) rev b/eed14f0cbf904d3f806cdbfe6cc303c0.3mf, retry_enabled=True, retry_count=3, timeout=30.0
+2026-10-11 17:02:06,626 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=[PRINTER], prot_c=False)
+2026-10-11 17:02:06,641 INFO [backend.app.services.bambu_ftp] [-] FTP connecting to [IP] for upload (model=[PRINTER], mode=prot_p, socket_timeout=30.0s, deadline=600s)...
+2026-10-11 17:02:06,755 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=[PRINTER], prot_c=False)
+2026-10-11 17:02:06,755 INFO [backend.app.services.bambu_ftp] [-] FTP connected to [IP]
+2026-10-11 17:02:06,755 INFO [backend.app.services.bambu_ftp] [-] FTP uploading /var/print_storage/bambuddy/archive/4/20261011_170206_Library table Gridfinity - Base front left (white) rev b/eed14f0cbf904d3f806cdbfe6cc303c0.3mf (1193305 bytes) to /Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf
+2026-10-11 17:02:06,778 INFO [backend.app.services.bambu_ftp] [-] FTP data channel ready in 0.0s (PASV + TLS handshake)
+2026-10-11 17:02:06,955 INFO [backend.app.services.bambu_ftp] [-] FTP STOR returned error_temp for /Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf but file is intact on the printer (1193305 bytes match) — proceeding: 426 Failure reading network stream.
+2026-10-11 17:02:06,955 INFO [backend.app.services.bambu_ftp] [-] FTP upload complete: /Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf (1193305 bytes in 0.2s, 5828 KB/s)
+2026-10-11 17:02:06,955 INFO [backend.app.services.bambu_ftp] [-] FTP mode cached for [IP]: prot_p
+2026-10-11 17:02:06,961 INFO [backend.app.main] [-] Registered expected print: printer=4, file=Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf, archive=319, ams_mapping=[6], plate_id=1
+2026-10-11 17:02:06,969 INFO [backend.app.services.print_scheduler] [-] Queue item 17: Status set to 'printing', sending print command...
+2026-10-11 17:02:06,975 INFO [backend.app.services.printer_manager] [-] PRINT COMMAND: printer=4, file=Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf, caller=print_scheduler.py:2431:_dispatch_one
+2026-10-11 17:02:06,975 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Sending print command: {"print": {"sequence_id": "20000", "command": "project_file", "param": "Metadata/plate_1.gcode", "url": "ftp://Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf", "file": "Library_table_Gridfinity_-_Base_front_left_(white)_rev_b.3mf", "md5": "", "bed_type": "auto", "timelapse": false, "bed_leveling": false, "auto_bed_leveling": 2, "flow_cali": false, "vibration_cali": true, "layer_inspect": true, "use_ams": true, "extrude_cali_flag": 2, "extrude_cali_manual_mode": 0, "nozzle_offset_cali": 2, "subtask_name": "Library_table_Gridfinity_-_Base_front_left_(white)_rev_b", "profile_id": "0", "project_id": "751165377", "subtask_id": "751165377", "task_id": "751165377", "ams_mapping": [6], "ams_mapping2": [{"ams_id": 1, "slot_id": 2}]}}
+2026-10-11 17:02:06,976 INFO [backend.app.services.print_scheduler] [-] Queue item 17: Print started successfully - Library table Gridfinity - Base front left (white) rev b.gcode.3mf
+2026-10-11 17:02:06,980 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Captured ams_mapping from print command: [6]
+2026-10-11 17:02:51,814 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] PRINT START detected - file: /data/Metadata/plate_1.gcode, subtask: Library_table_Gridfinity_-_Base_front_left_(white)_rev_b, is_new: True, is_file_change: False
+2026-10-11 17:02:51,815 INFO [backend.app.main] [-] [CALLBACK] on_print_start called for printer 4, data keys: ['filename', 'subtask_name', 'remaining_time', 'raw_data', 'ams_mapping']
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Skipped trays with invalid remain% for printer 4: AMS0-T2(remain=-1), AMS1-T2(remain=-1), AMS1-T3(remain=-1), AMS128-T0(remain=-1)
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 4: mapping=[258], tray_now=255, last_loaded_tray=128
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 4: mapping-related keys: {'mapping': [258], 'ams_extruder_map': {'0': 0, '1': 1, '128': 1}}
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 4 AMS 0: T0(type=, color=, now=?, tar=?), T1(type=, color=, now=?, tar=?), T2(type=, color=, now=?, tar=?), T3(type=, color=, now=?, tar=?)
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 4 AMS 1: T0(type=, color=, now=?, tar=?), T1(type=PLA, color=00AE42FF, now=?, tar=?), T2(type=PLA, color=FEFCDDFF, now=?, tar=?), T3(type=PLA, color=FEFCDDFF, now=?, tar=?)
+2026-10-11 17:02:51,820 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 4 AMS 128: T0(type=PLA, color=39FF14FF, now=?, tar=?)
+2026-10-11 17:02:51,821 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Snapshotted 4 spool assignments for printer 4: {'1-1': 189, '1-2': 10, '1-3': 11, '128-0': 227}
+2026-10-11 17:02:51,824 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Captured start remain% for printer 4 (7 trays): {'0-0': 0, '0-1': 0, '0-3': 0, '1-0': 0, '1-1': 48, '255-0': 0, '255-1': 0}
+2026-10-11 17:02:51,827 INFO [backend.app.main] [-] [PLATE CHECK] printer_id=4, plate_detection_enabled=False
+2026-10-11 17:02:51,827 INFO [backend.app.main] [-] [CALLBACK] Print start detected - filename: /data/Metadata/plate_1.gcode, subtask: Library_table_Gridfinity_-_Base_front_left_(white)_rev_b
+2026-10-11 17:02:51,827 INFO [backend.app.main] [-] Using expected archive 319 for print (skipping duplicate)
+2026-10-11 17:02:51,868 INFO [backend.app.main] [-] [ENERGY] Recorded starting energy (expected-print) for archive 319 from plug 'Bambu [PRINTER] Outlet': 47.638 kWh
+2026-10-11 17:02:51,870 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:02:51,870 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:02:51,951 INFO [backend.app.api.routes.printers] [76422c80] Cover: resolved plate 1 before download (subtask=Library_table_Gridfinity_-_Base_front_left_(white)_rev_b)
+2026-10-11 17:02:51,973 INFO [backend.app.api.routes.printers] [76422c80] Cover using cached 3MF from /var/print_storage/bambuddy/archive/4/20261011_170206_Library table Gridfinity - Base front left (white) rev b/eed14f0cbf904d3f806cdbfe6cc303c0.3mf (avoided duplicate FTP)
+2026-10-11 17:02:51,973 INFO [backend.app.api.routes.printers] [76422c80] Downloaded file size: 1193305 bytes
+2026-10-11 17:02:53,131 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 486898 bytes
+2026-10-11 17:02:53,131 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 486898 bytes
+2026-10-11 17:02:53,131 INFO [backend.app.services.notification_service] [-] on_print_start called for printer 4 ([PRINTER])
+2026-10-11 17:02:53,133 INFO [backend.app.services.notification_service] [-] No notification providers configured for print_start event on printer 4
+2026-10-11 17:02:53,134 INFO [backend.app.main] [-] Loaded 1 printable objects for printer 4
+2026-10-11 17:02:53,327 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=[PRINTER], prot_c=False)
+2026-10-11 17:02:53,418 INFO [backend.app.main] [-] [TIMELAPSE] Baseline at print start: 158 video files for printer 4
+2026-10-11 17:03:39,100 INFO [backend.app.main] [-] Recorded 8 AMS sensor history entries
+2026-10-11 17:04:46,535 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-10-11 17:04:47,049 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/auth/media-token HTTP/1.1" 200
+2026-10-11 17:04:47,070 INFO [backend.app.api.routes.printers] [f50955d6] Cover: resolved plate 1 before download (subtask=Library_table_Gridfinity_-_Base_front_left_(white)_rev_b)
+2026-10-11 17:05:25,732 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=6 at layer=0
+2026-10-11 17:08:39,112 INFO [backend.app.main] [-] Recorded 8 AMS sensor history entries
+2026-10-11 17:13:08,662 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 tray 3: state=10 (not loaded) — clearing stale tray data
+2026-10-11 17:13:08,663 INFO [backend.app.main] [-] [Printer 2] Broadcasting AMS change via WebSocket
+2026-10-11 17:13:08,670 INFO [backend.app.main] [-] Auto-unlink held: spool 394 AMS0-T3 — tray reports no filament data; unlinking if it is still blank in 120s
+2026-10-11 17:13:08,822 INFO [backend.app.api.routes.cloud] [3f1de69a] get_filament_info called with 3 IDs: ['GFNLS08', 'GFL01', 'GFG96']
+2026-10-11 17:13:09,365 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-10-11 17:13:39,127 INFO [backend.app.main] [-] Recorded 8 AMS sensor history entries
+2026-10-11 17:14:20,119 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:14:20,121 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:14:21,397 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 241899 bytes
+2026-10-11 17:14:21,397 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 241899 bytes
+2026-10-11 17:14:24,684 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=2 at layer=0
+2026-10-11 17:14:39,989 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=6 at layer=0
+2026-10-11 17:15:07,786 INFO [backend.app.main] [-] [Printer 2] Broadcasting AMS change via WebSocket
+2026-10-11 17:15:07,943 INFO [backend.app.api.routes.cloud] [4673fd07] get_filament_info called with 4 IDs: ['GFNLS08', 'GFL01', 'GFG96', 'PMHT01']
+2026-10-11 17:15:08,143 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-10-11 17:15:14,752 INFO [uvicorn.access] [-] [IP]:0 - "DELETE /api/v1/inventory/assignments/2/0/3 HTTP/1.1" 200
+2026-10-11 17:15:26,661 INFO [backend.app.services.bambu_mqtt] [92cd9780] [[SERIAL]] Publishing ams_filament_setting: AMS 0, tray 3, tray_info_idx=P0315daa, setting_id=PFUSd1c06b524b0c9b
+2026-10-11 17:15:26,661 INFO [backend.app.services.bambu_mqtt] [92cd9780] [[SERIAL]] Publishing extrusion_cali_sel: AMS 0, tray 3, cali_idx=-1
+2026-10-11 17:15:26,662 INFO [backend.app.api.routes.inventory] [92cd9780] No stored K-profile for spool 74 — reset slot to Default K (cali_idx=-1)
+2026-10-11 17:15:26,664 INFO [backend.app.api.routes.inventory] [92cd9780] Auto-configured AMS slot ams=0 tray=3 for spool 74 on printer 2
+2026-10-11 17:15:26,672 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/inventory/assignments HTTP/1.1" 200
+2026-10-11 17:15:26,791 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/printers/2/refresh-status HTTP/1.1" 200
+2026-10-11 17:15:27,616 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Assignment verified: AMS0-T3 now reports P0315DAA (kprofile_applied=True)
+2026-10-11 17:15:27,616 INFO [backend.app.main] [-] [Printer 2] Broadcasting AMS change via WebSocket
+2026-10-11 17:15:27,651 INFO [backend.app.main] [-] Auto-unlink: spool 74 AMS0-T3 — fingerprint mismatch but tray matches spool, updating fp
+2026-10-11 17:15:27,742 INFO [backend.app.api.routes.cloud] [c1882446] get_filament_info called with 4 IDs: ['GFNLS08', 'GFL01', 'GFG96', 'P0315daa']
+2026-10-11 17:15:27,874 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-10-11 17:15:31,484 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:15:31,485 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:15:32,667 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 244970 bytes
+2026-10-11 17:15:32,668 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 244970 bytes
+2026-10-11 17:16:03,448 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:16:03,449 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:16:04,616 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 235076 bytes
+2026-10-11 17:16:04,617 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 235076 bytes
+2026-10-11 17:17:14,931 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:17:14,932 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:17:16,238 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 245240 bytes
+2026-10-11 17:17:16,238 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 245240 bytes
+2026-10-11 17:18:24,856 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:18:24,856 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:18:26,093 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 315918 bytes
+2026-10-11 17:18:26,093 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 315918 bytes
+2026-10-11 17:18:39,136 INFO [backend.app.main] [-] Recorded 8 AMS sensor history entries
+2026-10-11 17:19:29,330 INFO [backend.app.services.print_scheduler] [-] Queue item 16: preheat target reached (bed=90.0 chamber=38.0) — entering soak
+2026-10-11 17:19:29,330 INFO [backend.app.services.print_scheduler] [-] Queue item 16: preheat soak — holding for 360s (of 360s configured; chamber has been above target for ~0s already)
+2026-10-11 17:19:33,893 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:19:33,894 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:19:35,216 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 311977 bytes
+2026-10-11 17:19:35,216 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 311977 bytes
+2026-10-11 17:20:43,870 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 4
+2026-10-11 17:20:43,872 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: [PRINTER])
+2026-10-11 17:20:45,088 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 243024 bytes
+2026-10-11 17:20:45,088 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 243024 bytes
+2026-10-11 17:21:05,337 INFO [backend.app.api.routes.support] [464856b5] Log level changed to DEBUG
+2026-10-11 17:21:05,337 INFO [backend.app.api.routes.bug_report] [464856b5] Bug report: enabled debug logging
+2026-10-11 17:21:05,337 DEBUG [backend.app.services.bambu_mqtt] [464856b5] [[SERIAL]] Requesting status update (pushall)
+2026-10-11 17:21:05,337 DEBUG [backend.app.services.bambu_mqtt] [464856b5] [[SERIAL]] Requesting status update (pushall)
+2026-10-11 17:21:05,337 DEBUG [backend.app.services.bambu_mqtt] [464856b5] [[SERIAL]] Requesting status update (pushall)
+2026-10-11 17:21:05,338 DEBUG [backend.app.services.bambu_mqtt] [464856b5] [[SERIAL]] Requesting status update (pushall)
+2026-10-11 17:21:05,338 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/bug-report/start-logging HTTP/1.1" 200
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'buildplate_marker_detector': False}
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['buildplate_marker_detector']
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: FINISH, gcode_file: , subtask_name: Emoji_hands
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '1', 'tray_exist_bits': '8', 'tray_is_bbl_bits': '8', 'tray_tar': '255', 'tray_now': '255', 'tray_pre': '255', 'tray_read_done_bits': '8', 'tray_reading_bits': '0', 'version': 18, 'insert_flag': True, 'power_on_flag': True}
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 255
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 1 new units, 1 total
+2026-10-11 17:21:05,419 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1002 -> extruder 0
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0}
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 0 (main=0, sub=0)
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper raw value: 5.0
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper direct value: 5.0°C (heater OFF)
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=5.0, heating=False, respect_local=False
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 5.0, target: 0.0, heating: False
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'ipcam_dev': '1', 'ipcam_record': 'disable', 'timelapse': 'disable', 'resolution': '1080p', 'tutk_server': 'disable', 'mode_bits': 3}
+2026-10-11 17:21:05,420 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -70dBm
+2026-10-11 17:21:05,421 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'node': 'chamber_light', 'mode': 'off'}]
+2026-10-11 17:21:05,421 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: FINISH -> FINISH, file: , subtask: Emoji_hands
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_marker_detector': False, 'cfg': 4943271, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_marker_detector', 'cfg', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 4943271 (binary: 0b10010110110110110100111)
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: FINISH, gcode_file: /data/Metadata/plate_4.gcode, subtask_name: AMS+HT+干燥剂盒+加大漏斗+V2.1_Dessicant_Storage_Unit_-_Variation_4_Big_Funnel
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '11', 'ams_exist_bits_raw': '11', 'cali_id': 255, 'cali_stat': 0, 'cfs': [2, 3, 4], 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': 'f', 'tray_hall_out_bits': '0', 'tray_is_bbl_bits': 'f', 'tray_now': '255', 'tray_pre': '255', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'tray_tar': '255', 'unbind_ams_stat': 0, 'version': 34588}
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 255
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 2 new units, 2 total
+2026-10-11 17:21:05,693 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x11001103 -> extruder 1
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x10002004 -> extruder 0
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 1, '128': 0}
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 0 (main=0, sub=0)
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=274 (switch_state bits 12-14: 0)
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 25°C (heater OFF)
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=25.0, heating=False, respect_local=False
+2026-10-11 17:21:05,694 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 25.0, target: 0.0, heating: False
+2026-10-11 17:21:05,695 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: [{'attr': 83886336, 'code': 131083, 'ts_boot': 385714990, 'ts_unix': '20261001034135'}]
+2026-10-11 17:21:05,695 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': 7, 'liveview_preview': True, 'mode_bits': 2, 'resolution': '1080p', 'rtsp_url': 'rtsps://[IP]:322/streaming/live/1', 'timelapse': 'disable', 'tl_external_free_kb': 4218240, 'tl_external_total_kb': 30058880, 'tl_internal_free_kb': 631733, 'tl_internal_total_kb': 962560, 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-10-11 17:21:05,695 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -37dBm
+2026-10-11 17:21:05,695 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'off', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-10-11 17:21:05,695 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [65535, 65535, 2]
+2026-10-11 17:21:05,695 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: FINISH -> FINISH, file: /data/Metadata/plate_4.gcode, subtask: AMS+HT+干燥剂盒+加大漏斗+V2.1_Dessicant_Storage_Unit_-_Variation_4_Big_Funnel
+2026-10-11 17:21:06,029 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_marker_detector': False, 'cfg': 1797255, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['allow_skip_parts', 'buildplate_marker_detector', 'cfg', 'first_layer_inspector', 'halt_print_sensitivity', 'print_halt', 'printing_monitor', 'spaghetti_detector']
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 1797255 (binary: 0b110110110110010000111)
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_1.gcode, subtask_name: Library_table_Gridfinity_-_Base_front_left_(white)_rev_b
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '13', 'ams_exist_bits_raw': '13', 'cali_id': 255, 'cali_stat': 0, 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': '100e0', 'tray_hall_out_bits': '40', 'tray_is_bbl_bits': '100e0', 'tray_now': '2', 'tray_pre': '2', 'tray_read_done_bits': '100e0', 'tray_reading_bits': '0', 'tray_tar': '2', 'unbind_ams_stat': 0, 'version': 5386}
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 6
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 3 new units, 3 total
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x10001003 -> extruder 0
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 1 info=0x10001101 -> extruder 1
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x10002104 -> extruder 1
+2026-10-11 17:21:06,030 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0, '1': 1, '128': 1}
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=33042 (switch_state bits 12-14: 0)
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 24°C (heater OFF)
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=24.0, heating=False, respect_local=False
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 24.0, target: 0.0, heating: False
+2026-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-10-11 17:21:06,031 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': 5, '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-10-11 17:21:06,031 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -46dBm
+2026-10-11 17:21:06,031 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-10-11 17:21:06,032 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [258]
+2026-10-11 17:21:06,032 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_1.gcode, subtask: Library_table_Gridfinity_-_Base_front_left_(white)_rev_b