weewx not Starting without LAN

119 views
Skip to first unread message

walterli

unread,
Nov 6, 2019, 3:13:18 PM11/6/19
to weewx-user
Hi all,

Shortdescription:
When I unplug the ethernetcable form raspberry pi, weewx stops working despite there is WLAN connection.

Long description:
I just bought a Raspberry Pi 3+. I installed raspbian buster from image to a memory stick. I'm able to connect raspberry pi by LAN and also WLAN (finally after I added IPQoS 0x00 at the end of /etc/ssh/sshd_config)

I then installed weewx manually. The data is stored to a mySQL-Database which is not on the Pi, but on my NAS. As long as the ethernet cable to the Pi is connected this works fine. As soon as I unplug the cable, weewx stops working. Even tough I'm still able to SSH via WLAN to PI. Find below an extract from the log taken via WLAN when disconnecting LAN cable:

My Interactions were:
20:51:07 I disconnected the ethernet cable from Pi. Ping from Windows is still possible --> weewx not working anymore
20:55:12 I sent the command sudo /etc/init.d/weewx restart via SSH and WLAN
21:02:54 Recconnected ethernet cable to Pi
21:08:02 I sent the command sudo /etc/init.d/weewx restart via SSH and WLAN --> weewx working fine again

Could it be, that KlimaLogg USB Stick, USB Memorystick with operating system and WIFI Chip are disturbing each other somehow (20:58:30)?

