Bug report logs 9bced0e00d5348229741e96f72a2022d.log

logs/9bced0e00d5348229741e96f72a2022d.log

@@ -0,0 +1,200 @@
+2026-07-22 17:59:42,973 INFO [backend.app.main] [-] [TIMELAPSE]   - video_2026-01-07_05-34-03.mp4
+2026-07-22 17:59:42,973 INFO [backend.app.main] [-] [TIMELAPSE]   - video_2026-01-07_10-54-48.mp4
+2026-07-22 17:59:42,973 INFO [backend.app.main] [-] [TIMELAPSE]   - video_2026-01-07_20-43-25.mp4
+2026-07-22 17:59:42,973 INFO [backend.app.main] [-] [TIMELAPSE]   - video_2026-01-08_01-54-18.mp4
+2026-07-22 17:59:42,973 INFO [backend.app.main] [-] [TIMELAPSE] Attempt 1: New file detected: video_2026-07-23_05-12-24.mp4 (downloading for archive 2)
+2026-07-22 17:59:43,121 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=H2C, prot_c=False)
+2026-07-22 17:59:43,651 INFO [backend.app.main] [-] [TIMELAPSE] Successfully attached timelapse to archive 2
+2026-07-22 17:59:47,628 INFO [backend.app.main] [-] [PHOTO-BG] Extracted finish photo from timelapse video_2026-07-23_05-12-24.mp4 for archive 2
+2026-07-22 17:59:47,630 INFO [backend.app.main] [-] [PHOTO-BG] Saved: finish_20260722_175946_8fd5116d.jpg
+2026-07-22 17:59:47,630 INFO [backend.app.main] [-] [PHOTO-NOTIFY] Photo task returned: finish_20260722_175946_8fd5116d.jpg
+2026-07-22 17:59:47,630 INFO [backend.app.main] [-] [NOTIFY-BG] Starting notifications for printer 1, photo=finish_20260722_175946_8fd5116d.jpg
+2026-07-22 17:59:47,632 INFO [backend.app.main] [-] [NOTIFY-BG] Loaded finish photo bytes: 453826 bytes
+2026-07-22 17:59:47,632 INFO [backend.app.services.notification_service] [-] on_print_complete called for printer 1 ([PRINTER]), status=completed
+2026-07-22 17:59:47,633 INFO [backend.app.services.notification_service] [-] Found 1 providers for on_print_complete: ['ntfy']
+2026-07-22 17:59:47,641 INFO [backend.app.services.notification_service] [-] Sent notification via ntfy
+2026-07-22 17:59:47,641 INFO [backend.app.main] [-] [NOTIFY-BG] Completed
+2026-07-22 18:03:47,492 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:08:47,495 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:13:47,498 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:18:47,500 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:23:47,503 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:28:47,507 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:33:47,510 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:38:47,513 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:43:47,517 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:48:47,521 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:53:47,524 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 18:58:47,527 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:03:47,530 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:08:47,532 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:13:47,535 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:18:47,537 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:23:47,540 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:28:47,543 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:33:47,546 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:38:47,549 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:43:47,552 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:48:47,554 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:53:47,556 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 19:58:47,560 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:03:47,563 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:08:47,566 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:13:47,570 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:18:47,572 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:23:47,575 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:28:47,578 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:32:43,810 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-07-22 20:32:43,810 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: H2C)
+2026-07-22 20:32:45,021 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 427525 bytes
+2026-07-22 20:32:45,021 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 427525 bytes
+2026-07-22 20:32:45,033 INFO [backend.app.services.notification_service] [-] Sent notification via ntfy
+2026-07-22 20:32:45,033 INFO [backend.app.main] [-] [HMS] Sent notification for 1 error(s) on printer 1
+2026-07-22 20:33:47,581 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:37:12,408 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Captured ams_mapping from print command: [5, 1, 128]
+2026-07-22 20:37:12,621 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS Filament Backup: OFF
+2026-07-22 20:37:14,907 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS Filament Backup: ON
+2026-07-22 20:37:14,908 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] PRINT START detected - file: /data/Metadata/plate_1.gcode, subtask: Towel Clips, is_new: True, is_file_change: False
+2026-07-22 20:37:14,908 INFO [backend.app.main] [-] [CALLBACK] on_print_start called for printer 1, data keys: ['filename', 'subtask_name', 'remaining_time', 'raw_data', 'ams_mapping']
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Skipped trays with invalid remain% for printer 1: AMS0-T3(remain=-1), AMS1-T0(remain=-1), AMS1-T2(remain=-1), AMS1-T3(remain=-1), AMS128-T0(remain=-1)
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1: mapping=[257, 1, 32768], tray_now=255, last_loaded_tray=254
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1: mapping-related keys: {'mapping': [257, 1, 32768], 'ams_extruder_map': {'0': 0, '1': 0, '128': 1}}
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1 AMS 0: T0(type=PLA, color=B39B84FF, now=?, tar=?), T1(type=PLA, color=FFFFFFFF, now=?, tar=?), T2(type=PLA, color=000000FF, now=?, tar=?), T3(type=PLA, color=A03CF7FF, now=?, tar=?)
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1 AMS 1: T0(type=PLA, color=161616FF, now=?, tar=?), T1(type=PETG, color=C9A38180, now=?, tar=?), T2(type=PET-CF, color=FFFFFFFF, now=?, tar=?), T3(type=ASA, color=898989FF, now=?, tar=?)
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] PRINT START printer 1 AMS 128: T0(type=PET-CF, color=161616FF, now=?, tar=?)
+2026-07-22 20:37:14,911 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Snapshotted 4 spool assignments for printer 1: {'0-0': 1, '0-1': 2, '0-2': 3, '1-1': 4}
+2026-07-22 20:37:14,912 INFO [backend.app.services.usage_tracker] [-] [UsageTracker] Captured start remain% for printer 1 (6 trays): {'0-0': 100, '0-1': 38, '0-2': 75, '1-1': 51, '255-0': 0, '255-1': 0}
+2026-07-22 20:37:14,913 INFO [backend.app.main] [-] [PLATE CHECK] printer_id=1, plate_detection_enabled=False
+2026-07-22 20:37:14,913 INFO [backend.app.main] [-] [CALLBACK] Print start detected - filename: /data/Metadata/plate_1.gcode, subtask: Towel Clips
+2026-07-22 20:37:14,913 INFO [backend.app.main] [-] Trying filenames: ['Towel Clips.gcode.3mf', 'Towel Clips.3mf', 'plate_1.gcode.3mf', 'plate_1.3mf', 'Towel_Clips.gcode.3mf', 'Towel_Clips.3mf']
+2026-07-22 20:37:15,069 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=H2C, prot_c=False)
+2026-07-22 20:37:15,423 INFO [backend.app.services.bambu_ftp] [-] Successfully downloaded /Towel Clips.gcode.3mf to /opt/[user]/archive/temp/Towel Clips.gcode.3mf (471650 bytes)
+2026-07-22 20:37:15,424 INFO [backend.app.services.bambu_ftp] [-] FTP mode cached for [IP]: prot_p
+2026-07-22 20:37:15,430 INFO [backend.app.main] [-] Downloaded: /Towel Clips.gcode.3mf
+2026-07-22 20:37:15,436 INFO [backend.app.main] [-] Created archive 3 for Towel Clips.gcode.3mf
+2026-07-22 20:37:15,437 INFO [backend.app.main] [-] [ENERGY] No smart plug for printer 1 (archive 3)
+2026-07-22 20:37:15,437 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-07-22 20:37:15,438 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: H2C)
+2026-07-22 20:37:16,663 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 416020 bytes
+2026-07-22 20:37:16,663 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 416020 bytes
+2026-07-22 20:37:16,663 INFO [backend.app.services.notification_service] [-] on_print_start called for printer 1 ([PRINTER])
+2026-07-22 20:37:16,664 INFO [backend.app.services.notification_service] [-] No notification providers configured for print_start event on printer 1
+2026-07-22 20:37:16,665 INFO [backend.app.main] [-] Loaded 3 printable objects for printer 1
+2026-07-22 20:37:16,808 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=H2C, prot_c=False)
+2026-07-22 20:37:17,142 INFO [backend.app.main] [-] [TIMELAPSE] Baseline at print start: 863 video files for printer 1
+2026-07-22 20:38:47,585 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:39:41,215 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] H2D tray_now: multiple AMS [0, 1] on extruder 0, no snow field, using slot 1 (may be incorrect)
+2026-07-22 20:39:41,216 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=1 at layer=0
+2026-07-22 20:39:42,487 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=5 at layer=0
+2026-07-22 20:43:47,588 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:47:25,566 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=128 at layer=0
+2026-07-22 20:48:39,171 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=5 at layer=0
+2026-07-22 20:48:47,591 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:53:47,594 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:56:34,780 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-07-22 20:56:34,781 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: H2C)
+2026-07-22 20:56:35,994 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 346869 bytes
+2026-07-22 20:56:35,994 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 346869 bytes
+2026-07-22 20:58:47,597 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 20:59:24,500 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 20:59:45,902 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=1 at layer=12
+2026-07-22 20:59:56,590 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:01:16,471 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=5 at layer=13
+2026-07-22 21:02:14,631 INFO [backend.app.main] [-] [SNAPSHOT] Capturing fresh frame for printer 1
+2026-07-22 21:02:14,632 INFO [backend.app.services.camera] [-] Capturing camera frame bytes from [IP] using RTSP (model: H2C)
+2026-07-22 21:02:15,831 INFO [backend.app.services.camera] [-] Successfully captured camera frame bytes: 344500 bytes
+2026-07-22 21:02:15,831 INFO [backend.app.main] [-] [SNAPSHOT] Fresh camera frame: 344500 bytes
+2026-07-22 21:03:47,601 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 21:03:51,716 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:06:11,741 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:07:34,359 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:08:47,603 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 21:08:47,791 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:10:02,338 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:12:20,708 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:12:53,449 INFO [uvicorn.access] [-] [IP]:58644 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-07-22 21:12:53,530 INFO [uvicorn.access] [-] [IP]:58644 - "POST /api/v1/auth/ws-token HTTP/1.1" 200
+2026-07-22 21:12:53,554 INFO [backend.app.api.routes.websocket] [-] WebSocket client connecting (principal=[USER])
+2026-07-22 21:12:53,557 INFO [backend.app.api.routes.websocket] [-] WebSocket client connected
+2026-07-22 21:12:53,557 INFO [backend.app.api.routes.websocket] [-] Sent initial status for 1 printers
+2026-07-22 21:12:53,581 INFO [backend.app.api.routes.printers] [0dbe331a] Cover: resolved plate 1 before download (subtask=Towel Clips)
+2026-07-22 21:12:53,581 INFO [backend.app.api.routes.printers] [0dbe331a] Cover using cached 3MF from /opt/[user]/archive/temp/Towel Clips.gcode.3mf (avoided duplicate FTP)
+2026-07-22 21:12:53,581 INFO [backend.app.api.routes.printers] [0dbe331a] Downloaded file size: 471650 bytes
+2026-07-22 21:12:53,598 INFO [backend.app.api.routes.cloud] [a11c43a4] get_filament_info called with 9 IDs: ['GFA02', 'GFA01', 'P45feeb1', 'P42549c6', 'GFG01', 'P88b1277', 'Pb5cf9e6', 'P45b0529', 'P564a74b']
+2026-07-22 21:12:53,930 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset P45feeb1 (API ID: P45feeb1): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,026 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset P42549c6 (API ID: P42549c6): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,128 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset GFG01 (API ID: GFSG01): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,222 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset P88b1277 (API ID: P88b1277): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,319 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset Pb5cf9e6 (API ID: Pb5cf9e6): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,412 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset P45b0529 (API ID: P45b0529): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,508 WARNING [backend.app.api.routes.cloud] [a11c43a4] Failed to get cloud preset P564a74b (API ID: P564a74b): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:12:54,509 INFO [uvicorn.access] [-] [IP]:58643 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-07-22 21:13:25,165 INFO [uvicorn.access] [-] [IP]:58658 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-07-22 21:13:25,183 INFO [backend.app.api.routes.camera] [f9c9d1d5] Using RTSP protocol for H2C
+2026-07-22 21:13:25,183 INFO [backend.app.api.routes.camera] [f9c9d1d5] Camera viewer attached to printer-1 (subscribers=1)
+2026-07-22 21:13:25,221 INFO [backend.app.services.camera] [f9c9d1d5] RTSP socket I/O timeout flag: -timeout
+2026-07-22 21:13:25,221 INFO [backend.app.api.routes.camera] [f9c9d1d5] Starting RTSP camera stream for [IP] (stream_id=1-fanout, model=H2C, fps=15, probesize=32, analyzeduration=0)
+2026-07-22 21:13:25,255 INFO [uvicorn.access] [-] [IP]:58662 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-07-22 21:13:25,273 INFO [backend.app.api.routes.camera] [c51ccf97] Using RTSP protocol for H2C
+2026-07-22 21:13:25,273 INFO [backend.app.api.routes.camera] [c51ccf97] Camera viewer attached to printer-1 (subscribers=2)
+2026-07-22 21:13:42,941 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-07-22 21:13:47,607 INFO [backend.app.main] [-] Recorded 3 AMS sensor history entries
+2026-07-22 21:14:16,175 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Tray change during print: tray=128 at layer=50
+2026-07-22 21:14:27,490 INFO [backend.app.api.routes.camera] [f9c9d1d5] Camera viewer detached from printer-1 (subscribers=1)
+2026-07-22 21:14:27,490 INFO [backend.app.api.routes.camera] [c51ccf97] Camera viewer detached from printer-1 (subscribers=0)
+2026-07-22 21:14:27,674 INFO [uvicorn.access] [-] [IP]:58671 - "POST /api/v1/printers/camera/stream-token HTTP/1.1" 200
+2026-07-22 21:14:27,795 INFO [uvicorn.access] [-] [IP]:58675 - "POST /api/v1/auth/ws-token HTTP/1.1" 200
+2026-07-22 21:14:27,822 INFO [backend.app.api.routes.websocket] [-] WebSocket client connecting (principal=[USER])
+2026-07-22 21:14:27,827 INFO [backend.app.api.routes.websocket] [-] WebSocket client connected
+2026-07-22 21:14:27,827 INFO [backend.app.api.routes.websocket] [-] Sent initial status for 1 printers
+2026-07-22 21:14:27,846 INFO [backend.app.api.routes.printers] [6a7ac001] Cover: resolved plate 1 before download (subtask=Towel Clips)
+2026-07-22 21:14:27,875 INFO [backend.app.api.routes.cloud] [953ba559] get_filament_info called with 9 IDs: ['GFA02', 'GFA01', 'P45feeb1', 'P42549c6', 'GFG01', 'P88b1277', 'Pb5cf9e6', 'P45b0529', 'P564a74b']
+2026-07-22 21:14:27,877 INFO [uvicorn.access] [-] [IP]:58673 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-07-22 21:14:27,921 INFO [backend.app.api.routes.websocket] [-] WebSocket client disconnected normally
+2026-07-22 21:14:32,490 INFO [backend.app.api.routes.camera] [f9c9d1d5] Camera stream cancelled (stream_id=1-fanout)
+2026-07-22 21:14:34,490 WARNING [backend.app.api.routes.camera] [f9c9d1d5] ffmpeg didn't terminate gracefully, killing (stream_id=1-fanout)
+2026-07-22 21:15:21,787 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=H2C, prot_c=False)
+2026-07-22 21:15:21,789 INFO [backend.app.services.bambu_ftp] [-] FTP connected successfully to [IP] (model=H2C, prot_c=False)
+2026-07-22 21:17:01,506 INFO [backend.app.api.routes.websocket] [-] WebSocket client disconnected normally
+2026-07-22 21:18:14,119 INFO [backend.app.api.routes.cloud] [2f0e446c] get_filament_info called with 9 IDs: ['GFA02', 'GFA01', 'P45feeb1', 'P42549c6', 'GFG01', 'P88b1277', 'Pb5cf9e6', 'P45b0529', 'P564a74b']
+2026-07-22 21:18:14,480 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset P45feeb1 (API ID: P45feeb1): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:14,592 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset P42549c6 (API ID: P42549c6): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:14,684 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset GFG01 (API ID: GFSG01): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:14,778 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset P88b1277 (API ID: P88b1277): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:14,899 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset Pb5cf9e6 (API ID: Pb5cf9e6): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:15,009 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset P45b0529 (API ID: P45b0529): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:15,102 WARNING [backend.app.api.routes.cloud] [2f0e446c] Failed to get cloud preset P564a74b (API ID: P564a74b): Failed to get setting detail: 400 {"message":"missing","code":2,"error":"Please check specified resource exist or not.","public":null,"version":null,"type":null,"name":null,"update_time":null,"nickname":null,"base_id":null,"setting":n
+2026-07-22 21:18:15,103 INFO [uvicorn.access] [-] [IP]:58724 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-07-22 21:18:16,973 INFO [uvicorn.access] [-] [IP]:58722 - "POST /api/v1/auth/ws-token HTTP/1.1" 200
+2026-07-22 21:18:16,999 INFO [backend.app.api.routes.websocket] [-] WebSocket client connecting (principal=[USER])
+2026-07-22 21:18:16,999 INFO [backend.app.api.routes.websocket] [-] WebSocket client connected
+2026-07-22 21:18:17,000 INFO [backend.app.api.routes.websocket] [-] Sent initial status for 1 printers
+2026-07-22 21:18:24,206 INFO [backend.app.api.routes.support] [a950402d] Log level changed to DEBUG
+2026-07-22 21:18:24,206 INFO [backend.app.api.routes.bug_report] [a950402d] Bug report: enabled debug logging
+2026-07-22 21:18:24,206 DEBUG [backend.app.services.bambu_mqtt] [a950402d] [[SERIAL]] Requesting status update (pushall)
+2026-07-22 21:18:24,206 INFO [uvicorn.access] [-] [IP]:58730 - "POST /api/v1/bug-report/start-logging HTTP/1.1" 200
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'allow_skip_parts': False, 'buildplate_marker_detector': True, 'cfg': 1797559, 'first_layer_inspector': True, 'halt_print_sensitivity': 'medium', 'print_halt': True, 'printing_monitor': True, 'spaghetti_detector': True}
+2026-07-22 21:18:25,535 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-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] xcam cfg bitmask: 1797559 (binary: 0b110110110110110110111)
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: RUNNING, gcode_file: /data/Metadata/plate_1.gcode, subtask_name: Towel Clips
+2026-07-22 21:18:25,535 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, 'cfs': [2, 9, 5, 7], 'insert_flag': True, 'power_on_flag': False, 'tray_exist_bits': '100ff', 'tray_hall_out_bits': '10020', 'tray_is_bbl_bits': '100ff', 'tray_now': '0', 'tray_pre': '0', 'tray_read_done_bits': '100ff', 'tray_reading_bits': '0', 'tray_tar': '0', 'unbind_ams_stat': 0, 'version': 21020}
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 128
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 3 new units, 3 total
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x10002003 -> extruder 0
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 1 info=0x10001003 -> extruder 0
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 128 info=0x11002104 -> extruder 1
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0, '1': 0, '128': 1}
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 768 (main=3, sub=0)
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] device.extruder.state=33042 (switch_state bits 12-14: 0)
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] info.temp direct: 31°C (heater OFF)
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ctc_info keys: ['temp']
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=31.0, heating=False, respect_local=False
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 31.0, target: 0.0, heating: False
+2026-07-22 21:18:25,535 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-07-22 21:18:25,536 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': 'enable', 'tl_store_hpd_type': 2, 'tl_store_path_type': 2, 'tutk_server': 'disable'}
+2026-07-22 21:18:25,536 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Timelapse detected during print (from ipcam)
+2026-07-22 21:18:25,536 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -58dBm
+2026-07-22 21:18:25,536 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-07-22 21:18:25,536 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT mapping field: [257, 1, 32768]
+2026-07-22 21:18:25,536 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: RUNNING -> RUNNING, file: /data/Metadata/plate_1.gcode, subtask: Towel Clips