prusa3d / Prusa-Link

153 stars 24 forks source link

Connecting USB webcam causes system to crash #774

Closed neoyarus closed 1 year ago

neoyarus commented 1 year ago

I am using a radxa zero SBC with 2GB of ram and a 4-core CPU connected to a prusa MK3S+ via the RPI0 port on the mainboard. I have a 1080p usb-c webcam, which the radxa zero should have more than enough power to drive. When i connect the webcam without prusalink running, everything is fine. However, when i connect the webcam with prusalink running, the cpu load goes up untill the device becomes unresponsive and crashes. Here are the logs from the moment when i plug in the webcam untill the ssh connection drops out:

rock@radxa-zero:~$ journalctl -f

-- Logs begin at Mon 2023-05-08 19:57:01 UTC. --
Jun 05 10:07:49 radxa-zero sshd[1878]: pam_env(sshd:session): Unable to open env                                                                                              file: /etc/default/locale: No such file or directory
Jun 05 10:07:49 radxa-zero systemd[1956]: Started D-Bus User Message Bus.
Jun 05 10:07:49 radxa-zero systemd[1956]: Started Sound Service.
Jun 05 10:07:49 radxa-zero systemd[1956]: Reached target Main User Target.
Jun 05 10:07:49 radxa-zero systemd[1956]: Startup finished in 1.052s.
Jun 05 10:07:49 radxa-zero bluetoothd[1714]: Endpoint registered: sender=:1.30 p                                                                                             ath=/MediaEndpoint/A2DPSink/sbc
Jun 05 10:07:49 radxa-zero bluetoothd[1714]: Endpoint registered: sender=:1.30 p                                                                                             ath=/MediaEndpoint/A2DPSource/sbc
Jun 05 10:07:49 radxa-zero kernel: Bluetooth: RFCOMM TTY layer initialized
Jun 05 10:07:49 radxa-zero kernel: Bluetooth: RFCOMM socket layer initialized
Jun 05 10:07:49 radxa-zero kernel: Bluetooth: RFCOMM ver 1.11
Jun 05 10:09:07 radxa-zero kernel: usb 1-1: new high-speed USB device number 2 using xhci-hcd
Jun 05 10:09:08 radxa-zero kernel: usb 1-1: New USB device found, idVendor=1bcf, idProduct=0001, bcdDevice=10.02
Jun 05 10:09:08 radxa-zero kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jun 05 10:09:08 radxa-zero kernel: usb 1-1: Product: FHD Webcam
Jun 05 10:09:08 radxa-zero kernel: usb 1-1: Manufacturer: HCVSight
Jun 05 10:09:08 radxa-zero kernel: uvcvideo: Found UVC 1.00 device FHD Webcam (1bcf:0001)
Jun 05 10:09:08 radxa-zero kernel: input: FHD Webcam: FHD Webcam as /devices/platform/soc/ffe09000.usb/ff500000.usb/xhci-hcd.0.auto/usb1/1-1/1-1:1.0/input/input0
Jun 05 10:09:08 radxa-zero kernel: usbcore: registered new interface driver uvcvideo
Jun 05 10:09:08 radxa-zero kernel: USB Video Class driver (1.1.1)
Jun 05 10:09:10 radxa-zero kernel: usb 1-1: Warning! Unlikely big volume range (=2880), cval->res is probably wrong.
Jun 05 10:09:10 radxa-zero kernel: usb 1-1: [5] FU [Mic Capture Volume] ch = 1, val = 0/2880/1
Jun 05 10:09:10 radxa-zero kernel: usbcore: registered new interface driver snd-usb-audio
Jun 05 10:09:10 radxa-zero systemd[1956]: Reached target Sound Card.
Jun 05 10:09:10 radxa-zero systemd-udevd[1993]: controlC1: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 1' failed with exit code 99.
Jun 05 10:09:21 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:09:24 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:09:24 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:09:24 radxa-zero camera_driver[1748]: ERROR: The driver V4L2 broke while taking a photo. Disconnecting {_photo_taker():239}
                                                Traceback (most recent call last):
                                                  File "/home/rock/.local/lib/python3.9/site-packages/prusa/connect/printer/camera_driver.py", line 237, in _photo_taker
                                                    snapshot.data = self.take_a_photo()
                                                  File "/home/rock/.local/lib/python3.9/site-packages/prusa/link/cameras/v4l2_driver.py", line 514, in take_a_photo
                                                    v4l2_source_buffer = self.device.next_frame()
                                                  File "/home/rock/.local/lib/python3.9/site-packages/prusa/link/cameras/v4l2_driver.py", line 344, in next_frame
                                                    raise TimeoutError("Getting the next frame timed out")
                                                TimeoutError: Getting the next frame timed out