Nov  6 20:47:59 raspberrypi weewx[1591]: engine: Starting main packet loop.
Nov  6 20:48:59 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:48:00 CET (1573069680) to database 'weewx_kl'
Nov  6 20:48:59 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:48:00 CET (1573069680) to daily summary in 'weewx_kl'
Nov  6 20:49:02 raspberrypi weewx[1591]: cheetahgenerator: Generated 1 files for report kl in 1.13 seconds
Nov  6 20:50:01 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:49:00 CET (1573069740) to database 'weewx_kl'
Nov  6 20:50:01 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:49:00 CET (1573069740) to daily summary in 'weewx_kl'
Nov  6 20:50:01 raspberrypi weewx[1591]: engine: Launch of report thread aborted: existing report thread still running
Nov  6 20:50:31 raspberrypi weewx[1591]: imagegenerator: Generated 61 images for kl in 89.43 seconds
Nov  6 20:51:01 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:51:00 CET (1573069860) to database 'weewx_kl'
Nov  6 20:51:01 raspberrypi weewx[1591]: manager: Added record 2019-11-06 20:51:00 CET (1573069860) to daily summary in 'weewx_kl'
Nov  6 20:51:02 raspberrypi weewx[1591]: cheetahgenerator: Generated 1 files for report kl in 0.75 seconds
Nov  6 20:51:07 raspberrypi dhcpcd[330]: eth0: carrier lost
Nov  6 20:51:07 raspberrypi kernel: [ 2309.198616] smsc95xx 1-1.1:1.0 eth0: link down
Nov  6 20:51:07 raspberrypi dhcpcd[330]: eth0: deleting address fe80::cd3e:3538:8150:a0de
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Withdrawing address record for fe80::cd3e:3538:8150:a0de on eth0.
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::cd3e:3538:8150:a0de.
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Interface eth0.IPv6 no longer relevant for mDNS.
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Withdrawing address record for 192.168.0.45 on eth0.
Nov  6 20:51:07 raspberrypi dhcpcd[330]: eth0: deleting route to 192.168.0.0/24
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.45.
Nov  6 20:51:07 raspberrypi dhcpcd[330]: eth0: deleting default route via 192.168.0.1
Nov  6 20:51:07 raspberrypi avahi-daemon[259]: Interface eth0.IPv4 no longer relevant for mDNS.
Nov  6 20:51:08 raspberrypi ntpd[386]: Deleting interface #9 eth0, fe80::cd3e:3538:8150:a0de%2#123, interface stats: received=0, sent=0, dropped=0, active_time=253 secs
Nov  6 20:51:08 raspberrypi ntpd[386]: Deleting interface #10 eth0, 192.168.0.45#123, interface stats: received=0, sent=0, dropped=0, active_time=250 secs
Nov  6 20:55:12 raspberrypi systemd[1]: Stopping LSB: weewx weather system...
Nov  6 20:57:14 raspberrypi weewx[1695]: Stopping weewx weather system: weewx........................ failed!
Nov  6 20:57:14 raspberrypi systemd[1]: weewx.service: Control process exited, code=exited, status=1/FAILURE
Nov  6 20:57:14 raspberrypi systemd[1]: weewx.service: Failed with result 'exit-code'.
Nov  6 20:57:14 raspberrypi systemd[1]: Stopped LSB: weewx weather system.
Nov  6 20:57:14 raspberrypi systemd[1]: weewx.service: Found left-over process 1591 (weewxd) in control group while starting unit. Ignoring.
Nov  6 20:57:14 raspberrypi systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Nov  6 20:57:14 raspberrypi systemd[1]: Starting LSB: weewx weather system...
Nov  6 20:57:14 raspberrypi weewx[1900]: Starting weewx weather system: weewx already running....
Nov  6 20:57:14 raspberrypi systemd[1]: Started LSB: weewx weather system.
Nov  6 20:58:30 raspberrypi weewx[1591]: KlimaLogg: RFComm: generateResponse: intercepted message from device 2816 with length: 02
Nov  6 20:58:30 raspberrypi weewx[1591]: KlimaLogg: RFComm: unexpected device ID (id=2816); use parameter 'serial' if more than one USB transceiver present
Nov  6 21:02:54 raspberrypi dhcpcd[330]: eth0: carrier acquired
Nov  6 21:02:54 raspberrypi kernel: [ 3016.904399] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
Nov  6 21:02:54 raspberrypi dhcpcd[330]: eth0: IAID eb:7a:9a:cf
Nov  6 21:02:54 raspberrypi dhcpcd[330]: eth0: adding address fe80::cd3e:3538:8150:a0de
Nov  6 21:02:54 raspberrypi avahi-daemon[259]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::cd3e:3538:8150:a0de.
Nov  6 21:02:54 raspberrypi avahi-daemon[259]: New relevant interface eth0.IPv6 for mDNS.
Nov  6 21:02:54 raspberrypi avahi-daemon[259]: Registering new address record for fe80::cd3e:3538:8150:a0de on eth0.*.
Nov  6 21:02:55 raspberrypi dhcpcd[330]: eth0: hardware address 28:be:9b:ba:39:a4 claims 192.168.0.1
Nov  6 21:02:55 raspberrypi dhcpcd[330]: eth0: selected profile 192.168.0.1
Nov  6 21:02:55 raspberrypi dhcpcd[330]: eth0: IAID eb:7a:9a:cf
Nov  6 21:02:55 raspberrypi dhcpcd[330]: eth0: probing address 192.168.0.45/24
Nov  6 21:02:55 raspberrypi dhcpcd[330]: eth0: soliciting an IPv6 router
Nov  6 21:02:56 raspberrypi ntpd[386]: bind(23) AF_INET6 fe80::cd3e:3538:8150:a0de%2#123 flags 0x11 failed: Cannot assign requested address
Nov  6 21:02:56 raspberrypi ntpd[386]: unable to create socket on eth0 (11) for fe80::cd3e:3538:8150:a0de%2#123
Nov  6 21:02:56 raspberrypi ntpd[386]: failed to init interface for address fe80::cd3e:3538:8150:a0de%2
Nov  6 21:02:58 raspberrypi ntpd[386]: Listen normally on 12 eth0 [fe80::cd3e:3538:8150:a0de%2]:123
Nov  6 21:02:58 raspberrypi ntpd[386]: new interface(s) found: waking up resolver
Nov  6 21:03:00 raspberrypi dhcpcd[330]: eth0: using static address 192.168.0.45/24
Nov  6 21:03:00 raspberrypi dhcpcd[330]: eth0: adding route to 192.168.0.0/24
Nov  6 21:03:00 raspberrypi avahi-daemon[259]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.45.
Nov  6 21:03:00 raspberrypi dhcpcd[330]: eth0: adding default route via 192.168.0.1
Nov  6 21:03:00 raspberrypi avahi-daemon[259]: New relevant interface eth0.IPv4 for mDNS.
Nov  6 21:03:00 raspberrypi avahi-daemon[259]: Registering new address record for 192.168.0.45 on eth0.IPv4.
Nov  6 21:03:02 raspberrypi ntpd[386]: Listen normally on 13 eth0 192.168.0.45:123
Nov  6 21:03:02 raspberrypi ntpd[386]: new interface(s) found: waking up resolver
Nov  6 21:03:08 raspberrypi dhcpcd[330]: eth0: no IPv6 Routers available
Nov  6 21:03:19 raspberrypi weewx[1591]: imagegenerator: Generated 25 images for kl in 736.84 seconds
Nov  6 21:04:59 raspberrypi weewx[1591]: engine: Main loop exiting. Shutting engine down.
Nov  6 21:04:59 raspberrypi weewx[1591]: engine: Shutting down StdReport thread
Nov  6 21:04:59 raspberrypi weewx[1591]: engine: Caught unrecoverable exception in engine:
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****  (2014, "Commands out of sync; you can't run this command now")
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****  Traceback (most recent call last):
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/engine.py", line 894, in main
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      engine.run()
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/engine.py", line 202, in run
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      self.dispatchEvent(weewx.Event(weewx.POST_LOOP))
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/engine.py", line 224, in dispatchEvent
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      callback(event)
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/engine.py", line 580, in post_loop
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      self._catchup(self.engine.console.genArchiveRecords)
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/engine.py", line 627, in _catchup
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      lastgood_ts = dbmanager.lastGoodStamp()
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/manager.py", line 207, in lastGoodStamp
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      _row = self.getSql("SELECT MAX(dateTime) FROM %s" % self.table_name)
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weewx/manager.py", line 399, in getSql
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      _cursor.close()
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/home/weewx/bin/weedb/mysql.py", line 261, in close
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      self.cursor.close()
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 84, in close
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      while self.nextset():
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****    File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 172, in nextset
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****      nr = db.next_result()
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****  ProgrammingError: (2014, "Commands out of sync; you can't run this command now")
Nov  6 21:04:59 raspberrypi weewx[1591]:     ****  Exiting.
Nov  6 21:08:02 raspberrypi systemd[1]: Stopping LSB: weewx weather system...
Nov  6 21:08:02 raspberrypi weewx[2007]: Stopping weewx weather system: weewx not running....
Nov  6 21:08:02 raspberrypi systemd[1]: weewx.service: Succeeded.
Nov  6 21:08:02 raspberrypi systemd[1]: Stopped LSB: weewx weather system.
Nov  6 21:08:02 raspberrypi systemd[1]: Starting LSB: weewx weather system...
Nov  6 21:08:02 raspberrypi weewx[2029]: engine: Initializing weewx version 3.9.2
Nov  6 21:08:02 raspberrypi weewx[2029]: engine: Using Python 2.7.16 (default, Apr  6 2019, 01:42:57) #012[GCC 8.2.0]
Nov  6 21:08:02 raspberrypi weewx[2029]: engine: Platform Linux-4.19.75-v7+-armv7l-with-debian-10.1
Nov  6 21:08:02 raspberrypi weewx[2029]: engine: Locale is 'de_CH.UTF-8'
Nov  6 21:08:02 raspberrypi weewx[2029]: engine: pid file is /var/run/weewx.pid
Nov  6 21:08:02 raspberrypi weewx[2033]: engine: Using configuration file /home/weewx/weewx.conf
Nov  6 21:08:02 raspberrypi weewx[2033]: engine: Loading station type KlimaLogg (user.kl)
Nov  6 21:08:02 raspberrypi weewx[2018]: Starting weewx weather system: weewx.
Nov  6 21:08:02 raspberrypi systemd[1]: Started LSB: weewx weather system.
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: driver version is 1.3.7
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: channel is 1
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: frequency is EU
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: sensor map is: {'temp3': 'Temp3', 'temp2': 'Temp2', 'temp1': 'Temp1', 'temp0': 'Temp0', 'temp7': 'Temp7', 'temp6': 'Temp6', 'temp5': 'Temp5', 'temp4': 'Temp4', 'temp8': 'Temp8', 'batteryStatus8': 'BatteryStatus8', 'batteryStatus1': 'BatteryStatus1', 'batteryStatus0': 'BatteryStatus0', 'batteryStatus3': 'BatteryStatus3', 'batteryStatus2': 'BatteryStatus2', 'batteryStatus5': 'BatteryStatus5', 'batteryStatus4': 'BatteryStatus4', 'batteryStatus7': 'BatteryStatus7', 'batteryStatus6': 'BatteryStatus6', 'humidity8': 'Humidity8', 'humidity4': 'Humidity4', 'humidity5': 'Humidity5', 'humidity6': 'Humidity6', 'humidity7': 'Humidity7', 'humidity0': 'Humidity0', 'humidity1': 'Humidity1', 'humidity2': 'Humidity2', 'humidity3': 'Humidity3', 'rxCheckPercent': 'SignalQuality'}
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: catchup limited to 51200 records
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: timing is 300 ms (0.300 s)
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: comm_interval is 8
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: logger_channel is 1
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: found transceiver at bus= device=
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: manufacturer: LA CROSSE TECHNOLOGY
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: product: Weather Direct Light Wireless Device
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: interface: 0
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: base frequency: 868300000
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: frequency correction: 94320 (0x17070)
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: adjusted frequency: 910572861 (0x36463d3d)
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: transceiver identifier: 91 (0x005b)
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: transceiver serial: 01012703140091
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: StdConvert target unit is 0x11
Nov  6 21:08:03 raspberrypi weewx[2033]: wxcalculate: The following values will be calculated: barometer=prefer_hardware, windchill=prefer_hardware, dewpoint=prefer_hardware, appTemp=prefer_hardware, rainRate=prefer_hardware, windrun=prefer_hardware, heatindex=prefer_hardware, maxSolarRad=prefer_hardware, humidex=prefer_hardware, pressure=prefer_hardware, inDewpoint=prefer_hardware, ET=prefer_hardware, altimeter=prefer_hardware, cloudbase=prefer_hardware
Nov  6 21:08:03 raspberrypi weewx[2033]: wxcalculate: The following algorithms will be used for calculations: altimeter=aaNOAA, maxSolarRad=RS
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: Archive will use data binding kl_binding
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: Record generation will be attempted in 'hardware'
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: Using archive interval of 60 seconds (specified in weewx configuration)
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: Using binding 'kl_binding' to database 'weewx_kl'
Nov  6 21:08:03 raspberrypi weewx[2033]: manager: Starting backfill of daily summaries
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: StationRegistry: Registration not requested.
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: Wunderground: Posting not enabled.
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: PWSweather: Posting not enabled.
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: CWOP: Posting not enabled.
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: WOW: Posting not enabled.
Nov  6 21:08:03 raspberrypi weewx[2033]: restx: AWEKAS: Posting not enabled.
Nov  6 21:08:03 raspberrypi weewx[2033]: engine: Starting up weewx version 3.9.2
Nov  6 21:08:03 raspberrypi weewx[2033]: KlimaLogg: MainThread: Scanning historical records
Nov  6 21:08:05 raspberrypi weewx[2033]: KlimaLogg: RFComm: starting rf communication
Nov  6 21:08:05 raspberrypi weewx[2033]: KlimaLogg: RFComm: console is paired to device with ID 005b and logger channel 1
Nov  6 21:08:06 raspberrypi weewx[2033]: KlimaLogg: RFComm: ToDateTime: bogus date for HistoryData1: error status in buffer
Nov  6 21:08:06 raspberrypi weewx[2033]: KlimaLogg: RFComm: handleHistoryData: request records since 2019-11-06 20:51:00 CET (1573069860)
Nov  6 21:08:06 raspberrypi weewx[2033]: KlimaLogg: RFComm: handleHistoryData: records cached=0, records skipped=0, next=1617
Nov  6 21:08:07 raspberrypi weewx[2033]: KlimaLogg: RFComm: handleHistoryData: records cached=1, records skipped=5, next=1623
Nov  6 21:08:07 raspberrypi weewx[2033]: KlimaLogg: RFComm: handleHistoryData: records cached=3, records skipped=9, next=1625
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Records scanned: 3
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Found 2 historical records
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Handle record 1: 2019-11-06 20:55:00 CET (1573070100)
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Handle record 2: 2019-11-06 21:00:00 CET (1573070400)
Nov  6 21:08:18 raspberrypi weewx[2033]: manager: Added record 2019-11-06 21:00:00 CET (1573070400) to database 'weewx_kl'
Nov  6 21:08:18 raspberrypi weewx[2033]: manager: Added record 2019-11-06 21:00:00 CET (1573070400) to daily summary in 'weewx_kl'
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Handle record 3: 2019-11-06 21:05:00 CET (1573070700)
Nov  6 21:08:18 raspberrypi weewx[2033]: manager: Added record 2019-11-06 21:05:00 CET (1573070700) to database 'weewx_kl'
Nov  6 21:08:18 raspberrypi weewx[2033]: manager: Added record 2019-11-06 21:05:00 CET (1573070700) to daily summary in 'weewx_kl'
Nov  6 21:08:18 raspberrypi weewx[2033]: KlimaLogg: MainThread: Saved 2 historical records; ts last saved record 2019-11-06 21:05:00 CET (1573070700)
Nov  6 21:08:18 raspberrypi weewx[2033]: engine: Starting main packet loop.


