+- OpenMarine (https://forum.openmarine.net)
+-- Forum: OpenPlotter (https://forum.openmarine.net/forumdisplay.php?fid=1)
+--- Forum: Bug Reports (https://forum.openmarine.net/forumdisplay.php?fid=4)
+--- Thread: Openplotter restarting overnight and failing (/showthread.php?tid=4093)
Openplotter restarting overnight and failing - pscheepe - 2022-06-06
Hallo,
I am using Openplotter 2 on a rpi 4 with 4 GB, with USB Ublox 7 GPS and SDR TV stick together with AvNav and a BME 280 sensor. All works fine, but when I leave it running overnight it seems to do a restart at 00:00 and than failed on a Network connection. I looked at the syslog and it seems to me that a network connection failed (see screenshot attached).
As I want to extend the functionality to provide me with temperature, humidity and acceleration alarms via email when the boat is at birth, I need the system to be running 24/7 without interruption.
Anyone any idea?
RE: Openplotter restarting overnight and failing - Sailoog - 2022-06-06
That is really strange. Always at 00:00???
There is not screenshot.
RE: Openplotter restarting overnight and failing - pscheepe - 2022-06-06
Hallo Sailoog,
Thanks for your quick reply.
the screenshot was too big to be send but i seem to be unable to add an attachment therefore here is the text from the syslog up till the moment I restart Openplotter, hope this helps:
Jun 6 00:00:01 openplotter rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="502" x-info="https://www.rsyslog.com"] rsyslogd was HUPed
Jun 6 00:00:01 openplotter systemd[1]: logrotate.service: Succeeded.
Jun 6 00:00:01 openplotter systemd[1]: Started Rotate log files.
Jun 6 00:00:01 openplotter avnav[598]: 2022-06-06 00:00:01,598-598-598-MainThread-INFO-basedir=/usr/lib/avnav/server,datadir=/home/pi/avnav/data
Jun 6 00:00:01 openplotter avnav[598]: 2022-06-06 00:00:01,600-598-598-MainThread-INFO-####start processing (version=20220421, logging to /home/pi/avnav/data/log/avnav.log, parameters=/usr/lib/avnav/server/avnav_server.py -q -l INFO -c /home/pi/avnav/data/charts -w /home/pi/avnav/data -u viewer=/usr/lib/avnav/viewer,libraries=/usr/lib/avnav/viewer/libraries,sounds=/usr/lib/avnav/sounds /home/pi/avnav/data/avnav_server.xml)####
Jun 6 00:00:01 openplotter systemd-networkd[156]: wlan0: Gained IPv6LL
Jun 6 00:00:01 openplotter avahi-daemon[520]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::dea6:32ff:fe1b:25b3.
Jun 6 00:00:01 openplotter avahi-daemon[520]: New relevant interface wlan0.IPv6 for mDNS.
Jun 6 00:00:01 openplotter avahi-daemon[520]: Registering new address record for fe80::dea6:32ff:fe1b:25b3 on wlan0.*.
Jun 6 00:00:01 openplotter systemd-timesyncd[339]: Network configuration changed, trying to establish connection.
Jun 6 00:00:02 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=920 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ")
Jun 6 00:00:02 openplotter systemd[817]: Starting Virtual filesystem service...
Jun 6 00:00:02 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.Daemon'
Jun 6 00:00:02 openplotter systemd[817]: Started Virtual filesystem service.
Jun 6 00:00:02 openplotter kernel: [ 23.702484] fuse: init (API version 7.31)
Jun 6 00:00:02 openplotter systemd[1]: Mounting FUSE Control File System...
Jun 6 00:00:02 openplotter systemd[1]: Mounted FUSE Control File System.
Jun 6 00:00:03 openplotter systemd[817]: Starting Sound Service...
Jun 6 00:00:03 openplotter systemd[1]: man-db.service: Succeeded.
Jun 6 00:00:03 openplotter systemd[1]: Started Daily man-db regeneration.
Jun 6 00:00:03 openplotter dbus-daemon[511]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.39' (uid=1000 pid=1055 comm="/usr/bin/pulseaudio --daemonize=no ")
Jun 6 00:00:03 openplotter systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Jun 6 00:00:03 openplotter dbus-daemon[511]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Successfully called chroot.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Successfully dropped privileges.
Jun 6 00:00:03 openplotter systemd[1]: Started RealtimeKit Scheduling Policy Service.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Successfully limited resources.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Running.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Watchdog thread running.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Canary thread running.
Jun 6 00:00:03 openplotter avahi-daemon[520]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::dea6:32ff:fe1b:25b3.
Jun 6 00:00:03 openplotter systemd-timesyncd[339]: Network configuration changed, trying to establish connection.
Jun 6 00:00:03 openplotter avahi-daemon[520]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2a02:a448:6097:1:dea6:32ff:fe1b:25b3.
Jun 6 00:00:03 openplotter systemd[1]: openplotter-gpio-read.service: Service RestartSec=5s expired, scheduling restart.
Jun 6 00:00:03 openplotter avahi-daemon[520]: Registering new address record for 2a02:a448:6097:1:dea6:32ff:fe1b:25b3 on wlan0.*.
Jun 6 00:00:03 openplotter systemd[1]: openplotter-gpio-read.service: Scheduled restart job, restart counter is at 1.
Jun 6 00:00:03 openplotter avahi-daemon[520]: Withdrawing address record for fe80::dea6:32ff:fe1b:25b3 on wlan0.
Jun 6 00:00:03 openplotter systemd[1]: Stopped openplotter-gpio-read.service.
Jun 6 00:00:03 openplotter systemd[1]: Started openplotter-gpio-read.service.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Successfully made thread 1055 of process 1055 (n/a) owned by '1000' high priority at nice level -11.
Jun 6 00:00:03 openplotter rtkit-daemon[1075]: Supervising 1 threads of 1 processes of 1 users.
Jun 6 00:00:03 openplotter kernel: [ 24.888585] usb 1-1.3: 3:1: cannot get freq at ep 0x84
Jun 6 00:00:03 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1020 comm="pcmanfm --desktop --profile LXDE-pi ")
Jun 6 00:00:03 openplotter systemd[817]: Starting Virtual filesystem service - disk device monitor...
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Jun 6 00:00:04 openplotter systemd[817]: Started Virtual filesystem service - disk device monitor.
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1020 comm="pcmanfm --desktop --profile LXDE-pi ")
Jun 6 00:00:04 openplotter systemd[817]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Jun 6 00:00:04 openplotter systemd[817]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1020 comm="pcmanfm --desktop --profile LXDE-pi ")
Jun 6 00:00:04 openplotter systemd[817]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Jun 6 00:00:04 openplotter systemd[817]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Jun 6 00:00:04 openplotter kernel: [ 25.737225] usb 1-1.3: 3:1: cannot get freq at ep 0x84
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 1 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1020 comm="pcmanfm --desktop --profile LXDE-pi ")
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Successfully made thread 1129 of process 1055 (n/a) owned by '1000' RT at priority 5.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 2 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter systemd[817]: Starting Virtual filesystem service - digital camera monitor...
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 2 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter systemd[1]: systemd-rfkill.service: Succeeded.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Successfully made thread 1133 of process 1055 (n/a) owned by '1000' RT at priority 5.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 3 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Jun 6 00:00:04 openplotter systemd[817]: Started Virtual filesystem service - digital camera monitor.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 3 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Successfully made thread 1147 of process 1055 (n/a) owned by '1000' RT at priority 5.
Jun 6 00:00:04 openplotter rtkit-daemon[1075]: Supervising 4 threads of 1 processes of 1 users.
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1020 comm="pcmanfm --desktop --profile LXDE-pi ")
Jun 6 00:00:04 openplotter systemd[817]: Starting Virtual filesystem service - Apple File Conduit monitor...
Jun 6 00:00:04 openplotter systemd[817]: Started Sound Service.
Jun 6 00:00:04 openplotter bluetoothd[790]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource
Jun 6 00:00:04 openplotter bluetoothd[790]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink
Jun 6 00:00:04 openplotter pulseaudio[1055]: E: [pulseaudio] backend-ofono.c: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files
Jun 6 00:00:04 openplotter gvfs-afc-volume-monitor[1149]: Volume monitor alive
Jun 6 00:00:04 openplotter dbus-daemon[929]: [session uid=1000 pid=929] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Jun 6 00:00:04 openplotter systemd[817]: Started Virtual filesystem service - Apple File Conduit monitor.
Jun 6 00:00:04 openplotter kernel: [ 26.096558] Bluetooth: RFCOMM TTY layer initialized
Jun 6 00:00:04 openplotter kernel: [ 26.096577] Bluetooth: RFCOMM socket layer initialized
Jun 6 00:00:04 openplotter kernel: [ 26.096600] Bluetooth: RFCOMM ver 1.11
Jun 6 00:00:05 openplotter systemd[1]: openplotter-gpio-read.service: Succeeded.
Jun 6 00:00:05 openplotter dhcpcd[517]: wlan0: leased 192.168.2.2 for 86400 seconds
Jun 6 00:00:05 openplotter avahi-daemon[520]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.2.
Jun 6 00:00:05 openplotter avahi-daemon[520]: New relevant interface wlan0.IPv4 for mDNS.
Jun 6 00:00:05 openplotter dhcpcd[517]: wlan0: adding route to 192.168.2.0/24
Jun 6 00:00:05 openplotter avahi-daemon[520]: Registering new address record for 192.168.2.2 on wlan0.IPv4.
Jun 6 00:00:05 openplotter dhcpcd[517]: wlan0: adding default route via 192.168.2.254
Jun 6 00:00:05 openplotter dhcpcd[517]: br0: adding route to 10.10.10.0/24
Jun 6 00:00:05 openplotter dnsmasq[675]: reading /run/dnsmasq/resolv.conf
Jun 6 00:00:05 openplotter dnsmasq[675]: using nameserver 192.168.2.254#53
Jun 6 00:00:05 openplotter dnsmasq[675]: using nameserver 8.8.8.8#53
Jun 6 00:00:05 openplotter ModemManager[474]: <info> [device /sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3] creating modem with plugin 'u-blox' and '1' ports
Jun 6 00:00:05 openplotter ModemManager[474]: <warn> Could not grab port (tty/ttyACM0): 'Cannot add port 'tty/ttyACM0', unhandled serial type'
Jun 6 00:00:05 openplotter ModemManager[474]: <warn> Couldn't create modem for device '/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3': Failed to find primary AT port
Jun 6 00:00:07 openplotter pulseaudio[1055]: E: [alsa-sink-bcm2835 Headphones] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write.
Jun 6 00:00:07 openplotter pulseaudio[1055]: E: [alsa-sink-bcm2835 Headphones] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_bcm2835'. Please report this issue to the ALSA developers.
Jun 6 00:00:07 openplotter pulseaudio[1055]: E: [alsa-sink-bcm2835 Headphones] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Jun 6 00:00:09 openplotter systemd-networkd[156]: br0: Configured
Jun 6 00:00:09 openplotter systemd-timesyncd[339]: Network configuration changed, trying to establish connection.
Jun 6 11:10:09 openplotter systemd-timesyncd[339]: Synchronized to time server for the first time [2a07:5740:600::a20e:57a4]:123 (2.debian.pool.ntp.org).
Jun 6 11:10:09 openplotter systemd[1]: Starting Daily apt upgrade and clean activities...
RE: Openplotter restarting overnight and failing - Sailoog - 2022-06-06
I can not see anything abnormal. I would try disabling some features gradually until finding the guilty.
Have you tried openplotter 3? some apps you need are not ready yet but we are progressing.
RE: Openplotter restarting overnight and failing - pscheepe - 2022-06-07
As I am still experimenting and want to add a Sensehat using NodeRed, I will see where we go and when version 3 is available with SDR and I2C I will try this as well.
Thanks for your help, you may close this tread now.
Greetings,
Peter
RE: Openplotter restarting overnight and failing - Sailoog - 2022-06-07
Let's keep it open in case someone else has the same problem and we can find a pattern.
RE: Openplotter restarting overnight and failing - pscheepe - 2022-07-19
It seems the issu has been resolved, although I do not remember what I did to get this result.