Jun 05 10:09:51 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:09:55 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:09:55 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:10:03 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:10:04 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:15 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:21 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:10:21 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:10:31 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:35 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:10:35 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:35 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: Could not get rssi (-110)
Jun 05 10:10:32 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:10:49 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:10:55 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:55 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:10:55 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:10:54 radxa-zero prusa.link.printer_adapter.lcd_printer[1748]: WARNING: Displaying an error message No Internet access  {_check_errors():289}
Jun 05 10:10:56 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:10:56 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:10:58 radxa-zero kernel: brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
Jun 05 10:11:10 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Max retries exceeded with url: /p/telemetry (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0xffff6c7922b0>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution')) {loop_step():738}
Jun 05 10:11:12 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:11:12 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:11:10 radxa-zero systemd-resolved[1603]: Using degraded feature set (UDP) for DNS server 82.209.240.241.
Jun 05 10:11:17 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:11:18 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: Could not get rssi (-110)
Jun 05 10:11:21 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:11:27 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:11:27 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:11:35 radxa-zero kernel: hrtimer: interrupt took 932535 ns
Jun 05 10:11:35 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:11:30 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:11:53 radxa-zero kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Jun 05 10:12:06 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:06 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:12:18 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:24 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:24 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:12:29 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:32 radxa-zero kernel: brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
Jun 05 10:12:35 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:12:38 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:41 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:13:04 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:13:08 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:13:08 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:13:08 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:13:08 radxa-zero kernel: brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
Jun 05 10:13:08 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: Could not get rssi (-110)
Jun 05 10:13:08 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:12:57 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Max retries exceeded with url: /p/telemetry (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0xffff6c792ac0>, 'Connection to connect.prusa3d.com timed out. (connect timeout=10)')) {loop_step():738}
Jun 05 10:13:08 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Max retries exceeded with url: /p/telemetry (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0xffff6c787c70>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution')) {loop_step():738}
Jun 05 10:13:12 radxa-zero kernel: brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
Jun 05 10:13:16 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:13:21 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:13:28 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:13:28 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:13:31 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:13:31 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: Could not get rssi (-110)
Jun 05 10:13:39 radxa-zero connect-printer[1748]: ERROR: ('Connection aborted.', ConnectionResetError(104, 'Connection reset by peer')) {loop_step():738}
Jun 05 10:13:47 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:13:47 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4215] dhcp4 (wlan0): option dhcp_lease_time      => '600'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4282] dhcp4 (wlan0): option domain_name_servers  => '82.209.243.241 82.209.240.241'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4323] dhcp4 (wlan0): option expiry               => '1685960585'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4356] dhcp4 (wlan0): option ip_address           => '192.168.88.15'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4393] dhcp4 (wlan0): option next_server          => '192.168.88.1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4424] dhcp4 (wlan0): option ntp_servers          => '178.124.164.107 62.117.76.142'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4444] dhcp4 (wlan0): option requested_broadcast_address => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4474] dhcp4 (wlan0): option requested_domain_name => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4516] dhcp4 (wlan0): option requested_domain_name_servers => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4541] dhcp4 (wlan0): option requested_domain_search => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4617] dhcp4 (wlan0): option requested_host_name  => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4641] dhcp4 (wlan0): option requested_interface_mtu => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4670] dhcp4 (wlan0): option requested_ms_classless_static_routes => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4695] dhcp4 (wlan0): option requested_nis_domain => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4716] dhcp4 (wlan0): option requested_nis_servers => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4780] dhcp4 (wlan0): option requested_ntp_servers => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4804] dhcp4 (wlan0): option requested_rfc3442_classless_static_routes => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4830] dhcp4 (wlan0): option requested_root_path  => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4864] dhcp4 (wlan0): option requested_routers    => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4885] dhcp4 (wlan0): option requested_static_routes => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4909] dhcp4 (wlan0): option requested_subnet_mask => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4934] dhcp4 (wlan0): option requested_time_offset => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4955] dhcp4 (wlan0): option requested_wpad       => '1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.4991] dhcp4 (wlan0): option routers              => '192.168.88.1'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.5017] dhcp4 (wlan0): option subnet_mask          => '255.255.255.0'
Jun 05 10:13:53 radxa-zero NetworkManager[1608]: <info>  [1685960033.5038] dhcp4 (wlan0): state changed bound -> extended
Jun 05 10:13:54 radxa-zero dbus-daemon[1607]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=1608 comm="/usr/sbin/NetworkManager --no-daemon ")
Jun 05 10:13:54 radxa-zero systemd[1]: Starting Network Manager Script Dispatcher Service...
Jun 05 10:13:54 radxa-zero systemd[1]: Starting Message of the Day...
Jun 05 10:13:55 radxa-zero systemd[1]: motd-news.service: Succeeded.
Jun 05 10:13:55 radxa-zero systemd[1]: Finished Message of the Day.
Jun 05 10:13:56 radxa-zero dbus-daemon[1607]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 05 10:13:56 radxa-zero systemd[1]: Started Network Manager Script Dispatcher Service.
Jun 05 10:13:59 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:02 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:14:02 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:14:02 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:02 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:14:07 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:07 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: Could not get rssi (-110)
Jun 05 10:14:07 radxa-zero systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Jun 05 10:14:08 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:14:08 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:14:08 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:14:08 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:14:09 radxa-zero connect-printer[1748]: ERROR: ('Connection aborted.', ConnectionResetError(104, 'Connection reset by peer')) {loop_step():738}
Jun 05 10:14:12 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:12 radxa-zero kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Jun 05 10:14:12 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:14:12 radxa-zero kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Jun 05 10:14:12 radxa-zero kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Jun 05 10:14:12 radxa-zero kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Jun 05 10:14:19 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:19 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:14:25 radxa-zero kernel: brcmfmac: brcmf_sdio_readframes: RXHEADER FAILED: -110
Jun 05 10:14:25 radxa-zero kernel: brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK
Jun 05 10:14:41 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:14:41 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:49 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:14:49 radxa-zero kernel: ieee80211 phy0: brcmf_fill_bss_param: Failed to get bss info (-110)
Jun 05 10:14:57 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:15:01 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:15:01 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:15:07 radxa-zero connect-printer[1748]: ERROR: HTTPSConnectionPool(host='connect.prusa3d.com', port=443): Read timed out. (read timeout=10) {loop_step():742}
Jun 05 10:15:16 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:15:20 radxa-zero prusa.link.serial.instruction[1748]: WARNING: Instruction M220 did not capture its expected output, so it REFUSES to be confirmed! {confirm():142}
Jun 05 10:15:24 radxa-zero kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Jun 05 10:15:24 radxa-zero kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Interesting log triggered by instruction refusing confirmation. {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M221' confirmed {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Value of item flow_multiplier has been determined to be 100 {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'T:23.6 /0.0 B:24.4 /0.0 T0:23.6 /0.0 @:0 B@:0 P:0.0 A:33.3' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^T:(?P<ntemp>-?\d+\.\d+) /(?P<set_ntemp>-?\d+\.\d+) B:(?P<btemp>-?\d+\.\d+) /(?P<set_btemp>-?\d+\.\d+) T0:(-?\d+\.\d+) /(-?\d+\.\d+) @:(?P<tpwm>-?\d+) B@:(?P<bpwm>-?\d+) P:(?P<ptemp>-?\d+\.\d+)( A:(?P<atemp>-?\d+\.\d+))?$ with priority 0 having 1 handler calling {281473165440480: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff940a35e0>} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'X:0.00 Y:0.00 Z:0.15 E:0.00 Count X: 0.00 Y:0.00 Z:0.15 E:0.00' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^X:(?P<x>-?\d+\.\d+) Y:(?P<y>-?\d+\.\d+) Z:(?P<z>-?\d+\.\d+) E:(?P<e>-?\d+\.\d+) Count X: (?P<count_x>-?\d+\.\d+) Y:(?P<count_y>-?\d+\.\d+) Z:(?P<count_z>-?\d+\.\d+) E:(?P<count_e>-?\d+\.\d+)$ with priority 0 having 1 handler calling {281473165440912: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff940a3790>} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Scheduling invalidation of item flow_multiplier for 1s in the future {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'E0:0 RPM PRN1:0 RPM E0@:0 PRN1@:0' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for E0:(?P<hotend_rpm>\d+) RPM PRN1:(?P<print_rpm>\d+) RPM E0@:(?P<hotend_power>\d+) PRN1@:(?P<print_power>\d+) with priority 0 having 1 handler calling {281473165441056: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff940a3820>} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Gathering new value for item print_state {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M27 P' enqueued to the front {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Item speed_multiplier has been invalidated {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Sent to printer: b'M27 P\n' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Camera id is FHD Webcam: FHD Webcam  {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'Not SD printing' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(?P<sdn_lfn>/.*\..*)|(?P<no_print>Not SD printing)|(?P<serial_paused>Print saved)|(?P<sd_paused>SD print paused)|(?P<byte_pos>SD printing byte (?P<current>\d+)/(?P<sum>\d+))|(?P<printing_time>(?P<hours>\d+):(?P<minutes>\d{2}))$ with priority 1685960114.5056822 having 0 handler calling {} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'ok' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(ok.*)|(Done saving file\.)$ with priority inf having 2 handlers calling {(281473235036336, 281473217475728): <bound method SerialQueue._confirmation_handler of <prusa.link.serial.serial_queue.MonitoredSerialQueue object at 0xffff97243490>>, 281473165901104: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff94113d30>} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M27 P' confirmed {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Value of item print_state has been determined to be PrintState.NOT_SD_PRINTING {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Scheduling invalidation of item print_state for 1s in the future {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Default expected state change is overridden {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Gathering new value for item speed_multiplier {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M220' enqueued  {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Sent to printer: b'M220\n' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: '100%' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(?P<percent>\d{0,3})%$ with priority 1685960114.9277174 having 0 handler calling {} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'ok' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(ok.*)|(Done saving file\.)$ with priority inf having 2 handlers calling {(281473235036336, 281473217475728): <bound method SerialQueue._confirmation_handler of <prusa.link.serial.serial_queue.MonitoredSerialQueue object at 0xffff97243490>>, 281473165901104: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff94113d30>} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Value of item speed_multiplier has been determined to be 100 {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M220' confirmed {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Scheduling invalidation of item speed_multiplier for 1s in the future {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Item flow_multiplier has been invalidated {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Gathering new value for item flow_multiplier {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M221' enqueued  {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Sent to printer: b'M221\n' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: '100%' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(?P<percent>\d{0,3})%$ with priority 1685960115.406025 having 0 handler calling {} {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'ok' {_confirmed():431}
Jun 05 10:15:20 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(ok.*)|(Done saving file\.)$ with priority inf having 2 handlers calling {(281473235036336, 281473217475728): <bound method SerialQueue._confirmation_handler of <prusa.link.serial.serial_queue.MonitoredSerialQueue object at 0xffff97243490>>, 281473165901104: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff94113d30>} {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Value of item flow_multiplier has been determined to be 100 {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M221' confirmed {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M117 ~see 192.168.88.26' enqueued to the front {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Scheduling invalidation of item flow_multiplier for 1s in the future {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Sent to printer: b'M117 ~see 192.168.88.26  \n' {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'LCD status changed' {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^LCD status changed$ with priority 0 having 1 handler calling {281473208597808: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff969cbd30>} {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'ok' {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Matched RegexPairing for ^(ok.*)|(Done saving file\.)$ with priority inf having 2 handlers calling {(281473235036336, 281473217475728): <bound method SerialQueue._confirmation_handler of <prusa.link.serial.serial_queue.MonitoredSerialQueue object at 0xffff97243490>>, 281473165901104: <function ThreadedSerialParser.decoupled.<locals>.inner at 0xffff94113d30>} {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printed: 'see 192.168.88.26  ' on the LCD. {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M117 ~see 192.168.88.26' confirmed {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Item print_state has been invalidated {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Gathering new value for item print_state {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Instruction 'M27 P' enqueued to the front {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Sent to printer: b'M27 P\n' {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Printer says: 'Not SD printing' {_confirmed():431}
Jun 05 10:15:21 radxa-zero interesting_logger[1748]: WARNING: Was[DEBUG]: Ma
TojikCZ commented 1 year ago

Sorry, i just thought it would quack like an Ubuntu Even the kernel is old. 5.10.69 I'm running 6.3.6 Yours is from the September 2021 It's not that bad, but it's def not recent, but it probably won't have much effect anyways I use arch btw :D so I would try out manjaro, they seem to have a recent image available, but who knows if it works as expected Again, sorry for not being of much help. I'll be off on the weekend, so see ya on monday

neoyarus commented 1 year ago

Thanks for the help. I'll probably experiement with different images over the weekend, maybe the majaro ones will support the overlay that i need for communicating with the printer over gpio pins. See you on monday :)

neoyarus commented 1 year ago

It looks like i was able to fix the issue by installing a newer (pre-release) ubuntu image. There was a bunch of new issues during install, but once i got them resolved with the help of chatGPT, the camera works fine and prusalink does not crash.