Does anybody sees, why weewx with only WLAN is not working in my case? I also tried to boot Pi without having connected the ethernet cable. No success: Pi is pingable and reachable by SSH but weewx won't start.

Kind regards

Raffael

vince

unread,
Nov 6, 2019, 3:47:19 PM11/6/19
to weewx-user

On Wednesday, November 6, 2019 at 12:13:18 PM UTC-8, walterli wrote:
Does anybody sees, why weewx with only WLAN is not working in my case? I also tried to boot Pi without having connected the ethernet cable. No success: Pi is pingable and reachable by SSH but weewx won't start.



You're going to have to set debug=1 and provide us with a syslog from when it starts to boot up to when weewx doesn't start.

walterli

unread,
Nov 6, 2019, 5:20:23 PM11/6/19
to weewx-user
Hi vince,

thank's a lot for your fast reply! I enabled debugging, restarted Pi with only WLAN (ethernet not connected). I'm not sure what you mean, with when "it" starts to boot. Are you refering to Pi or to weewex? Below the boot process of weewx:

Feb 14 11:12:03 raspberrypi systemd[1]: Starting LSB: weewx weather system...
Feb 14 11:12:03 raspberrypi systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Feb 14 11:12:03 raspberrypi cron[274]: (CRON) INFO (pidfile fd = 3)
Feb 14 11:12:03 raspberrypi alsactl[278]: alsactl 1.1.8 daemon started
Feb 14 11:12:03 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Feb 14 11:12:03 raspberrypi systemd[1]: man-db.timer: Not using persistent file timestamp Wed 2019-11-06 20:14:03 CET as it is in the future.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Daily man-db regeneration.
Feb 14 11:12:03 raspberrypi systemd[1]: Starting Check for Raspberry Pi EEPROM updates...
Feb 14 11:12:03 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Feb 14 11:12:03 raspberrypi thd[267]: Found socket passed from systemd
Feb 14 11:12:03 raspberrypi cron[274]: (CRON) INFO (Running @reboot jobs)
Feb 14 11:12:03 raspberrypi systemd[1]: Starting WPA supplicant...
Feb 14 11:12:03 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Feb 14 11:12:03 raspberrypi systemd[1]: logrotate.timer: Not using persistent file timestamp Wed 2019-11-06 20:14:03 CET as it is in the future.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Daily rotation of log files.
Feb 14 11:12:03 raspberrypi systemd[1]: Starting rng-tools.service...
Feb 14 11:12:03 raspberrypi systemd[1]: apt-daily.timer: Not using persistent file timestamp Wed 2019-11-06 20:14:03 CET as it is in the future.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Daily apt download activities.
Feb 14 11:12:03 raspberrypi systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Wed 2019-11-06 20:14:03 CET as it is in the future.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Feb 14 11:12:03 raspberrypi systemd[1]: Reached target Timers.
Feb 14 11:12:03 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Feb 14 11:12:03 raspberrypi systemd[1]: Reached target Sound Card.
Feb 14 11:12:03 raspberrypi rng-tools[318]: Starting Hardware RNG entropy gatherer daemon: rngd.
Feb 14 11:12:03 raspberrypi rngd[348]: rngd 2-unofficial-mt.14 starting up...
Feb 14 11:12:03 raspberrypi dhcpcd[289]: dev: loaded udev
Feb 14 11:12:03 raspberrypi rngd[348]: entropy feed to the kernel ready
Feb 14 11:12:03 raspberrypi rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.1901.0]
Feb 14 11:12:03 raspberrypi rsyslogd:  [origin software="rsyslogd" swVersion="8.1901.0" x-pid="268" x-info="https://www.rsyslog.com"] start
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Successfully dropped root privileges.
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: avahi-daemon 0.7 starting up.
Feb 14 11:12:03 raspberrypi kernel: [    9.578224] 8021q: 802.1Q VLAN Support v1.8
Feb 14 11:12:03 raspberrypi dhcpcd[289]: forked to background, child pid 369
Feb 14 11:12:03 raspberrypi udisksd[276]: udisks daemon version 2.8.1 starting
Feb 14 11:12:03 raspberrypi dphys-swapfile[273]: want /var/swap=100MByte, checking existing: keeping it
Feb 14 11:12:03 raspberrypi systemd[1]: Started System Logging Service.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Raise network interfaces.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Check for v3d driver.
Feb 14 11:12:03 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Feb 14 11:12:03 raspberrypi systemd[1]: Started rng-tools.service.
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Successfully called chroot().
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Successfully dropped remaining capabilities.
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: No service file found in /etc/avahi/services.
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Network interface enumeration completed.
Feb 14 11:12:03 raspberrypi avahi-daemon[316]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 2066605770.
Feb 14 11:12:03 raspberrypi wpa_supplicant[315]: Successfully initialized wpa_supplicant
Feb 14 11:12:03 raspberrypi udisksd[276]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory
Feb 14 11:12:03 raspberrypi udisksd[276]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
Feb 14 11:12:03 raspberrypi dhcpcd-run-hooks[397]: wlan0: starting wpa_supplicant
Feb 14 11:12:03 raspberrypi udisksd[276]: Failed to load the 'mdraid' libblockdev plugin
Feb 14 11:12:03 raspberrypi udisksd[276]: Failed to load the 'crypto' libblockdev plugin
Feb 14 11:12:03 raspberrypi kernel: [    9.919713] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k FS
Feb 14 11:12:03 raspberrypi dbus-daemon[298]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.4' (uid=0 pid=276 comm="/usr/lib/udisks2/udisksd ")
Feb 14 11:12:03 raspberrypi systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Login Service.
Feb 14 11:12:03 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Feb 14 11:12:03 raspberrypi systemd[1]: Started WPA supplicant.
Feb 14 11:12:03 raspberrypi raspi-config[277]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Feb 14 11:12:03 raspberrypi raspi-config[277]:  No. Switching to ondemand scaling governor.
Feb 14 11:12:03 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Feb 14 11:12:03 raspberrypi systemd[1]: Starting Authorization Manager...
Feb 14 11:12:03 raspberrypi systemd[1]: Reached target Network.
Feb 14 11:12:03 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Feb 14 11:12:04 raspberrypi systemd[1]: Starting A high performance web server and a reverse proxy server...
Feb 14 11:12:04 raspberrypi systemd[1]: Starting Permit User Sessions...
Feb 14 11:12:04 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Feb 14 11:12:04 raspberrypi systemd[1]: Starting Network Time Service...
Feb 14 11:12:04 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Feb 14 11:12:04 raspberrypi kernel: [   10.075327] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Feb 14 11:12:04 raspberrypi kernel: [   10.075343] brcmfmac: power management disabled
Feb 14 11:12:04 raspberrypi systemd[1]: Started Permit User Sessions.
Feb 14 11:12:04 raspberrypi systemd[1]: Starting Light Display Manager...
Feb 14 11:12:04 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Feb 14 11:12:04 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Feb 14 11:12:04 raspberrypi ntpd[415]: ntpd 4.2....@1.3728-o (1): Starting
Feb 14 11:12:04 raspberrypi ntpd[415]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 110:115
Feb 14 11:12:04 raspberrypi systemd[1]: Started Network Time Service.
Feb 14 11:12:04 raspberrypi ntpd[435]: proto: precision = 0.729 usec (-20)
Feb 14 11:12:04 raspberrypi ntpd[435]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
Feb 14 11:12:04 raspberrypi ntpd[435]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2020-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37
Feb 14 11:12:04 raspberrypi ntpd[435]: Listen and drop on 0 v6wildcard [::]:123
Feb 14 11:12:04 raspberrypi ntpd[435]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Feb 14 11:12:04 raspberrypi ntpd[435]: Listen normally on 2 lo 127.0.0.1:123
Feb 14 11:12:04 raspberrypi ntpd[435]: Listen normally on 3 lo [::1]:123
Feb 14 11:12:04 raspberrypi ntpd[435]: Listening on routing socket on fd #20 for interface updates
Feb 14 11:12:04 raspberrypi ntpd[435]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Feb 14 11:12:04 raspberrypi ntpd[435]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Feb 14 11:12:04 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Feb 14 11:12:04 raspberrypi dhcpcd[369]: eth0: waiting for carrier
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: waiting for carrier
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: carrier acquired
Feb 14 11:12:04 raspberrypi kernel: [   10.578109] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Feb 14 11:12:04 raspberrypi kernel: [   10.578474] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Feb 14 11:12:04 raspberrypi dhcpcd[369]: DUID 00:01:00:01:25:1e:c3:69:b8:27:eb:2f:cf:9a
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: IAID eb:2f:cf:9a
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: adding address fe80::bc93:b7e:c8b5:47f
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: carrier lost
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::bc93:b7e:c8b5:47f.
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: New relevant interface wlan0.IPv6 for mDNS.
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: Registering new address record for fe80::bc93:b7e:c8b5:47f on wlan0.*.
Feb 14 11:12:04 raspberrypi dhcpcd[369]: wlan0: deleting address fe80::bc93:b7e:c8b5:47f
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: Withdrawing address record for fe80::bc93:b7e:c8b5:47f on wlan0.
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::bc93:b7e:c8b5:47f.
Feb 14 11:12:04 raspberrypi avahi-daemon[316]: Interface wlan0.IPv6 no longer relevant for mDNS.
Feb 14 11:12:05 raspberrypi dhcpcd[369]: wlan0: carrier acquired
Feb 14 11:12:05 raspberrypi kernel: [   11.634258] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Feb 14 11:12:05 raspberrypi dhcpcd[369]: wlan0: IAID eb:2f:cf:9a
Feb 14 11:12:05 raspberrypi dhcpcd[369]: wlan0: adding address fe80::77f1:c446:55bf:f3a
Feb 14 11:12:05 raspberrypi avahi-daemon[316]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::77f1:c446:55bf:f3a.
Feb 14 11:12:05 raspberrypi avahi-daemon[316]: New relevant interface wlan0.IPv6 for mDNS.
Feb 14 11:12:05 raspberrypi avahi-daemon[316]: Registering new address record for fe80::77f1:c446:55bf:f3a on wlan0.*.
Feb 14 11:12:05 raspberrypi dhcpcd[369]: wlan0: probing address 192.168.0.46/24
Feb 14 11:12:06 raspberrypi dhcpcd[369]: wlan0: soliciting an IPv6 router
Feb 14 11:12:06 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Feb 14 11:12:07 raspberrypi ntpd[435]: bind(23) AF_INET6 fe80::77f1:c446:55bf:f3a%3#123 flags 0x11 failed: Cannot assign requested address
Feb 14 11:12:07 raspberrypi ntpd[435]: unable to create socket on wlan0 (4) for fe80::77f1:c446:55bf:f3a%3#123
Feb 14 11:12:07 raspberrypi ntpd[435]: failed to init interface for address fe80::77f1:c446:55bf:f3a%3
Feb 14 11:12:09 raspberrypi ntpd[435]: Listen normally on 5 wlan0 [fe80::77f1:c446:55bf:f3a%3]:123
Feb 14 11:12:09 raspberrypi ntpd[435]: new interface(s) found: waking up resolver
Feb 14 11:12:11 raspberrypi dhcpcd[369]: wlan0: using static address 192.168.0.46/24
Feb 14 11:12:11 raspberrypi avahi-daemon[316]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.46.
Feb 14 11:12:11 raspberrypi avahi-daemon[316]: New relevant interface wlan0.IPv4 for mDNS.
Feb 14 11:12:11 raspberrypi dhcpcd[369]: wlan0: adding route to 192.168.0.0/24
Feb 14 11:12:11 raspberrypi avahi-daemon[316]: Registering new address record for 192.168.0.46 on wlan0.IPv4.
Feb 14 11:12:11 raspberrypi dhcpcd[369]: wlan0: adding default route via 192.168.0.1
Feb 14 11:12:12 raspberrypi ntpd[435]: Listen normally on 6 wlan0 192.168.0.46:123
Feb 14 11:12:12 raspberrypi ntpd[435]: new interface(s) found: waking up resolver
Feb 14 11:12:12 raspberrypi ntpd[435]: Soliciting pool server 81.94.123.17
Feb 14 11:12:12 raspberrypi ntpd[435]: Soliciting pool server 81.94.123.16
Feb 14 11:12:12 raspberrypi ntpd[435]: Soliciting pool server 62.202.141.23
Feb 14 11:12:12 raspberrypi ntpd[435]: Soliciting pool server 192.33.96.102
Feb 14 11:12:13 raspberrypi ntpd[435]: Soliciting pool server 195.186.4.101
Feb 14 11:12:13 raspberrypi ntpd[435]: Soliciting pool server 46.22.26.12
Feb 14 11:12:13 raspberrypi ntpd[435]: Soliciting pool server 212.51.144.44
Feb 14 11:12:13 raspberrypi ntpd[435]: Soliciting pool server 192.33.214.47
Feb 14 11:12:14 raspberrypi ntpd[435]: Soliciting pool server 185.134.196.169
Feb 14 11:12:14 raspberrypi ntpd[435]: Soliciting pool server 5.148.175.134
Feb 14 11:12:14 raspberrypi ntpd[435]: Soliciting pool server 31.3.135.232
Feb 14 11:12:14 raspberrypi ntpd[435]: Soliciting pool server 162.159.200.1
Feb 14 11:12:15 raspberrypi ntpd[435]: Soliciting pool server 213.251.52.217
Feb 14 11:12:15 raspberrypi ntpd[435]: Soliciting pool server 162.159.200.123
Feb 14 11:12:15 raspberrypi ntpd[435]: Soliciting pool server 217.147.208.1
Feb 14 11:12:16 raspberrypi ntpd[435]: Soliciting pool server 2606:4700:f1::1
Feb 14 11:12:16 raspberrypi ntpd[435]: Soliciting pool server 213.251.53.234
Feb 14 11:12:17 raspberrypi ntpd[435]: Soliciting pool server 130.60.204.10
Feb 14 11:12:18 raspberrypi ntpd[435]: Soliciting pool server 178.209.50.229
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.4618f930 does not match aorg 0000000000.00000000 from ser...@213.251.53.234 xmt 0xe16dbf00.550feae8
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.46292162 does not match aorg 0000000000.00000000 from ser...@192.33.96.102 xmt 0xe16dbf00.55cc064a
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.46272391 does not match aorg 0000000000.00000000 from ser...@195.186.4.101 xmt 0xe16dbf00.554f42ae
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.462b1aba does not match aorg 0000000000.00000000 from ser...@62.202.141.23 xmt 0xe16dbf00.55bcecae
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.460fabb4 does not match aorg 0000000000.00000000 from ser...@178.209.50.229 xmt 0xe16dbf00.54255c58
Nov  6 22:52:00 raspberrypi systemd[1]: Starting Daily man-db regeneration...
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.46232cc7 does not match aorg 0000000000.00000000 from ser...@185.134.196.169 xmt 0xe16dbf00.54a16ac5
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.461cb86a does not match aorg 0000000000.00000000 from ser...@162.159.200.123 xmt 0xe16dbf00.549d2aa6
Nov  6 22:52:00 raspberrypi ntpd[435]: receive: Unexpected origin timestamp 0xe00fbd83.46212997 does not match aorg 0000000000.00000000 from ser...@162.159.200.1 xmt 0xe16dbf00.549e47bf
Nov  6 22:52:00 raspberrypi dhcpcd[369]: wlan0: no IPv6 Routers available
Nov  6 22:52:03 raspberrypi systemd[1]: Starting Rotate log files...
Nov  6 22:52:03 raspberrypi systemd[1]: Starting Daily apt download activities...
Nov  6 22:52:07 raspberrypi kernel: [   32.614805] Bluetooth: Core ver 2.22
Nov  6 22:52:07 raspberrypi kernel: [   32.614919] NET: Registered protocol family 31
Nov  6 22:52:07 raspberrypi kernel: [   32.614925] Bluetooth: HCI device and connection manager initialized
Nov  6 22:52:07 raspberrypi kernel: [   32.616064] Bluetooth: HCI socket layer initialized
Nov  6 22:52:07 raspberrypi kernel: [   32.616080] Bluetooth: L2CAP socket layer initialized
Nov  6 22:52:07 raspberrypi kernel: [   32.616121] Bluetooth: SCO socket layer initialized
Nov  6 22:52:09 raspberrypi udisksd[276]: Error initializing polkit authority: Error initializing authority: Error calling StartServiceByName for org.freedesktop.PolicyKit1: GDBus.Error:org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms) (g-dbus-error-quark, 20)
Nov  6 22:52:11 raspberrypi btuart[265]: bcm43xx_init
Nov  6 22:52:11 raspberrypi btuart[265]: Flash firmware /lib/firmware/brcm/BCM43430A1.hcd
Nov  6 22:52:11 raspberrypi kernel: [   36.613918] Bluetooth: HCI UART driver ver 2.3
Nov  6 22:52:11 raspberrypi kernel: [   36.613928] Bluetooth: HCI UART protocol H4 registered
Nov  6 22:52:11 raspberrypi kernel: [   36.613999] Bluetooth: HCI UART protocol Three-wire (H5) registered
Nov  6 22:52:11 raspberrypi kernel: [   36.614134] Bluetooth: HCI UART protocol Broadcom registered
Nov  6 22:52:11 raspberrypi btuart[265]: Set BDADDR UART: b8:27:eb:d0:30:65
Nov  6 22:52:11 raspberrypi btuart[265]: Set Controller UART speed to 921600 bit/s
Nov  6 22:52:11 raspberrypi btuart[265]: Device setup complete
Nov  6 22:52:11 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Nov  6 22:52:11 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Nov  6 22:52:15 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Nov  6 22:52:15 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Nov  6 22:52:15 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Nov  6 22:52:15 raspberrypi systemd[1]: Starting Bluetooth service...
Nov  6 22:52:15 raspberrypi lightdm[429]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov  6 22:52:15 raspberrypi polkitd[405]: started daemon version 0.105 using authority implementation `local' version `0.105'
Nov  6 22:52:15 raspberrypi systemd[1]: Started Authorization Manager.
Nov  6 22:52:20 raspberrypi systemd[1]: plymouth-start.service: Succeeded.
Nov  6 22:52:20 raspberrypi systemd[1]: plymouth-quit-wait.service: Succeeded.
Nov  6 22:52:20 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Nov  6 22:52:20 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Nov  6 22:52:20 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 144 (n/a).
Nov  6 22:52:20 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 144 (n/a).
Nov  6 22:52:20 raspberrypi systemd[1]: Started Light Display Manager.
Nov  6 22:52:20 raspberrypi systemd[1]: Started Getty on tty1.
Nov  6 22:52:20 raspberrypi systemd[1]: Reached target Login Prompts.
Nov  6 22:52:20 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Nov  6 22:52:20 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Nov  6 22:52:22 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Nov  6 22:52:22 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Nov  6 22:52:36 raspberrypi systemd[1]: Started A high performance web server and a reverse proxy server.
Nov  6 22:52:48 raspberrypi systemd[1]: Started Disk Manager.
Nov  6 22:52:48 raspberrypi bluetoothd[488]: Bluetooth daemon 5.50
Nov  6 22:52:48 raspberrypi udisksd[276]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Nov  6 22:52:54 raspberrypi systemd[1]: Started Bluetooth service.
Nov  6 22:52:54 raspberrypi systemd[1]: Reached target Bluetooth.
Nov  6 22:52:54 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Nov  6 22:52:54 raspberrypi systemd[1]: Started BluezALSA proxy.
Nov  6 22:52:56 raspberrypi systemd[1]: logrotate.service: Succeeded.
Nov  6 22:52:56 raspberrypi systemd[1]: Started Rotate log files.
Nov  6 22:52:59 raspberrypi bluetoothd[488]: Starting SDP server
Nov  6 22:53:00 raspberrypi kernel: [   85.050019] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Nov  6 22:53:00 raspberrypi kernel: [   85.050028] Bluetooth: BNEP filters: protocol multicast
Nov  6 22:53:00 raspberrypi kernel: [   85.050043] Bluetooth: BNEP socket layer initialized
Nov  6 22:53:00 raspberrypi dbus-daemon[298]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.10' (uid=0 pid=488 comm="/usr/lib/bluetooth/bluetoothd ")
Nov  6 22:53:00 raspberrypi bluetoothd[488]: Bluetooth management interface 1.14 initialized
Nov  6 22:53:00 raspberrypi bluetoothd[488]: Sap driver initialization failed.
Nov  6 22:53:00 raspberrypi bluetoothd[488]: sap-server: Operation not permitted (1)
Nov  6 22:53:00 raspberrypi systemd[1]: bthe...@hci0.service: Succeeded.
Nov  6 22:53:00 raspberrypi bluetoothd[488]: Endpoint registered: sender=:1.12 path=/org/bluez/hci0/A2DP/SBC/Source/1
Nov  6 22:53:00 raspberrypi bluetoothd[488]: Endpoint registered: sender=:1.12 path=/org/bluez/hci0/A2DP/SBC/Source/2
Nov  6 22:53:00 raspberrypi systemd[1]: Starting Hostname Service...
Nov  6 22:53:00 raspberrypi weewx[427]: engine: Initializing weewx version 3.9.2
Nov  6 22:53:00 raspberrypi weewx[427]: engine: Using Python 2.7.16 (default, Apr  6 2019, 01:42:57) #012[GCC 8.2.0]
Nov  6 22:53:00 raspberrypi kernel: [   85.166844] Bluetooth: RFCOMM TTY layer initialized
Nov  6 22:53:00 raspberrypi kernel: [   85.166866] Bluetooth: RFCOMM socket layer initialized
Nov  6 22:53:00 raspberrypi kernel: [   85.166889] Bluetooth: RFCOMM ver 1.11
Nov  6 22:53:00 raspberrypi weewx[427]: engine: Platform Linux-4.19.75-v7+-armv7l-with-debian-10.1
Nov  6 22:53:00 raspberrypi weewx[427]: engine: Locale is 'de_CH.UTF-8'
Nov  6 22:53:00 raspberrypi weewx[427]: engine: pid file is /var/run/weewx.pid
Nov  6 22:53:00 raspberrypi bluetoothd[488]: Failed to set privacy: Rejected (0x0b)
Nov  6 22:53:00 raspberrypi weewx[280]: Starting weewx weather system: weewx.
Nov  6 22:53:00 raspberrypi systemd[1]: Started LSB: weewx weather system.
Nov  6 22:53:00 raspberrypi systemd[1]: Reached target Multi-User System.
Nov  6 22:53:00 raspberrypi systemd[1]: Reached target Graphical Interface.
Nov  6 22:53:00 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Nov  6 22:53:00 raspberrypi weewx[576]: engine: Using configuration file /home/weewx/weewx.conf
Nov  6 22:53:00 raspberrypi weewx[576]: engine: Debug is 1
Nov  6 22:53:00 raspberrypi weewx[576]: engine: Initializing engine
Nov  6 22:53:00 raspberrypi weewx[576]: engine: Loading station type KlimaLogg (user.kl)
Nov  6 22:53:00 raspberrypi systemd[502]: Reached target Paths.
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on GnuPG network certificate management daemon.
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov  6 22:53:00 raspberrypi systemd[502]: Starting D-Bus User Message Bus Socket.
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov  6 22:53:00 raspberrypi systemd[502]: Reached target Timers.
Nov  6 22:53:00 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Nov  6 22:53:00 raspberrypi systemd[502]: Listening on D-Bus User Message Bus Socket.
Nov  6 22:53:00 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Nov  6 22:53:00 raspberrypi systemd[502]: Reached target Sockets.
Nov  6 22:53:00 raspberrypi systemd[502]: Reached target Basic System.
Nov  6 22:53:00 raspberrypi systemd[502]: Reached target Default.
Nov  6 22:53:00 raspberrypi systemd[502]: Startup finished in 28.346s.
Nov  6 22:53:00 raspberrypi systemd[1]: Started User Manager for UID 1000.
Nov  6 22:53:00 raspberrypi systemd[1]: Started Session c2 of user pi.
Nov  6 22:53:00 raspberrypi systemd[1]: Started Session c1 of user pi.
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: driver version is 1.3.7
Nov  6 22:53:00 raspberrypi dbus-daemon[298]: [system] Successfully activated service 'org.freedesktop.hostname1'
Nov  6 22:53:00 raspberrypi systemd[1]: Started Hostname Service.
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: channel is 1
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: frequency is EU
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: using sensor map for kl schema
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: sensor map is: {'temp3': 'Temp3', 'temp2': 'Temp2', 'temp1': 'Temp1', 'temp0': 'Temp0', 'temp7': 'Temp7', 'temp6': 'Temp6', 'temp5': 'Temp5', 'temp4': 'Temp4', 'temp8': 'Temp8', 'batteryStatus8': 'BatteryStatus8', 'batteryStatus1': 'BatteryStatus1', 'batteryStatus0': 'BatteryStatus0', 'batteryStatus3': 'BatteryStatus3', 'batteryStatus2': 'BatteryStatus2', 'batteryStatus5': 'BatteryStatus5', 'batteryStatus4': 'BatteryStatus4', 'batteryStatus7': 'BatteryStatus7', 'batteryStatus6': 'BatteryStatus6', 'humidity8': 'Humidity8', 'humidity4': 'Humidity4', 'humidity5': 'Humidity5', 'humidity6': 'Humidity6', 'humidity7': 'Humidity7', 'humidity0': 'Humidity0', 'humidity1': 'Humidity1', 'humidity2': 'Humidity2', 'humidity3': 'Humidity3', 'rxCheckPercent': 'SignalQuality'}
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: catchup limited to 51200 records
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: timing is 300 ms (0.300 s)
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: CommunicationService.init
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: comm_interval is 8
Nov  6 22:53:00 raspberrypi weewx[576]: KlimaLogg: MainThread: logger_channel is 1
Nov  6 22:53:30 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Nov  6 22:53:34 raspberrypi weewx[576]: KlimaLogg: MainThread: found transceiver at bus= device=
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: manufacturer: LA CROSSE TECHNOLOGY
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: product: Weather Direct Light Wireless Device
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: interface: 0
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: claiming USB interface 0
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: frequency standard: EU
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: base frequency: 868300000
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: frequency correction: 94320 (0x17070)
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: adjusted frequency: 910572861 (0x36463d3d)
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: frequency registers: 36 46 3d 3d
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: transceiver identifier: 91 (0x005b)
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: transceiver serial: 01012703140091
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: MainThread: startRFThread: spawning RF thread
Nov  6 22:53:36 raspberrypi weewx[576]: KlimaLogg: RFComm: setting up rf communication
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Loading service weewx.engine.StdTimeSynch
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Finished loading service weewx.engine.StdTimeSynch
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Loading service weewx.engine.StdConvert
Nov  6 22:53:36 raspberrypi weewx[576]: engine: StdConvert target unit is 0x11
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Finished loading service weewx.engine.StdConvert
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Loading service weewx.engine.StdCalibrate
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Finished loading service weewx.engine.StdCalibrate
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Loading service weewx.engine.StdQC
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Finished loading service weewx.engine.StdQC
Nov  6 22:53:36 raspberrypi weewx[576]: engine: Loading service weewx.wxservices.StdWXCalculate
Nov  6 22:53:38 raspberrypi weewx[576]: wxcalculate: The following values will be calculated: barometer=prefer_hardware, windchill=prefer_hardware, dewpoint=prefer_hardware, appTemp=prefer_hardware, rainRate=prefer_hardware, windrun=prefer_hardware, heatindex=prefer_hardware, maxSolarRad=prefer_hardware, humidex=prefer_hardware, pressure=prefer_hardware, inDewpoint=prefer_hardware, ET=prefer_hardware, altimeter=prefer_hardware, cloudbase=prefer_hardware
Nov  6 22:53:38 raspberrypi weewx[576]: wxcalculate: The following algorithms will be used for calculations: altimeter=aaNOAA, maxSolarRad=RS
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Finished loading service weewx.wxservices.StdWXCalculate
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Loading service weewx.engine.StdArchive
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Archive will use data binding kl_binding
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Record generation will be attempted in 'hardware'
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Using archive interval of 60 seconds (specified in weewx configuration)
Nov  6 22:53:38 raspberrypi weewx[576]: engine: Use LOOP data in hi/low calculations: 1
Nov  6 22:54:23 raspberrypi systemd[1]: man-db.service: Succeeded.
Nov  6 22:54:23 raspberrypi systemd[1]: Started Daily man-db regeneration.
Nov  6 22:54:24 raspberrypi lightdm[639]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov  6 22:54:24 raspberrypi systemd[1]: Started Session c3 of user pi.
Nov  6 22:54:26 raspberrypi lightdm[429]: Error opening audit socket: Protocol not supported
Nov  6 22:54:26 raspberrypi systemd[502]: Started D-Bus User Message Bus.
Nov  6 22:54:26 raspberrypi systemd[1]: apt-daily.service: Succeeded.
Nov  6 22:54:26 raspberrypi systemd[1]: Started Daily apt download activities.
Nov  6 22:54:26 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
Nov  6 22:54:30 raspberrypi systemd[1]: apt-daily-upgrade.service: Succeeded.
Nov  6 22:54:30 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Nov  6 22:54:30 raspberrypi systemd[1]: Startup finished in 3.979s (kernel) + 2min 51.593s (userspace) = 2min 55.573s.
Nov  6 22:55:08 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=648 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ")
Nov  6 22:55:08 raspberrypi systemd[502]: Starting Virtual filesystem service...
Nov  6 22:55:08 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.Daemon'
Nov  6 22:55:08 raspberrypi systemd[502]: Started Virtual filesystem service.
Nov  6 22:55:08 raspberrypi kernel: [  213.682100] fuse init (API version 7.27)
Nov  6 22:55:08 raspberrypi systemd[1]: Mounting FUSE Control File System...
Nov  6 22:55:08 raspberrypi systemd[1]: Mounted FUSE Control File System.
Nov  6 22:55:09 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=795 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov  6 22:55:09 raspberrypi systemd[502]: Starting Virtual filesystem service - disk device monitor...
Nov  6 22:55:09 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Nov  6 22:55:09 raspberrypi systemd[502]: Started Virtual filesystem service - disk device monitor.
Nov  6 22:55:09 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=795 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov  6 22:55:09 raspberrypi systemd[502]: Starting Virtual filesystem service - digital camera monitor...
Nov  6 22:55:09 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Nov  6 22:55:09 raspberrypi systemd[502]: Started Virtual filesystem service - digital camera monitor.
Nov  6 22:55:09 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=795 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov  6 22:55:09 raspberrypi systemd[502]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Nov  6 22:55:10 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Nov  6 22:55:10 raspberrypi systemd[502]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Nov  6 22:55:10 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=795 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov  6 22:55:10 raspberrypi systemd[502]: Starting Virtual filesystem service - Apple File Conduit monitor...
Nov  6 22:55:10 raspberrypi gvfs-afc-volume-monitor[894]: Volume monitor alive
Nov  6 22:55:10 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Nov  6 22:55:10 raspberrypi systemd[502]: Started Virtual filesystem service - Apple File Conduit monitor.
Nov  6 22:55:10 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=795 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov  6 22:55:10 raspberrypi systemd[502]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Nov  6 22:55:10 raspberrypi dbus-daemon[659]: [session uid=1000 pid=659] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Nov  6 22:55:10 raspberrypi systemd[502]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Nov  6 22:55:54 raspberrypi weewx[576]: KlimaLogg: MainThread: stopRFThread: waiting for RF thread to terminate
Nov  6 22:56:54 raspberrypi weewx[576]: KlimaLogg: MainThread: unable to terminate RF thread after 60 seconds
Nov  6 22:56:54 raspberrypi weewx[576]: KlimaLogg: MainThread: releasing USB interface
Nov  6 22:56:54 raspberrypi weewx[576]: engine: Caught unrecoverable exception in engine:
Nov  6 22:56:54 raspberrypi weewx[576]:     ****  (1007, "Can't create database 'weewx_kl'; database exists")
Nov  6 22:56:54 raspberrypi weewx[576]:     ****  Traceback (most recent call last):
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/engine.py", line 888, in main
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      engine = engine_class(config_dict)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/engine.py", line 78, in __init__
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      self.loadServices(config_dict)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/engine.py", line 142, in loadServices
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      self.service_obj.append(weeutil.weeutil._get_object(svc)(self, config_dict))
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/engine.py", line 500, in __init__
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      self.setup_database(config_dict)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/engine.py", line 608, in setup_database
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      dbmanager = self.engine.db_binder.get_manager(self.data_binding, initialize=True)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/manager.py", line 872, in get_manager
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      self.manager_cache[data_binding] = open_manager(manager_dict, initialize)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/manager.py", line 1021, in open_manager
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      manager_dict['schema'])
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weewx/manager.py", line 136, in open_with_create
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      weedb.create(database_dict)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weedb/__init__.py", line 80, in create
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      return driver_mod.create(**db_dict)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weedb/mysql.py", line 75, in create
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      cursor.execute("CREATE DATABASE %s" % (database_name,))
Nov  6 22:56:54 raspberrypi weewx[576]:     ****    File "/home/weewx/bin/weedb/mysql.py", line 49, in guarded_fn
Nov  6 22:56:54 raspberrypi weewx[576]:     ****      raise klass(e)
Nov  6 22:56:54 raspberrypi weewx[576]:     ****  DatabaseExistsError: (1007, "Can't create database 'weewx_kl'; database exists")
Nov  6 22:56:54 raspberrypi weewx[576]:     ****  Exiting.


