Bug report logs 81ff979a87fd46429cfa6209ec214f5a.log

logs/81ff979a87fd46429cfa6209ec214f5a.log

@@ -0,0 +1,200 @@
+2026-08-17 21:06:26,059 INFO [backend.app.services.virtual_printer.certificate] [af272bb9] Using existing CA certificate (expires in 7280 days)
+2026-08-17 21:06:46,734 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:06:46,736 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:07:16,747 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:07:16,749 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:07:46,760 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:07:46,762 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:08:16,773 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:08:16,775 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:08:46,785 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:08:46,787 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:09:16,799 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:09:16,801 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:09:46,812 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:09:46,814 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:10:16,825 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:10:16,827 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:10:46,841 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:10:46,843 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:11:16,854 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:11:16,856 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:11:46,866 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:11:46,869 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:11:57,960 INFO [backend.app.services.virtual_printer.bind_server] [-] Bind server: client connected from [IP]:56075
+2026-08-17 21:11:57,963 INFO [backend.app.services.virtual_printer.bind_server] [-] Bind server: received from [IP]:56075: {'login': {'command': 'detect', 'sequence_id': '20000'}}
+2026-08-17 21:11:57,963 INFO [backend.app.services.virtual_printer.bind_server] [-] Bind server: sent detect response to [IP]:56075 (serial=[SERIAL])
+2026-08-17 21:11:59,496 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] MQTT TLS connection from ('[IP]', 56076) - cipher=('TLS_AES_256_GCM_SHA384', 'TLSv1.3', 256), version=TLSv1.3
+2026-08-17 21:11:59,496 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] MQTT client connected: [IP]:56076
+2026-08-17 21:11:59,499 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] MQTT client authenticated successfully
+2026-08-17 21:11:59,499 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] MQTT client [IP]:56076 authenticated (negotiated keepalive=60s, idle disconnect disabled)
+2026-08-17 21:11:59,508 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] MQTT subscribe: device/[SERIAL]/report QoS=0
+2026-08-17 21:11:59,531 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"pushing":{"command":"pushall","push_target":1,"sequence_id":"20001","version":1}}...
+2026-08-17 21:11:59,531 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT pushing command: pushall
+2026-08-17 21:11:59,531 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sending status report in response to pushall
+2026-08-17 21:11:59,534 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"info":{"command":"get_version","sequence_id":"20002"}}...
+2026-08-17 21:11:59,534 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT info command: get_version
+2026-08-17 21:11:59,535 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sent version response (product_name=A1)
+2026-08-17 21:11:59,535 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"info":{"command":"get_version","sequence_id":"20003"}}...
+2026-08-17 21:11:59,535 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT info command: get_version
+2026-08-17 21:11:59,535 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sent version response (product_name=A1)
+2026-08-17 21:11:59,619 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"print":{"command":"extrusion_cali_get","filament_id":"","nozzle_diameter":"0.4","sequence_id":"200...
+2026-08-17 21:11:59,619 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT print command: extrusion_cali_get for 
+2026-08-17 21:12:00,600 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"print":{"command":"extrusion_cali_get","filament_id":"","nozzle_diameter":"0.4","sequence_id":"200...
+2026-08-17 21:12:00,600 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT print command: extrusion_cali_get for 
+2026-08-17 21:12:01,619 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"print":{"command":"extrusion_cali_get","filament_id":"","nozzle_diameter":"0.4","sequence_id":"200...
+2026-08-17 21:12:01,619 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT print command: extrusion_cali_get for 
+2026-08-17 21:12:02,620 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"print":{"command":"extrusion_cali_get","filament_id":"","nozzle_diameter":"0.4","sequence_id":"200...
+2026-08-17 21:12:02,620 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT print command: extrusion_cali_get for 
+2026-08-17 21:12:16,879 INFO [backend.app.services.print_scheduler] [-] Queue check: found 1 pending items: [(26, 1, 21, None)]
+2026-08-17 21:12:16,881 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:12:18,432 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"info":{"command":"get_version","sequence_id":"20008"}}...
+2026-08-17 21:12:18,432 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT info command: get_version
+2026-08-17 21:12:18,432 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sent version response (product_name=A1)
+2026-08-17 21:12:18,434 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"pushing":{"command":"pushall","push_target":1,"sequence_id":"20009","version":1}}...
+2026-08-17 21:12:18,434 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT pushing command: pushall
+2026-08-17 21:12:18,434 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sending status report in response to pushall
+2026-08-17 21:12:20,531 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP connection from ('[IP]', 50174)
+2026-08-17 21:12:20,536 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP login from [IP]
+2026-08-17 21:12:20,548 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP EPSV listening on port 50003
+2026-08-17 21:12:20,557 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP receiving file: verify_job from [IP]
+2026-08-17 21:12:20,569 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data TLS from [IP]: cipher=('ECDHE-RSA-AES256-GCM-SHA384', 'TLSv1.2', 256), version=TLSv1.2, session_reused=True
+2026-08-17 21:12:20,569 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data connection established from [IP]
+2026-08-17 21:12:20,669 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP saved file: /opt/[user]/virtual_printer/uploads/1/verify_job (16 bytes)
+2026-08-17 21:12:20,669 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Received file: verify_job from [IP]
+2026-08-17 21:12:20,674 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session cancelled from [IP]
+2026-08-17 21:12:20,674 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session ended from [IP]
+2026-08-17 21:12:20,692 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP connection from ('[IP]', 50178)
+2026-08-17 21:12:20,698 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP login from [IP]
+2026-08-17 21:12:20,709 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP EPSV listening on port 50003
+2026-08-17 21:12:20,718 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP receiving file: Number_with_name_Plate 1.gcode.3mf from [IP]
+2026-08-17 21:12:20,725 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data TLS from [IP]: cipher=('ECDHE-RSA-AES256-GCM-SHA384', 'TLSv1.2', 256), version=TLSv1.2, session_reused=True
+2026-08-17 21:12:20,725 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data connection established from [IP]
+2026-08-17 21:12:20,896 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP saved file: /opt/[user]/virtual_printer/uploads/1/Number_with_name_Plate 1.gcode.3mf (898920 bytes)
+2026-08-17 21:12:20,896 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Received file: Number_with_name_Plate 1.gcode.3mf from [IP]
+2026-08-17 21:12:25,922 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Archived: 27 - Number_with_name_Plate 1
+2026-08-17 21:12:25,928 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Added to queue: 35
+2026-08-17 21:12:25,929 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session cancelled from [IP]
+2026-08-17 21:12:25,929 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session ended from [IP]
+2026-08-17 21:12:37,564 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"info":{"command":"get_version","sequence_id":"20010"}}...
+2026-08-17 21:12:37,564 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT info command: get_version
+2026-08-17 21:12:37,564 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sent version response (product_name=A1)
+2026-08-17 21:12:37,567 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"pushing":{"command":"pushall","push_target":1,"sequence_id":"20011","version":1}}...
+2026-08-17 21:12:37,567 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT pushing command: pushall
+2026-08-17 21:12:37,567 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sending status report in response to pushall
+2026-08-17 21:12:39,757 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP connection from ('[IP]', 58768)
+2026-08-17 21:12:39,765 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP login from [IP]
+2026-08-17 21:12:39,781 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP EPSV listening on port 50000
+2026-08-17 21:12:39,790 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP receiving file: verify_job from [IP]
+2026-08-17 21:12:39,796 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data TLS from [IP]: cipher=('ECDHE-RSA-AES256-GCM-SHA384', 'TLSv1.2', 256), version=TLSv1.2, session_reused=True
+2026-08-17 21:12:39,796 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data connection established from [IP]
+2026-08-17 21:12:39,898 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP saved file: /opt/[user]/virtual_printer/uploads/1/verify_job (16 bytes)
+2026-08-17 21:12:39,898 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Received file: verify_job from [IP]
+2026-08-17 21:12:39,903 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session cancelled from [IP]
+2026-08-17 21:12:39,903 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session ended from [IP]
+2026-08-17 21:12:39,918 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP connection from ('[IP]', 64004)
+2026-08-17 21:12:39,926 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP login from [IP]
+2026-08-17 21:12:39,937 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP EPSV listening on port 50003
+2026-08-17 21:12:39,947 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP receiving file: Number_with_name_Plate 2.gcode.3mf from [IP]
+2026-08-17 21:12:39,954 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data TLS from [IP]: cipher=('ECDHE-RSA-AES256-GCM-SHA384', 'TLSv1.2', 256), version=TLSv1.2, session_reused=True
+2026-08-17 21:12:39,954 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP data connection established from [IP]
+2026-08-17 21:12:40,171 INFO [backend.app.services.virtual_printer.ftp_server] [-] FTP saved file: /opt/[user]/virtual_printer/uploads/1/Number_with_name_Plate 2.gcode.3mf (1564957 bytes)
+2026-08-17 21:12:40,171 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Received file: Number_with_name_Plate 2.gcode.3mf from [IP]
+2026-08-17 21:12:45,200 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Archived: 28 - Number_with_name_Plate 2
+2026-08-17 21:12:45,205 INFO [backend.app.services.virtual_printer.manager] [-] [VP Bambuddy] Added to queue: 36
+2026-08-17 21:12:45,206 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session cancelled from [IP]
+2026-08-17 21:12:45,206 INFO [backend.app.services.virtual_printer.ftp_server] [-] [Bambuddy] FTP session ended from [IP]
+2026-08-17 21:12:46,815 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 48 pushes/min to [IP]:56076
+2026-08-17 21:12:46,893 INFO [backend.app.services.print_scheduler] [-] Queue check: found 3 pending items: [(26, 1, 21, None), (35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:12:46,895 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 3}
+2026-08-17 21:12:52,188 INFO [backend.app.api.routes.print_queue] [be353952] Cancelled queue item 26
+2026-08-17 21:12:52,188 INFO [uvicorn.access] [-] [IP]:64392 - "POST /api/v1/queue/26/cancel HTTP/1.1" 200
+2026-08-17 21:12:57,292 INFO [backend.app.services.homeassistant] [481757f4] Turned ON HA entity '3ddrucker' (switch.3ddrucker)
+2026-08-17 21:12:57,297 INFO [uvicorn.access] [-] [IP]:52145 - "POST /api/v1/smart-plugs/1/control HTTP/1.1" 200
+2026-08-17 21:13:12,615 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] MQTT disconnected: rc=Unspecified error, flags=DisconnectFlags(is_disconnect_packet_from_server=False)
+2026-08-17 21:13:12,616 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Disconnected shortly after request topic subscription. Disabling request topic for this printer.
+2026-08-17 21:13:12,616 INFO [backend.app.main] [-] [#1752] Printer 1 connected→disconnected edge; scheduling offline notification in 60s
+2026-08-17 21:13:14,400 INFO [backend.app.main] [-] [#1752] Printer 1 reconnected before debounce; cancelling pending offline notification
+2026-08-17 21:13:14,436 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Firmware version: 01.08.00.00
+2026-08-17 21:13:14,955 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-08-17 21:13:14,957 INFO [backend.app.main] [-] [Printer 1] Broadcasting AMS change via WebSocket
+2026-08-17 21:13:15,910 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"info":{"command":"get_version","sequence_id":"20012"}}...
+2026-08-17 21:13:15,910 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT info command: get_version
+2026-08-17 21:13:15,910 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sent version response (product_name=A1)
+2026-08-17 21:13:16,937 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:13:16,938 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 2}
+2026-08-17 21:13:21,114 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Probing developer mode via ams_filament_setting (seq=5)
+2026-08-17 21:13:21,135 INFO [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Developer mode probe: ENABLED (result='success')
+2026-08-17 21:13:21,299 INFO [backend.app.api.routes.cloud] [8199fb64] get_filament_info called with 3 IDs: ['GFL99', 'Pbe7b418', 'GFU99']
+2026-08-17 21:13:21,306 INFO [uvicorn.access] [-] [IP]:49669 - "POST /api/v1/cloud/filament-info HTTP/1.1" 200
+2026-08-17 21:13:24,412 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS unit 0: serial number not available in version info
+2026-08-17 21:13:24,412 WARNING [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS unit 0: firmware version not available in version info
+2026-08-17 21:13:46,879 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:13:46,950 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:13:46,952 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 2}
+2026-08-17 21:14:16,961 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:14:16,964 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 2}
+2026-08-17 21:14:34,858 INFO [backend.app.api.routes.print_queue] [4788f8aa] Updated queue item 36
+2026-08-17 21:14:34,859 INFO [uvicorn.access] [-] [IP]:54247 - "PATCH /api/v1/queue/36 HTTP/1.1" 200
+2026-08-17 21:14:46,911 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:14:46,974 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:14:46,976 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:14:46,976 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:14:56,507 INFO [backend.app.main] [-] Recorded 1 AMS sensor history entries
+2026-08-17 21:15:06,372 INFO [uvicorn.access] [-] [IP]:43144 - "PATCH /api/v1/settings HTTP/1.1" 200
+2026-08-17 21:15:16,987 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:15:16,989 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:15:16,989 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:15:46,936 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:15:47,001 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:15:47,003 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:15:47,004 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:16:17,016 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:16:17,018 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:16:17,018 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:16:46,970 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:16:47,030 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:16:47,032 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:16:47,032 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:16:59,405 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT publish to device/[SERIAL]/request: {"pushing":{"command":"pushall","push_target":1,"sequence_id":"20013","version":1}}...
+2026-08-17 21:16:59,405 INFO [backend.app.services.virtual_printer.mqtt_server] [-] MQTT pushing command: pushall
+2026-08-17 21:16:59,405 INFO [backend.app.services.virtual_printer.mqtt_server] [-] Sending status report in response to pushall
+2026-08-17 21:17:17,044 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:17:17,046 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:17:17,046 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:17:47,006 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:17:47,058 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:17:47,059 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:17:47,060 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:18:17,071 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:18:17,073 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:18:17,073 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:18:47,040 INFO [backend.app.services.virtual_printer.mqtt_server] [-] [Bambuddy] 1Hz status push: 60 pushes/min to [IP]:56076
+2026-08-17 21:18:47,084 INFO [backend.app.services.print_scheduler] [-] Queue check: found 2 pending items: [(35, 1, 27, None), (36, 1, 28, None)]
+2026-08-17 21:18:47,086 INFO [backend.app.services.print_scheduler] [-] Queue skip summary: {'manual_start': 1}
+2026-08-17 21:18:47,086 INFO [backend.app.services.print_scheduler] [-] Queue: printer 1 not available — connected=True, state=IDLE, awaiting_plate_clear=True
+2026-08-17 21:18:53,053 INFO [backend.app.api.routes.support] [1d08e834] Log level changed to DEBUG
+2026-08-17 21:18:53,053 INFO [backend.app.api.routes.bug_report] [1d08e834] Bug report: enabled debug logging
+2026-08-17 21:18:53,053 DEBUG [backend.app.services.bambu_mqtt] [1d08e834] [[SERIAL]] Requesting status update (pushall)
+2026-08-17 21:18:53,053 INFO [uvicorn.access] [-] [IP]:60608 - "POST /api/v1/bug-report/start-logging HTTP/1.1" 200
+2026-08-17 21:18:53,629 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Found xcam inside print data: {'buildplate_marker_detector': True}
+2026-08-17 21:18:53,629 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Parsing xcam data - all fields: ['buildplate_marker_detector']
+2026-08-17 21:18:53,629 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received gcode_state: IDLE, gcode_file: , subtask_name: 
+2026-08-17 21:18:53,629 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS dict fields: {'ams_exist_bits': '1', 'tray_exist_bits': 'f', 'tray_is_bbl_bits': 'f', 'tray_tar': '255', 'tray_now': '255', 'tray_pre': '255', 'tray_read_done_bits': 'f', 'tray_reading_bits': '0', 'version': 10, 'insert_flag': True, 'power_on_flag': False}
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] tray_now updated: 255
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Merged AMS data: 1 new units, 1 total
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] AMS 0 info=0x1002 -> extruder 0
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_extruder_map: {'0': 0}
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ams_status: 0 (main=0, sub=0)
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper raw value: 5.0
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] chamber_temper direct value: 5.0°C (heater OFF)
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber heating calculated: target=0.0, current=5.0, heating=False, respect_local=False
+2026-08-17 21:18:53,630 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Chamber temp updated to: 5.0, target: 0.0, heating: False
+2026-08-17 21:18:53,631 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] HMS data received: []
+2026-08-17 21:18:53,631 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] ipcam field: {'ipcam_dev': '1', 'ipcam_record': 'enable', 'timelapse': 'disable', 'resolution': '1080p', 'tutk_server': 'disable', 'mode_bits': 3}
+2026-08-17 21:18:53,631 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] wifi_signal received: -32dBm
+2026-08-17 21:18:53,631 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] lights_report: [{'node': 'chamber_light', 'mode': 'on'}]
+2026-08-17 21:18:53,631 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] gcode_state: IDLE -> IDLE, file: , subtask: 
+2026-08-17 21:18:56,533 DEBUG [backend.app.main] [-] Recorded 3 printer sensor history entries
+2026-08-17 21:18:57,766 DEBUG [backend.app.services.bambu_mqtt] [-] [[SERIAL]] Received command response: push_status