if I do: sudo systemctl restart sip
Sip starts OK what is happening at boot?
complete log boot and after sip restart :
Feb 25 20:43:26 sip-system systemd[1]: Starting Bluetooth service...
Feb 25 20:43:27 sip-system sip[412]: Traceback (most recent call last):
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/sip.py", line 21, in <module>
Feb 25 20:43:27 sip-system sip[412]: import gv
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/gv.py", line 106, in <module>
Feb 25 20:43:27 sip-system sip[412]: from helpers import load_programs, station_names, days_since_epoch
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/helpers.py", line 21, in <module>
Feb 25 20:43:27 sip-system sip[412]: from gpio_pins import set_output
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/gpio_pins.py", line 36, in <module>
Feb 25 20:43:27 sip-system sip[412]: if gv.platform == "pi":
Feb 25 20:43:27 sip-system sip[412]: AttributeError: partially initialized module 'gv' has no attribute 'platform' (most likely due to a circular import)
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Failed with result 'exit-code'.
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Consumed 1.351s CPU time.
Feb 25 20:43:27 sip-system bluetoothd[459]: Bluetooth daemon 5.55
Feb 25 20:43:27 sip-system systemd[1]: Started Bluetooth service.
Feb 25 20:43:27 sip-system systemd[1]: Reached target Bluetooth.
Feb 25 20:43:27 sip-system bluetoothd[459]: Starting SDP server
Feb 25 20:43:27 sip-system kernel: [ 42.637946] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Feb 25 20:43:27 sip-system kernel: [ 42.637987] Bluetooth: BNEP filters: protocol multicast
Feb 25 20:43:27 sip-system kernel: [ 42.638017] Bluetooth: BNEP socket layer initialized
Feb 25 20:43:27 sip-system bluetoothd[459]: Bluetooth management interface 1.22 initialized
Feb 25 20:43:27 sip-system kernel: [ 42.670859] Bluetooth: MGMT ver 1.22
Feb 25 20:43:27 sip-system dbus-daemon[308]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.7' (uid=0 pid=459 comm="/usr/libexec/bluetooth/bluetoothd ")
Feb 25 20:43:27 sip-system kernel: [ 42.754276] NET: Registered PF_ALG protocol family
Feb 25 20:43:27 sip-system systemd[1]: Starting Hostname Service...
Feb 25 20:43:27 sip-system ModemManager[408]: <info> [base-manager] couldn't check support for device '/sys/devices/platform/soc/20300000.mmcnr/mmc_host/mmc1/mmc1:0001/mmc1:0001:1': not supported by any plugin
Feb 25 20:43:28 sip-system bluetoothd[459]: profiles/sap/server.c
ap_server_register() Sap driver initialization failed.
Feb 25 20:43:28 sip-system bluetoothd[459]: sap-server: Operation not permitted (1)
Feb 25 20:43:28 sip-system bluetoothd[459]: Failed to set privacy: Rejected (0x0b)
Feb 25 20:43:28 sip-system dbus-daemon[308]: [system] Successfully activated service 'org.freedesktop.hostname1'
Feb 25 20:43:28 sip-system systemd[1]: Started Hostname Service.
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: leased 192.168.1.7 for 7200 seconds
Feb 25 20:43:31 sip-system avahi-daemon[306]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.7.
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: adding route to 192.168.1.0/24
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: adding default route via 192.168.1.1
Feb 25 20:43:31 sip-system avahi-daemon[306]: New relevant interface wlan0.IPv4 for mDNS.
Feb 25 20:43:31 sip-system avahi-daemon[306]: Registering new address record for 192.168.1.7 on wlan0.IPv4.
Feb 25 20:43:31 sip-system systemd[1]: systemd-rfkill.service: Succeeded.
Feb 25 20:43:31 sip-system avahi-daemon[306]: Got SIGHUP, reloading.
Feb 25 20:43:31 sip-system avahi-daemon[306]: No service file found in /etc/avahi/services.
Feb 25 20:43:31 sip-system dhcpcd[410]: forked to background, child pid 538
Feb 25 20:43:31 sip-system systemd[1]: Started DHCP Client Daemon.
Feb 25 20:43:31 sip-system systemd[1]: Reached target Multi-User System.
Feb 25 20:43:32 sip-system bthelper[534]: Changing power off succeeded
Feb 25 20:43:32 sip-system systemd[1]: Starting Update UTMP about System Runlevel Changes...
Feb 25 20:43:32 sip-system systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Feb 25 20:43:32 sip-system systemd[1]: Finished Update UTMP about System Runlevel Changes.
Feb 25 20:43:32 sip-system systemd[1]: Startup finished in 4.752s (kernel) + 42.544s (userspace) = 47.297s.
Feb 25 20:43:32 sip-system bthelper[457]: Changing power on succeeded
Feb 25 20:43:34 sip-system systemd[1]: systemd-fsckd.service: Succeeded.
Feb 25 20:43:39 sip-system dhcpcd[538]: wlan0: no IPv6 Routers available
Feb 25 20:44:04 sip-system systemd-timesyncd[298]: Initial synchronization to time server 193.136.164.4:123 (2.debian.pool.ntp.org).
Feb 25 20:44:06 sip-system systemd[1]: Created slice User Slice of UID 1000.
Feb 25 20:44:06 sip-system systemd[1]: Starting User Runtime Directory /run/user/1000...
Feb 25 20:44:06 sip-system systemd[1]: Finished User Runtime Directory /run/user/1000.
Feb 25 20:44:06 sip-system systemd[1]: Starting User Manager for UID 1000...
Feb 25 20:44:07 sip-system systemd[543]: Queued start job for default target Main User Target.
Feb 25 20:44:07 sip-system systemd[543]: Created slice User Application Slice.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Paths.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Timers.
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG network certificate management daemon.
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Sockets.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Basic System.
Feb 25 20:44:07 sip-system systemd[1]: Started User Manager for UID 1000.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Main User Target.
Feb 25 20:44:07 sip-system systemd[543]: Startup finished in 1.116s.
Feb 25 20:44:07 sip-system systemd[1]: Started Session 1 of user pi.
Feb 25 20:44:14 sip-system systemd[1]: systemd-hostnamed.service: Succeeded.
Feb 25 20:44:48 sip-system systemd[1]: Started SIP for Python3.
Feb 25 20:44:53 sip-system sip[591]: MQTT publish UP
Feb 25 20:44:54 sip-system sip[591]: plugins loaded:
Feb 25 20:44:54 sip-system sip[591]: mobile_app
Feb 25 20:44:54 sip-system sip[591]: mqtt
Feb 25 20:44:54 sip-system sip[591]: node_red
Feb 25 20:44:54 sip-system sip[591]: plugin_manager
Feb 25 20:44:54 sip-system sip[591]: relay_board
Feb 25 20:44:54 sip-system sip[591]: system_update
Feb 25 20:44:54 sip-system sip[591]: weather_level_adj
Feb 25 20:44:54 sip-system sip[591]: Starting timing loop
Feb 25 20:44:56 sip-system sip[591]: http://:::80/
Feb 25 20:44:56 sip-system sip[591]: b'Checking weather status...'
Feb 25 20:44:57 sip-system sip[591]: b'Current temperature:\n15.9deg.C'
Feb 25 20:44:57 sip-system sip[591]: b'________________________________'
Feb 25 20:44:57 sip-system sip[591]: b'Daily irrigation:\n10.0mm'
Feb 25 20:44:57 sip-system sip[591]: b'Total rainfall:\n0.0mm'
Feb 25 20:44:57 sip-system sip[591]: b'Water needed (4days):\n18.5mm'
Feb 25 20:44:57 sip-system sip[591]: b'________________________________'
Feb 25 20:44:57 sip-system sip[591]: b'Irrigation needed:\n18.5mm'
Feb 25 20:44:57 sip-system sip[591]: b'Weather Adjustment:\n59.7%'
pi@sip-system:/var/log $
I have alter the service like this until i find a better option:
#Service for SIP running on a SystemD service
#
[Unit]
Description=SIP for Python3
After=syslog.target network.target
[Service]
ExecStart=/usr/bin/python3 -u /opt/SIP/sip.py
#Restart=on-abort
Restart=always
RestartSec=5
WorkingDirectory=/opt/SIP
SyslogIdentifier=sip
[Install]
WantedBy=multi-user.target
Sip starts OK what is happening at boot?
complete log boot and after sip restart :
Feb 25 20:43:26 sip-system systemd[1]: Starting Bluetooth service...
Feb 25 20:43:27 sip-system sip[412]: Traceback (most recent call last):
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/sip.py", line 21, in <module>
Feb 25 20:43:27 sip-system sip[412]: import gv
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/gv.py", line 106, in <module>
Feb 25 20:43:27 sip-system sip[412]: from helpers import load_programs, station_names, days_since_epoch
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/helpers.py", line 21, in <module>
Feb 25 20:43:27 sip-system sip[412]: from gpio_pins import set_output
Feb 25 20:43:27 sip-system sip[412]: File "/opt/SIP/gpio_pins.py", line 36, in <module>
Feb 25 20:43:27 sip-system sip[412]: if gv.platform == "pi":
Feb 25 20:43:27 sip-system sip[412]: AttributeError: partially initialized module 'gv' has no attribute 'platform' (most likely due to a circular import)
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Failed with result 'exit-code'.
Feb 25 20:43:27 sip-system systemd[1]: sip.service: Consumed 1.351s CPU time.
Feb 25 20:43:27 sip-system bluetoothd[459]: Bluetooth daemon 5.55
Feb 25 20:43:27 sip-system systemd[1]: Started Bluetooth service.
Feb 25 20:43:27 sip-system systemd[1]: Reached target Bluetooth.
Feb 25 20:43:27 sip-system bluetoothd[459]: Starting SDP server
Feb 25 20:43:27 sip-system kernel: [ 42.637946] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Feb 25 20:43:27 sip-system kernel: [ 42.637987] Bluetooth: BNEP filters: protocol multicast
Feb 25 20:43:27 sip-system kernel: [ 42.638017] Bluetooth: BNEP socket layer initialized
Feb 25 20:43:27 sip-system bluetoothd[459]: Bluetooth management interface 1.22 initialized
Feb 25 20:43:27 sip-system kernel: [ 42.670859] Bluetooth: MGMT ver 1.22
Feb 25 20:43:27 sip-system dbus-daemon[308]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.7' (uid=0 pid=459 comm="/usr/libexec/bluetooth/bluetoothd ")
Feb 25 20:43:27 sip-system kernel: [ 42.754276] NET: Registered PF_ALG protocol family
Feb 25 20:43:27 sip-system systemd[1]: Starting Hostname Service...
Feb 25 20:43:27 sip-system ModemManager[408]: <info> [base-manager] couldn't check support for device '/sys/devices/platform/soc/20300000.mmcnr/mmc_host/mmc1/mmc1:0001/mmc1:0001:1': not supported by any plugin
Feb 25 20:43:28 sip-system bluetoothd[459]: profiles/sap/server.c
ap_server_register() Sap driver initialization failed.Feb 25 20:43:28 sip-system bluetoothd[459]: sap-server: Operation not permitted (1)
Feb 25 20:43:28 sip-system bluetoothd[459]: Failed to set privacy: Rejected (0x0b)
Feb 25 20:43:28 sip-system dbus-daemon[308]: [system] Successfully activated service 'org.freedesktop.hostname1'
Feb 25 20:43:28 sip-system systemd[1]: Started Hostname Service.
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: leased 192.168.1.7 for 7200 seconds
Feb 25 20:43:31 sip-system avahi-daemon[306]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.7.
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: adding route to 192.168.1.0/24
Feb 25 20:43:31 sip-system dhcpcd[410]: wlan0: adding default route via 192.168.1.1
Feb 25 20:43:31 sip-system avahi-daemon[306]: New relevant interface wlan0.IPv4 for mDNS.
Feb 25 20:43:31 sip-system avahi-daemon[306]: Registering new address record for 192.168.1.7 on wlan0.IPv4.
Feb 25 20:43:31 sip-system systemd[1]: systemd-rfkill.service: Succeeded.
Feb 25 20:43:31 sip-system avahi-daemon[306]: Got SIGHUP, reloading.
Feb 25 20:43:31 sip-system avahi-daemon[306]: No service file found in /etc/avahi/services.
Feb 25 20:43:31 sip-system dhcpcd[410]: forked to background, child pid 538
Feb 25 20:43:31 sip-system systemd[1]: Started DHCP Client Daemon.
Feb 25 20:43:31 sip-system systemd[1]: Reached target Multi-User System.
Feb 25 20:43:32 sip-system bthelper[534]: Changing power off succeeded
Feb 25 20:43:32 sip-system systemd[1]: Starting Update UTMP about System Runlevel Changes...
Feb 25 20:43:32 sip-system systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Feb 25 20:43:32 sip-system systemd[1]: Finished Update UTMP about System Runlevel Changes.
Feb 25 20:43:32 sip-system systemd[1]: Startup finished in 4.752s (kernel) + 42.544s (userspace) = 47.297s.
Feb 25 20:43:32 sip-system bthelper[457]: Changing power on succeeded
Feb 25 20:43:34 sip-system systemd[1]: systemd-fsckd.service: Succeeded.
Feb 25 20:43:39 sip-system dhcpcd[538]: wlan0: no IPv6 Routers available
Feb 25 20:44:04 sip-system systemd-timesyncd[298]: Initial synchronization to time server 193.136.164.4:123 (2.debian.pool.ntp.org).
Feb 25 20:44:06 sip-system systemd[1]: Created slice User Slice of UID 1000.
Feb 25 20:44:06 sip-system systemd[1]: Starting User Runtime Directory /run/user/1000...
Feb 25 20:44:06 sip-system systemd[1]: Finished User Runtime Directory /run/user/1000.
Feb 25 20:44:06 sip-system systemd[1]: Starting User Manager for UID 1000...
Feb 25 20:44:07 sip-system systemd[543]: Queued start job for default target Main User Target.
Feb 25 20:44:07 sip-system systemd[543]: Created slice User Application Slice.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Paths.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Timers.
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG network certificate management daemon.
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb 25 20:44:07 sip-system systemd[543]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Sockets.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Basic System.
Feb 25 20:44:07 sip-system systemd[1]: Started User Manager for UID 1000.
Feb 25 20:44:07 sip-system systemd[543]: Reached target Main User Target.
Feb 25 20:44:07 sip-system systemd[543]: Startup finished in 1.116s.
Feb 25 20:44:07 sip-system systemd[1]: Started Session 1 of user pi.
Feb 25 20:44:14 sip-system systemd[1]: systemd-hostnamed.service: Succeeded.
Feb 25 20:44:48 sip-system systemd[1]: Started SIP for Python3.
Feb 25 20:44:53 sip-system sip[591]: MQTT publish UP
Feb 25 20:44:54 sip-system sip[591]: plugins loaded:
Feb 25 20:44:54 sip-system sip[591]: mobile_app
Feb 25 20:44:54 sip-system sip[591]: mqtt
Feb 25 20:44:54 sip-system sip[591]: node_red
Feb 25 20:44:54 sip-system sip[591]: plugin_manager
Feb 25 20:44:54 sip-system sip[591]: relay_board
Feb 25 20:44:54 sip-system sip[591]: system_update
Feb 25 20:44:54 sip-system sip[591]: weather_level_adj
Feb 25 20:44:54 sip-system sip[591]: Starting timing loop
Feb 25 20:44:56 sip-system sip[591]: http://:::80/
Feb 25 20:44:56 sip-system sip[591]: b'Checking weather status...'
Feb 25 20:44:57 sip-system sip[591]: b'Current temperature:\n15.9deg.C'
Feb 25 20:44:57 sip-system sip[591]: b'________________________________'
Feb 25 20:44:57 sip-system sip[591]: b'Daily irrigation:\n10.0mm'
Feb 25 20:44:57 sip-system sip[591]: b'Total rainfall:\n0.0mm'
Feb 25 20:44:57 sip-system sip[591]: b'Water needed (4days):\n18.5mm'
Feb 25 20:44:57 sip-system sip[591]: b'________________________________'
Feb 25 20:44:57 sip-system sip[591]: b'Irrigation needed:\n18.5mm'
Feb 25 20:44:57 sip-system sip[591]: b'Weather Adjustment:\n59.7%'
pi@sip-system:/var/log $
I have alter the service like this until i find a better option:
#Service for SIP running on a SystemD service
#
[Unit]
Description=SIP for Python3
After=syslog.target network.target
[Service]
ExecStart=/usr/bin/python3 -u /opt/SIP/sip.py
#Restart=on-abort
Restart=always
RestartSec=5
WorkingDirectory=/opt/SIP
SyslogIdentifier=sip
[Install]
WantedBy=multi-user.target