Message has been deleted
Message has been deleted
Message has been deleted

walterli

unread,
Nov 6, 2019, 5:48:24 PM11/6/19
to weewx-user
For reference attached how the log looks like when starting Pi with connected Ethernet cable.

P.S.: I tried to post it three times, but it was always cut. That's why it's attached as txt-file this time.
boot weewx LAN.txt

vince

unread,
Nov 6, 2019, 7:19:04 PM11/6/19
to weewx-user
On Wednesday, November 6, 2019 at 2:48:24 PM UTC-8, walterli wrote:
For reference attached how the log looks like when starting Pi with connected Ethernet cable.

P.S.: I tried to post it three times, but it was always cut. That's why it's attached as txt-file this time.

Unfortunately I don't have any experience with the KL driver but just to ask, do you perhaps have your database mounted across the network from some other system ?   I was a little surprised to see mention of "Apple File Conduit monitor" in your logs.

You might need to also post your weewx.conf (with any usernames/passwords edited out please).

The following logs looked like it's trying to tell you something db related as the underlying issue. Does your setup perhaps try to always create a db even if one already exists ?

walterli

unread,
Nov 7, 2019, 2:11:07 PM11/7/19
to weewx-user
weewx.conf is attached to this post.

The mySQL Database is not hosted on the Pi but on my NAS in the same local network.

