Bug report logs 50d5f9e1276242d58d0f32fe2776245a.log

logs/50d5f9e1276242d58d0f32fe2776245a.log

@@ -0,0 +1,200 @@
+2026-11-08 08:06:12,854 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:06:12,896 INFO [backend.app.api.routes.websocket] [-] WebSocket client connecting (principal=[USER])
+2026-11-08 08:06:12,901 INFO [uvicorn.error] [-] [IP]:0 - "WebSocket /api/v1/ws?token=[REDACTED]" [accepted]
+2026-11-08 08:06:12,901 INFO [uvicorn.error] [-] connection open
+2026-11-08 08:06:12,908 INFO [backend.app.api.routes.websocket] [-] WebSocket client connected
+2026-11-08 08:06:12,908 INFO [backend.app.api.routes.websocket] [-] Sent initial status for 2 printers
+2026-11-08 08:06:12,986 INFO [backend.app.api.routes.printers] [1e0d92ba] Cover: resolved plate 1 before download (subtask=SVETLO-LITO)
+2026-11-08 08:06:12,987 INFO [backend.app.api.routes.cloud] [f8338290] get_filament_info called with 1 IDs: ['GFG99']
+2026-11-08 08:06:12,988 INFO [backend.app.api.routes.cloud] [47abea7b] get_filament_info called with 2 IDs: ['GFG99', 'GFL99']
+2026-11-08 08:06:12,993 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-11-08 08:06:12,997 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-11-08 08:06:12,999 INFO [backend.app.api.routes.printers] [1e0d92ba] Cover using cached 3MF from /app/data/archive/library/files/4b34c841797143c9abed46b247c7c7c0.3mf (avoided duplicate FTP)
+2026-11-08 08:06:12,999 INFO [backend.app.api.routes.printers] [1e0d92ba] Downloaded file size: 272322 bytes
+2026-11-08 08:06:14,579 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 134440 bytes
+2026-11-08 08:06:14,579 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 134440 bytes
+2026-11-08 08:07:16,733 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:07:16,733 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:07:18,442 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 136393 bytes
+2026-11-08 08:07:18,442 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 136393 bytes
+2026-11-08 08:08:19,945 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:08:19,946 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:08:21,942 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 135788 bytes
+2026-11-08 08:08:21,942 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 135788 bytes
+2026-11-08 08:09:25,882 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:09:25,882 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:09:27,604 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 137873 bytes
+2026-11-08 08:09:27,604 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 137873 bytes
+2026-11-08 08:09:32,744 INFO [backend.app.main] [-] Recorded 1 AMS sensor history entries
+2026-11-08 08:10:29,766 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/library/files?folder_id=2&generate_stl_thumbnails=true HTTP/1.1" 200
+2026-11-08 08:10:31,217 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:10:31,218 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:10:32,937 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 129116 bytes
+2026-11-08 08:10:32,937 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 129116 bytes
+2026-11-08 08:10:53,099 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Dropped 7 command(s) queued on the previous MQTT connection
+2026-11-08 08:10:53,100 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Connection stale - no message for 48812.4s, forcing reconnect
+2026-11-08 08:10:53,109 INFO [backend.app.main] [-] [#1752] Printer 1 connected→disconnected edge; scheduling offline notification in 60s
+2026-11-08 08:10:53,920 INFO [backend.app.main] [-] [#1752] Printer 1 reconnected before debounce; cancelling pending offline notification
+2026-11-08 08:10:53,921 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Requesting K-profiles for nozzle_diameter=0.4 (attempt 1/2, seq_id=21)
+2026-11-08 08:10:54,000 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] K-profile response: nozzle=0.4, seq_id=20, 0 profiles, matched=True
+2026-11-08 08:10:54,000 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Got 0 K-profiles for nozzle=0.4
+2026-11-08 08:10:54,000 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Got 0 K-profiles for nozzle=0.4 on attempt 1
+2026-11-08 08:10:54,000 INFO [backend.app.main] [-] [Printer 1] Primed K-profile table for nozzle 0.4: 0 profiles
+2026-11-08 08:11:35,509 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:11:35,509 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:11:37,247 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 132455 bytes
+2026-11-08 08:11:37,247 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 132455 bytes
+2026-11-08 08:11:51,247 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-11-08 08:11:51,663 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/printers/1/refresh-status HTTP/1.1" 200
+2026-11-08 08:11:52,269 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-11-08 08:11:59,032 INFO [backend.app.api.routes.print_queue] [ccd523fd] Added library file 78 to queue for 1
+2026-11-08 08:11:59,035 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/queue/ HTTP/1.1" 200
+2026-11-08 08:12:02,692 INFO [backend.app.api.routes.cloud] [1b65d239] get_filament_info called with 1 IDs: ['GFG97']
+2026-11-08 08:12:02,705 INFO [backend.app.api.routes.printers] [fed82699] Cover: resolved plate 1 before download (subtask=SVETLO-LITO)
+2026-11-08 08:12:02,714 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-11-08 08:12:02,765 INFO [backend.app.api.routes.cloud] [3149cbd2] get_filament_info called with 2 IDs: ['GFG99', 'GFL99']
+2026-11-08 08:12:02,778 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-11-08 08:12:21,660 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(129, 1, None, 78)]
+2026-11-08 08:12:21,669 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 reserved — selected for dispatch in this pass
+2026-11-08 08:12:21,669 INFO [backend.app.services.print_scheduler] [-] Queue: printer 2 unavailable — an item is already printing on it (now: connected=True, state=RUNNING, awaiting_plate_clear=False)
+2026-11-08 08:12:21,671 INFO [backend.app.services.print_scheduler] [-] Launching 1 upload(s) (pool 0/4 in flight)
+2026-11-08 08:12:21,674 INFO [backend.app.services.print_scheduler] [-] Starting queue item 129
+2026-11-08 08:12:21,709 INFO [backend.app.services.print_scheduler] [-] Queue item 129: Created archive 121 from library file 78
+2026-11-08 08:12:21,714 INFO [backend.app.services.print_scheduler] [-] Queue item 129: FTP upload starting - printer=[PRINTER] (A1 Mini), ip=[IP], file=ram-air75.3mf, local_path=/app/data/archive/library/files/00204279a73143daa46e76e20209e707.3mf, retry_enabled=True, retry_count=3, timeout=30.0
+2026-11-08 08:12:22,485 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:22,504 INFO [backend.app.services.bambu_ftp] [-] FTP connecting to [IP] for upload (model=A1 Mini, mode=prot_p, socket_timeout=30.0s, deadline=600s)...
+2026-11-08 08:12:23,279 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:23,279 INFO [backend.app.services.bambu_ftp] [-] FTP connected to [IP]
+2026-11-08 08:12:23,279 INFO [backend.app.services.bambu_ftp] [-] FTP uploading /app/data/archive/library/files/00204279a73143daa46e76e20209e707.3mf (1404508 bytes) to /ram-air75.3mf
+2026-11-08 08:12:23,327 INFO [backend.app.services.bambu_ftp] [-] FTP data channel ready in 0.0s (PASV + TLS handshake)
+2026-11-08 08:12:30,006 INFO [backend.app.services.bambu_ftp] [-] FTP STOR confirmed for /ram-air75.3mf: 226
+2026-11-08 08:12:30,006 INFO [backend.app.services.bambu_ftp] [-] FTP upload complete: /ram-air75.3mf (1404508 bytes in 6.7s, 204 KB/s)
+2026-11-08 08:12:30,007 INFO [backend.app.services.bambu_ftp] [-] FTP mode cached for [IP]: prot_p
+2026-11-08 08:12:30,024 INFO [backend.app.main] [-] Registered expected print: printer=1, file=ram-air75.3mf, archive=121, ams_mapping=[254], plate_id=1
+2026-11-08 08:12:30,028 INFO [backend.app.services.print_scheduler] [-] Queue item 129: sent with another colour than the file asks for: [{'slot_id': 1, 'type': 'PCTG', 'wanted': '#C0C0C0', 'got': '#5A657B', 'tray': 254}]
+2026-11-08 08:12:30,032 INFO [backend.app.services.print_scheduler] [-] Queue item 129: Status set to 'printing', sending print command...
+2026-11-08 08:12:30,034 INFO [backend.app.services.print_scheduler] [-] Queue item 129: every filament plate 1 prints is on the external spool (mapping [254]) — dispatching with use_ams=False (#3087)
+2026-11-08 08:12:30,039 INFO [backend.app.services.printer_manager] [-] PRINT COMMAND: printer=1, file=ram-air75.3mf, caller=print_scheduler.py:2841:_dispatch_one
+2026-11-08 08:12:30,039 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Sending print command: {"print": {"sequence_id": "20000", "command": "project_file", "param": "Metadata/plate_1.gcode", "url": "ftp://ram-air75.3mf", "file": "ram-air75.3mf", "md5": "", "bed_type": "auto", "timelapse": false, "bed_leveling": false, "auto_bed_leveling": 0, "flow_cali": false, "vibration_cali": false, "layer_inspect": true, "use_ams": false, "extrude_cali_flag": 0, "extrude_cali_manual_mode": 0, "nozzle_offset_cali": 0, "subtask_name": "ram-air75", "profile_id": "0", "project_id": "983904794", "subtask_id": "983904794", "task_id": "983904794", "ams_mapping": [-1], "ams_mapping2": [{"ams_id": 255, "slot_id": 0}]}}
+2026-11-08 08:12:30,039 INFO [backend.app.services.print_scheduler] [-] Queue item 129: Print started successfully - ram-air75.gcode.3mf
+2026-11-08 08:12:30,061 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Print destination from the report topic: ftp://ram-air75.3mf
+2026-11-08 08:12:30,061 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Captured ams_mapping from print response: [254]
+2026-11-08 08:12:41,437 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:12:41,438 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:12:42,663 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] PRINT START detected - file: ram-air75.3mf, subtask: ram-air75, is_new: True, is_file_change: False
+2026-11-08 08:12:42,663 INFO [backend.app.main] [-] [CALLBACK] on_print_start called for printer 1, data keys: ['filename', 'subtask_name', 'remaining_time', 'raw_data', 'ams_mapping']
+2026-11-08 08:12:42,669 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1: mapping=None, tray_now=255, last_loaded_tray=254
+2026-11-08 08:12:42,672 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Captured start remain% for printer 1 (1 trays): {'255-0': 0}
+2026-11-08 08:12:42,675 INFO [backend.app.main] [-] [PLATE CHECK] printer_id=1, plate_detection_enabled=False
+2026-11-08 08:12:42,675 INFO [backend.app.main] [-] [CALLBACK] Print start detected - filename: ram-air75.3mf, subtask: ram-air75
+2026-11-08 08:12:42,676 INFO [backend.app.main] [-] Using expected archive 121 for print (skipping duplicate)
+2026-11-08 08:12:42,688 INFO [backend.app.main] [-] [ENERGY] No smart plug for printer 1 (archive 121)
+2026-11-08 08:12:42,693 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-11-08 08:12:42,693 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using chamber image protocol (model: A1 Mini)
+2026-11-08 08:12:42,792 INFO [backend.app.api.routes.printers] [34c15c5b] Cover: resolved plate 1 before download (subtask=ram-air75)
+2026-11-08 08:12:42,800 INFO [backend.app.api.routes.printers] [34c15c5b] Cover using cached 3MF from /app/data/archive/library/files/00204279a73143daa46e76e20209e707.3mf (avoided duplicate FTP)
+2026-11-08 08:12:42,800 INFO [backend.app.api.routes.printers] [34c15c5b] Downloaded file size: 1404508 bytes
+2026-11-08 08:12:43,183 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 141799 bytes
+2026-11-08 08:12:43,183 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 141799 bytes
+2026-11-08 08:12:45,325 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 167343 bytes
+2026-11-08 08:12:45,325 INFO [backend.app.services.notification_service] [-] on_print_start called for printer 1 ([PRINTER])
+2026-11-08 08:12:45,327 INFO [backend.app.services.notification_service] [-] No notification providers configured for print_start event on printer 1
+2026-11-08 08:12:45,329 INFO [backend.app.main] [-] Loaded 1 printable objects for printer 1
+2026-11-08 08:12:46,119 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:46,995 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:47,006 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /timelapse/video: 550 
+2026-11-08 08:12:47,783 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:47,795 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /record: 550 
+2026-11-08 08:12:48,575 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:48,588 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /recording: 550 
+2026-11-08 08:12:49,376 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:50,259 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:50,272 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /timelapse/video: 550 
+2026-11-08 08:12:51,048 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:51,059 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /record: 550 
+2026-11-08 08:12:51,851 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=A1 Mini, prot_c=False)
+2026-11-08 08:12:51,862 INFO [backend.app.services.bambu_ftp] [-] FTP list_files failed for /recording: 550 
+2026-11-08 08:12:51,871 INFO [backend.app.main] [-] [TIMELAPSE] Baseline at print start: 0 video files for printer 1
+2026-11-08 08:12:55,634 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:12:55,635 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:12:57,354 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 132283 bytes
+2026-11-08 08:12:57,354 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 132283 bytes
+2026-11-08 08:12:57,925 INFO [backend.app.services.notification_service] [-] Sent notification via X2D
+2026-11-08 08:13:45,892 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:13:45,893 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:13:47,719 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 141178 bytes
+2026-11-08 08:13:47,719 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 141178 bytes
+2026-11-08 08:13:50,333 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-11-08 08:13:50,333 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using chamber image protocol (model: A1 Mini)
+2026-11-08 08:13:52,737 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 136254 bytes
+2026-11-08 08:13:53,715 INFO [backend.app.services.notification_service] [-] Sent notification via [PRINTER]
+2026-11-08 08:13:54,129 INFO [backend.app.services.notification_service] [-] Sent notification via [PRINTER]
+2026-11-08 08:13:54,129 INFO [backend.app.main] [-] [HMS] Sent notification for 2 error(s) on printer 1
+2026-11-08 08:14:02,489 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-11-08 08:14:02,489 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using chamber image protocol (model: A1 Mini)
+2026-11-08 08:14:05,158 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 166540 bytes
+2026-11-08 08:14:05,785 INFO [backend.app.services.notification_service] [-] Sent notification via [PRINTER]
+2026-11-08 08:14:05,786 INFO [backend.app.main] [-] [HMS] Sent notification for 1 error(s) on printer 1
+2026-11-08 08:14:32,751 INFO [backend.app.main] [-] Recorded 1 AMS sensor history entries
+2026-11-08 08:14:46,315 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:14:46,315 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:14:48,094 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 136440 bytes
+2026-11-08 08:14:48,094 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 136440 bytes
+2026-11-08 08:15:49,135 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 2
+2026-11-08 08:15:49,136 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: X2D)
+2026-11-08 08:15:50,919 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 145829 bytes
+2026-11-08 08:15:50,919 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 145829 bytes
+2026-11-08 08:16:03,085 INFO [backend.app.api.routes.support] [4d68a035] Log level changed to DEBUG
+2026-11-08 08:16:03,085 INFO [backend.app.api.routes.bug_report] [4d68a035] Bug report: enabled debug logging
+2026-11-08 08:16:03,085 DEBUG [backend.app.services.bambu_mqtt] [4d68a035] [[SERIAL]] Requesting status update (pushall)
+2026-11-08 08:16:03,085 DEBUG [backend.app.services.bambu_mqtt] [4d68a035] [[SERIAL]] Requesting status update (pushall)
+2026-11-08 08:16:03,086 INFO [uvicorn.access] [-] [IP]:0 - "POST /api/v1/bug-report/start-logging HTTP/1.1" 200
+2026-11-08 08:16:03,376 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'buildplate_marker_detector': True}
+2026-11-08 08:16:03,376 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['buildplate_marker_detector']
+2026-11-08 08:16:03,376 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: ram-air75.3mf, subtask_name: ram-air75
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '0', 'tray_exist_bits': '0', 'tray_is_bbl_bits': '0', 'tray_tar': '254', 'tray_now': '254', 'tray_pre': '254', 'tray_read_done_bits': '0', 'tray_reading_bits': '0', 'version': 2, 'insert_flag': True, 'power_on_flag': False}
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 254
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 0 new units, 0 total
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper raw value: 5.0
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper direct value: 5.0°C (heater OFF)
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=5.0, heating=False, respect_local=False
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 5.0, target: 0.0, heating: False
+2026-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-11-08 08:16:03,377 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-11-08 08:16:03,377 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -35dBm
+2026-11-08 08:16:03,378 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'node': 'chamber_light', 'mode': 'on'}]
+2026-11-08 08:16:03,378 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: ram-air75.3mf, subtask: ram-air75
+2026-11-08 08:16:04,214 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_marker_detector': True, 'cfg': 8089015, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-11-08 08:16:04,214 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-11-08 08:16:04,214 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 8089015 (binary: 0b11110110110110110110111)
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_1.gcode, subtask_name: SVETLO-LITO
+2026-11-08 08:16:04,215 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, 'cfs': [2, 9, 5, 7], 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': '7', 'tray_hall_out_bits': '1', 'tray_is_bbl_bits': '7', 'tray_now': '0', 'tray_pre': '0', 'tray_read_done_bits': '7', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 564}
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 0
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 1 new units, 1 total
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x11001103 -> extruder 1
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 1}
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=33042 (switch_state bits 12-14: 0)
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 28°C (heater OFF)
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-11-08 08:16:04,215 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=28.0, heating=False, respect_local=False
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 28.0, target: 0.0, heating: False
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-11-08 08:16:04,216 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': 'disable', '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': 2923776, 'tl_external_total_kb': 15358080, 'tl_internal_free_kb': 962560, 'tl_internal_total_kb': 962560, 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -40dBm
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [0]
+2026-11-08 08:16:04,216 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_1.gcode, subtask: SVETLO-LITO
+2026-11-08 08:16:05,486 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_marker_detector': True, 'cfg': 8089015, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-11-08 08:16:05,486 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-11-08 08:16:05,486 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 8089015 (binary: 0b11110110110110110110111)
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_1.gcode, subtask_name: SVETLO-LITO
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 1}
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'mode': 'on', 'node': 'chamber_light'}, {'mode': 'flashing', 'node': 'work_light'}]
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [0]
+2026-11-08 08:16:05,487 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_1.gcode, subtask: SVETLO-LITO