Problem whit Paho mqtt

[DrLabel]

after Google I get to this page :

https://stackoverflow.com/questions/7798...sion-error

I'm getting this error:
pi@sip-system:/opt/SIP $ python3 sip.py
fatal: detected dubious ownership in repository at '/opt/SIP'
To add an exception for this directory, call:

       git config --global --add safe.directory /opt/SIP
Could not use git to determine version! Command '['git', 'rev-list', '--count', 'HEAD']' returned non-zero exit status 128.
fatal: detected dubious ownership in repository at '/opt/SIP'
To add an exception for this directory, call:

       git config --global --add safe.directory /opt/SIP
Could not use git to determine date of last commit! Command '['git', 'log', '-1', '--format=%cd', '--date=short']' returned non-zero exit status 128.
MQTT publish UP
MQTT plugin couldn't initalize client: Unsupported callback API version: version 2.0 added a callback_api_version, see migrations.md for details
plugins loaded:
 mobile_app
 mqtt
 node_red
 plugin_manager
 relay_board
 system_update
 weather_level_adj
Starting timing loop

http://:::80/
Traceback (most recent call last):
 File "/opt/SIP/sip.py", line 334, in <module>
   app.run()
 File "/opt/SIP/sip.py", line 253, in run
   return web.httpserver.runsimple(func, (ip, port))
 File "/opt/SIP/web/httpserver.py", line 178, in runsimple
   server.start()
 File "/opt/SIP/cheroot/server.py", line 1849, in start
   self.prepare()
 File "/opt/SIP/cheroot/server.py", line 1804, in prepare
   raise socket.error(msg)
OSError: No socket could be created -- (('::', 80, 0, 0): [Errno 13] Permission denied)

---

The error form paho I fix like this:
python3 -m pip install "paho-mqtt<2.0.0"


But sip don't start

---

the logs at boot
Feb 25 19:43:09 sip-system sip[410]: Traceback (most recent call last):
Feb 25 19:43:09 sip-system sip[410]: File "/opt/SIP/sip.py", line 21, in <module>
Feb 25 19:43:09 sip-system sip[410]: import gv
Feb 25 19:43:09 sip-system sip[410]: File "/opt/SIP/gv.py", line 106, in <module>
Feb 25 19:43:09 sip-system sip[410]: from helpers import load_programs, station_names, days_since_epoch
Feb 25 19:43:09 sip-system sip[410]: File "/opt/SIP/helpers.py", line 21, in <module>
Feb 25 19:43:09 sip-system sip[410]: from gpio_pins import set_output
Feb 25 19:43:09 sip-system sip[410]: File "/opt/SIP/gpio_pins.py", line 36, in <module>
Feb 25 19:43:09 sip-system sip[410]: if gv.platform == "pi":
Feb 25 19:43:09 sip-system sip[410]: AttributeError: partially initialized module 'gv' has no attribute 'platform' (most likely due to a circular import)
Feb 25 19:43:09 sip-system systemd[1]: sip.service: Main process exited, code=exited, status=1/FAILURE
Feb 25 19:43:09 sip-system systemd[1]: sip.service: Failed with result 'exit-code'.
Feb 25 19:43:09 sip-system systemd[1]: sip.service: Consumed 1.363s CPU time.
---------------------------------------------

[DrLabel]

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.cap_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

[astrogerard]

Code:

OSError: No socket could be created -- (('::', 80, 0, 0): [Errno 13] Permission denied)

means you are starting SIP without root privileges. A regular user is not allowed to use port 80.
Systemd takes care of this so that's why it runs ok then.

--Gerard

[DrLabel]

yes but during boot :

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.