Beside that, and the KL-driver I didn't deviate much from the standard setup of weewx. I cannot explain, why it tries to created the database every time. Apparently it does it only when the LAN cable is not connected. Maybe a MySQL configuration issue:

On mySQL I had created two users:
where 192.168.0.45 is the LAN address of the Pi and 192.168.0.46 is the WLAN address of the Pi

Since I was not perfectly sure, if really both users have the same rights, I deleted them and created instead only one user for all connections:
weewx@%
Now weewx tries no longer to create the database. One problem solved. Still weewx is not starting properly in WLAN.

I tried the following: once pi was started with LAN. I did the following:
sudo /etc/init.d/weewx stop
sudo /etc/init.d/weewx start
weewx is succesfully running and writing to the database
sudo /etc/init.d/weewx stop
unplug ethernet cable
sudo /etc/init.d/weewx start
weewx is not running properly

The log files of the two startups with, and without Ethernet cable can be found attached. In the beginning they are Identical. But suddenly the WLAN starts to deviate.

For me it looks like
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: RFComm: setting up rf communication
 is failing.

(Use Loop data in hi/low calculations: 1 is the last line the two startups have in common):
Nov  7 19:33:38 raspberrypi weewx[1562]: engine: Use LOOP data in hi/low calculations: 1
Nov  7 19:33:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: stopRFThread: waiting for RF thread to terminate
Nov  7 19:34:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: unable to terminate RF thread after 60 seconds
Nov  7 19:34:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: releasing USB interface
Nov  7 19:34:58 raspberrypi weewx[1562]: engine: Database connection exception: (2013, "Lost connection to MySQL server at 'reading authorization packet', system error: 11")
Nov  7 19:34:58 raspberrypi weewx[1562]:     ****  Waiting 2 minutes then retrying...
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: retrying...
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Using configuration file /home/weewx/weewx.conf
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Debug is 1
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Initializing engine
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading station type KlimaLogg (user.kl)
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: driver version is 1.3.7
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: channel is 1
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: frequency is EU
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: using sensor map for kl schema
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: sensor map is: {'temp3': 'Temp3', 'temp2': 'Temp2', 'temp1': 'Temp1', 'temp0': 'Temp0', 'temp7': 'Temp7', 'temp6': 'Temp6', 'temp5': 'Temp5', 'temp4': 'Temp4', 'temp8': 'Temp8', 'batteryStatus8': 'BatteryStatus8', 'batteryStatus1': 'BatteryStatus1', 'batteryStatus0': 'BatteryStatus0', 'batteryStatus3': 'BatteryStatus3', 'batteryStatus2': 'BatteryStatus2', 'batteryStatus5': 'BatteryStatus5', 'batteryStatus4': 'BatteryStatus4', 'batteryStatus7': 'BatteryStatus7', 'batteryStatus6': 'BatteryStatus6', 'humidity8': 'Humidity8', 'humidity4': 'Humidity4', 'humidity5': 'Humidity5', 'humidity6': 'Humidity6', 'humidity7': 'Humidity7', 'humidity0': 'Humidity0', 'humidity1': 'Humidity1', 'humidity2': 'Humidity2', 'humidity3': 'Humidity3', 'rxCheckPercent': 'SignalQuality'}
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: catchup limited to 51200 records
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: timing is 300 ms (0.300 s)
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: CommunicationService.init
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: comm_interval is 8
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: logger_channel is 1
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: found transceiver at bus= device=
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: manufacturer: LA CROSSE TECHNOLOGY
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: product: Weather Direct Light Wireless Device
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: interface: 0
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: claiming USB interface 0
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: frequency standard: EU
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: base frequency: 868300000
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: frequency correction: 94320 (0x17070)
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: adjusted frequency: 910572861 (0x36463d3d)
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: frequency registers: 36 46 3d 3d
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: transceiver identifier: 91 (0x005b)
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: transceiver serial: 01012703140091
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: MainThread: startRFThread: spawning RF thread
Nov  7 19:36:58 raspberrypi weewx[1562]: KlimaLogg: RFComm: setting up rf communication
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.engine.StdTimeSynch
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Finished loading service weewx.engine.StdTimeSynch
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.engine.StdConvert
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: StdConvert target unit is 0x11
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Finished loading service weewx.engine.StdConvert
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.engine.StdCalibrate
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Finished loading service weewx.engine.StdCalibrate
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.engine.StdQC
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Finished loading service weewx.engine.StdQC
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.wxservices.StdWXCalculate
Nov  7 19:36:58 raspberrypi weewx[1562]: wxcalculate: The following values will be calculated: barometer=prefer_hardware, windchill=prefer_hardware, dewpoint=prefer_hardware, appTemp=prefer_hardware, rainRate=prefer_hardware, windrun=prefer_hardware, heatindex=prefer_hardware, maxSolarRad=prefer_hardware, humidex=prefer_hardware, pressure=prefer_hardware, inDewpoint=prefer_hardware, ET=prefer_hardware, altimeter=prefer_hardware, cloudbase=prefer_hardware
Nov  7 19:36:58 raspberrypi weewx[1562]: wxcalculate: The following algorithms will be used for calculations: altimeter=aaNOAA, maxSolarRad=RS
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Finished loading service weewx.wxservices.StdWXCalculate
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Loading service weewx.engine.StdArchive
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Archive will use data binding kl_binding
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Record generation will be attempted in 'hardware'
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Using archive interval of 60 seconds (specified in weewx configuration)
Nov  7 19:36:58 raspberrypi weewx[1562]: engine: Use LOOP data in hi/low calculations: 1
Nov  7 19:37:18 raspberrypi weewx[1562]: KlimaLogg: MainThread: stopRFThread: waiting for RF thread to terminate
Nov  7 19:38:18 raspberrypi weewx[1562]: KlimaLogg: MainThread: unable to terminate RF thread after 60 seconds
Nov  7 19:38:18 raspberrypi weewx[1562]: KlimaLogg: MainThread: releasing USB interface
Nov  7 19:38:18 raspberrypi weewx[1562]: engine: Database connection exception: (2013, "Lost connection to MySQL server at 'reading authorization packet', system error: 11")
Nov  7 19:38:18 raspberrypi weewx[1562]:     ****  Waiting 2 minutes then retrying...









