Astrobox freezing - complains about bluetooth

Spencer_Owen · February 9, 2018, 9:53pm

I’ve started using astrobox. In the last 2 days my rasbperry pi has locked up 3 times (ruining the print).

Looking at syslog, it appears that it is starting the SDP server, then activating bluetooth, then starting the hostname service and then locking up.

Errors happen around 20:17:00. I reboot the pi at 20:59:00

Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Activation (wlan2) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Activation (wlan2) Stage 5 of 5 (IPv4 Commit) started...
Feb  9 20:17:08 astrobox1 avahi-daemon[433]: Joining mDNS multicast group on interface wlan2.IPv4 with address 192.168.1.189.
Feb  9 20:17:08 astrobox1 avahi-daemon[433]: New relevant interface wlan2.IPv4 for mDNS.
Feb  9 20:17:08 astrobox1 avahi-daemon[433]: Registering new address record for 192.168.1.189 on wlan2.IPv4.
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> (wlan2): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Activation (wlan2) Stage 5 of 5 (IPv4 Commit) complete.
Feb  9 20:17:08 astrobox1 dhclient: bound to 192.168.1.189 -- renewal in 2653 seconds.
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> (wlan2): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> (wlan2): device state change: secondaries -> activated (reason 'none') [90 100 0]
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> NetworkManager state is now CONNECTED_LOCAL
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> NetworkManager state is now CONNECTED_GLOBAL
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Policy set 'The LAN Before Time' (wlan2) as default for IPv4 routing and DNS.
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Writing DNS information to /sbin/resolvconf
Feb  9 20:17:08 astrobox1 ModemManager[441]: <warn>  Couldn't find support for device at '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1': not supported by any plugin
Feb  9 20:17:08 astrobox1 ModemManager[441]: <warn>  Couldn't find support for device at '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5': not supported by any plugin
Feb  9 20:17:08 astrobox1 systemd[1]: Stopping LSB: Starts the Name Service Cache Daemon...
Feb  9 20:17:08 astrobox1 nscd[860]: Stopping Name Service Cache Daemon: nscd.
Feb  9 20:17:08 astrobox1 systemd[1]: Starting LSB: Starts the Name Service Cache Daemon...
Feb  9 20:17:08 astrobox1 nscd: 875 cannot stat() file `/etc/netgroup': No such file or directory
Feb  9 20:17:08 astrobox1 nscd[869]: Starting Name Service Cache Daemon: nscd.
Feb  9 20:17:08 astrobox1 systemd[1]: Started LSB: Starts the Name Service Cache Daemon.
Feb  9 20:17:08 astrobox1 NetworkManager[436]: <info> Activation (wlan2) successful, device activated.
Feb  9 20:17:08 astrobox1 dbus[446]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Feb  9 20:17:08 astrobox1 systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb  9 20:17:09 astrobox1 dbus[446]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb  9 20:17:09 astrobox1 systemd[1]: Started Network Manager Script Dispatcher Service.
Feb  9 20:17:09 astrobox1 nm-dispatcher: Dispatching action 'up' for wlan2
Feb  9 20:17:09 astrobox1 dhcpcd[435]: wlan2: soliciting an IPv6 router
Feb  9 20:17:09 astrobox1 dhcpcd[435]: wlan2: rebinding lease of 192.168.1.186
Feb  9 20:17:09 astrobox1 kernel: [   11.360249] Bluetooth: Core ver 2.22
Feb  9 20:17:09 astrobox1 kernel: [   11.360340] NET: Registered protocol family 31
Feb  9 20:17:09 astrobox1 kernel: [   11.360346] Bluetooth: HCI device and connection manager initialized
Feb  9 20:17:09 astrobox1 kernel: [   11.361327] Bluetooth: HCI socket layer initialized
Feb  9 20:17:09 astrobox1 kernel: [   11.361342] Bluetooth: L2CAP socket layer initialized
Feb  9 20:17:09 astrobox1 kernel: [   11.361377] Bluetooth: SCO socket layer initialized
Feb  9 20:17:09 astrobox1 btuart[443]: bcm43xx_init
Feb  9 20:17:09 astrobox1 kernel: [   11.369113] Bluetooth: HCI UART driver ver 2.3
Feb  9 20:17:09 astrobox1 kernel: [   11.369127] Bluetooth: HCI UART protocol H4 registered
Feb  9 20:17:09 astrobox1 kernel: [   11.369132] Bluetooth: HCI UART protocol Three-wire (H5) registered
Feb  9 20:17:09 astrobox1 kernel: [   11.369305] Bluetooth: HCI UART protocol Broadcom registered
Feb  9 20:17:09 astrobox1 btuart[443]: Flash firmware /lib/firmware/BCM43430A1.hcd
Feb  9 20:17:09 astrobox1 btuart[443]: Set Controller UART speed to 921600 bit/s
Feb  9 20:17:09 astrobox1 btuart[443]: Device setup complete
Feb  9 20:17:09 astrobox1 systemd[1]: Started Configure Bluetooth Modems connected by UART.
Feb  9 20:17:10 astrobox1 systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill1...
Feb  9 20:17:10 astrobox1 systemd[1]: Starting Bluetooth service...
Feb  9 20:17:10 astrobox1 systemd[1]: Started Load/Save RF Kill Switch Status of rfkill1.
Feb  9 20:17:10 astrobox1 bluetoothd[959]: Bluetooth daemon 5.23
Feb  9 20:17:10 astrobox1 systemd[1]: Started Bluetooth service.
Feb  9 20:17:10 astrobox1 systemd[1]: Starting Bluetooth.
Feb  9 20:17:10 astrobox1 systemd[1]: Reached target Bluetooth.
Feb  9 20:17:10 astrobox1 bluetoothd[959]: Starting SDP server
Feb  9 20:17:10 astrobox1 kernel: [   11.517727] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Feb  9 20:17:10 astrobox1 kernel: [   11.517739] Bluetooth: BNEP filters: protocol multicast
Feb  9 20:17:10 astrobox1 kernel: [   11.517759] Bluetooth: BNEP socket layer initialized
Feb  9 20:17:10 astrobox1 bluetoothd[959]: Bluetooth management interface 1.14 initialized
Feb  9 20:17:10 astrobox1 dbus[446]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
Feb  9 20:17:10 astrobox1 bluetoothd[959]: Sap driver initialization failed.
Feb  9 20:17:10 astrobox1 bluetoothd[959]: sap-server: Operation not permitted (1)
Feb  9 20:17:10 astrobox1 systemd[1]: Starting Hostname Service...
Feb  9 20:17:10 astrobox1 NetworkManager[436]: <info> use BlueZ version 5
Feb  9 20:17:10 astrobox1 systemd-hostnamed[963]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname!
Feb  9 20:17:10 astrobox1 dbus[446]: [system] Successfully activated service 'org.freedesktop.hostname1'
Feb  9 20:17:10 astrobox1 systemd[1]: Started Hostname Service.
Feb  9 20:59:14 astrobox1 astrobox[430]: Starting astrobox: astroboxFri  9 Feb 20:59:14 UTC 2018
Feb  9 20:59:14 astrobox1 rsyslogd-2007: action 'action 19' suspended, next retry is Fri Feb  9 20:59:44 2018 [try http://www.rsyslog.com/e/2007 ]

What could be causing my raspberry pi to lock up?

It seems to loosely correlate with me doing bigger prints, and also using the time laps feature.

Daniel · February 10, 2018, 6:06pm

Are you using the standard release? The bluetooth is likely a red herring. We don’t currently use it for anything.

Spencer_Owen · February 11, 2018, 8:02pm

Using the latest release.

I’ve had this happen twice more.
I’ve got a camera for my printer this week, and the crashes seem to correlate with when I check the video stream from my phone.

It almost seams like the act of checking the video stream is overwhelming the network or the cpu.

I’ve switched from wireless to a wired connection on the raspberry pi but the problem continues.

Another very strange correlation is the rasbperry pi becomes unresponsive at exactly 17 minutes an 9 seconds after the hour.

Compare the timestamps from the logs from February 9th with February 11th. The last line before the system lock up is

  Feb 11 16:17:09 astrobox1 systemd[1]: Started Hostname Service.

Feb 11 16:17:09 astrobox1 bluetoothd[962]: Bluetooth management interface 1.14 initialized
Feb 11 16:17:09 astrobox1 kernel: [   11.058960] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Feb 11 16:17:09 astrobox1 kernel: [   11.058968] Bluetooth: BNEP filters: protocol multicast
Feb 11 16:17:09 astrobox1 kernel: [   11.058981] Bluetooth: BNEP socket layer initialized
Feb 11 16:17:09 astrobox1 systemd[1]: Starting Hostname Service...
Feb 11 16:17:09 astrobox1 bluetoothd[962]: Sap driver initialization failed.
Feb 11 16:17:09 astrobox1 bluetoothd[962]: sap-server: Operation not permitted (1)
Feb 11 16:17:09 astrobox1 NetworkManager[420]: <info> use BlueZ version 5
Feb 11 16:17:09 astrobox1 systemd-hostnamed[965]: Warning: nss-myhostname is not installed. Changing the local hostn
ame might make it unresolveable. Please install nss-myhostname!
Feb 11 16:17:09 astrobox1 dbus[439]: [system] Successfully activated service 'org.freedesktop.hostname1'
Feb 11 16:17:09 astrobox1 systemd[1]: Started Hostname Service. <----- THIS IS WHERE IT LOCKED UP
Feb 11 19:55:10 astrobox1 astrobox[417]: Starting astrobox: astroboxSun 11 Feb 19:55:10 UTC 2018  
Feb 11 19:55:10 astrobox1 systemd[1]: Time has been changed
Feb 11 19:55:10 astrobox1 rsyslogd-2007: action 'action 19' suspended, next retry is Sun Feb 11 19:55:40 2018 [try h
ttp://www.rsyslog.com/e/2007 ]

Daniel · February 11, 2018, 8:26pm

What’s he amperage of your power supply ?