start_weewx_LAN.txt
start_weewx_WLAN.txt
weewx.conf

vince

unread,
Nov 7, 2019, 3:11:36 PM11/7/19
to weewx-user
My wild guess is perhaps your NAS is restricting inbound to the mysql service to just your LAN ip, not including your wifi ip, but that's just a wild guess.

From the WLAN log - "Lost connection to MySQL server at 'reading authorization packet', system error: 11")

walterli

unread,
Nov 7, 2019, 3:14:20 PM11/7/19
to weewx-user
I agree, I guessed the same, that's why I created the new user weewx@% which should allow all hosts

walterli

unread,
Nov 7, 2019, 3:31:36 PM11/7/19
to weewx-user
Just tried what happens if I use a SQLite Database: it works perfectly. So it must really be something with the mySQL connection over WLAN...

vince

unread,
Nov 7, 2019, 3:41:29 PM11/7/19
to weewx-user
On Thursday, November 7, 2019 at 12:31:36 PM UTC-8, walterli wrote:
Just tried what happens if I use a SQLite Database: it works perfectly. So it must really be something with the mySQL connection over WLAN...

Cool - you can test that easily outside weewx.  Once that works, weewx should work.

walterli

unread,
Nov 7, 2019, 4:54:29 PM11/7/19
to weewx-user
The last findings are the following:

on WLAN I get:

pi@raspberrypi:/ $ mysql -h 192.168.0.44 -u weewx -p
Enter password:
ERROR 2013 (HY000): Lost connection to MySQL server at 'reading authorization packet', system error: 2 "No such file or directory"
After entering the pasword, it takes a couple of seconds, until I get the error message.

And on LAN I get:

pi@raspberrypi:~ $ sudo mysql -h 192.168.0.44 -u weewx -p
Enter password:
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 9668
Server version: 5.5.62-MariaDB Source distribution

Copyright (c) 2000, 2016, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]>

Currently I have no idea, why mySQL remote access works via LAN but not via WLAN. The WLAN connection goes through a Devolo Wifi --> PowerLine to the same router as the wired connection.

I have to think about this. Anyhow, thanks for your inputs!

Cameron D

unread,
Nov 8, 2019, 10:50:01 PM11/8/19
to weewx-user
did the new "user" have the same table access permissions as the original weewx user?

Cameron D

unread,
Nov 8, 2019, 10:54:57 PM11/8/19
to weewx-user
Sorry, ignore that. I have just realised you are not even getting that far.
Is there any reason you used sudo on the LAN test?  I would not have thought is necessary.

walterli

unread,
Nov 9, 2019, 2:36:06 AM11/9/19
to weewx-user
To be honest, I don't know exactly what I'm doing, so I use by default all the time sudo ;-D But you are right, it works as well without sudo, just tested to be sure.

The new "user" hase enough access permissions, because over wired LAN I'm able to connect to mySQL. There is only one user configured which is accepting all client IPs. I even interchanged the Pi's IP Adresss between WLAN and LAN to confirm this. Still the same result: LAN works, WLAN no access.

But as you say, I'm not even getting that far.

However, I'm a step further:
My normal hardware setup is:

Pi
-- WLAN --
-- 230V Power Line --
-- Ethernet Cable --
Router (WLAN disabled)
-- Ethernet Cable --
NAS

I tried the following two setups and they work (changes to usual setup in bold):

Setup 1: Connect Pi with cable to WLAN access point:
Pi
-- Ethernet Cable -- (WLAN remains enabled)
-- 230V Power Line --
-- Ethernet Cable --
Router (WLAN disabled)
-- Ethernet Cable --
NAS

Setup 2 Disable WLAN accesspoint and connect Pi directly with Wifi of Router (same SSID, Passord etc, no reconfig on Pi):
Pi
-- WLAN --
dLAN 1200+ WiFi ac (https://www.devolo.com/dlan-1200-wifi-ac-powerline) (disabled Wifi)
-- 230V Power Line --
-- Ethernet Cable --
Router (WLAN enabled)
-- Ethernet Cable --
NAS

This tells me,
- the WiFi settings in the Pi are correct.
- The connection from the usual dLAN access point to the NAS is correct (router is not blocking).
- However, the Wifi of the dLAN1200+ access piont is blocking somehow.


walterli

unread,
Nov 9, 2019, 2:58:49 AM11/9/19
to weewx-user
Success! Now everthing is working as I wish.

I did a firmware update of all dLAN devices. Wether it was the update or the reboot of these devices which solved the problem I cannot say.

Thank you for your support!
Reply all
Reply to author
Forward
0 new messages