Weewx won't start with daemon and by itself on 1st try

[Jerry Deibel]

Hi,

I have been running weewx with my ambient 1400 Observer for about 2 years. Last year I moved the OP system to a USB stick to save wear and tear on the SD card and  last week the USB had a sector error and would not load.  So much for moving over from a SD card to a USB stick.

I reloaded Jessi OP system on the Raspberry PI, but this time just on the SD card  using the SETUP.PI procedure ( no USB this time) and weewx is up and running using  [ sudo ./bin/weewxd weewx.conf ].  I ran it for a day or so to make sure everything was ok.  I backup my archive every day so I restored the archive database for the last year as well.   

The last 2 years I ran a daemon process to run it on power up , so today I did that..

Now my problem is ..... 

After doing the following to run it on power up....    

sudo util/init.d/weewx.debian to /etc/init.d/weewx)

sudo chmod +x /etc/init.d/weewx

sudo update-rc.d weewx defaults 98

I then tried to start        sudo /etc/init.d/weewx start     : no log outpur and ps aux shows not running

It DID  not start

I then stopped it..          sudo /etc/init.d/weewx  stop

I then started it again.   sudo /etc/init.d/weewx start

AND IT STARTED ....   Outputting to log and ...  ps aux | grep weewx    ... shows it running ok.

Also, it does not start on  a power up.  

Here is the log right after power up ..

pi@raspberrypi:~ $ tail -f /var/log/syslog

Jan  4 10:50:18 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[664]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/index.bdmv

Jan  4 10:50:18 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[664]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/BACKUP/index.bdmv

Jan  4 10:50:20 raspberrypi ntpd_intres[542]: DNS 0.debian.pool.ntp.org -> 45.79.1.70

Jan  4 10:50:20 raspberrypi ntpd_intres[542]: DNS 1.debian.pool.ntp.org -> 195.21.137.209

Jan  4 10:50:20 raspberrypi ntpd_intres[542]: DNS 2.debian.pool.ntp.org -> 104.131.53.252

Jan  4 10:50:20 raspberrypi ntpd_intres[542]: DNS 3.debian.pool.ntp.org -> 138.68.2.126

Jan  4 10:50:24 raspberrypi dhcpcd[420]: eth0: no IPv6 Routers available

Jan  4 10:51:12 raspberrypi systemd[1]: Time has been changed

Jan  4 10:51:12 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed Jan  4 10:51:42 2017 [try http://www.rsyslog.com/e/2007 ]

Jan  4 10:51:12 raspberrypi systemd[560]: Time has been changed

Jan  4 10:53:11 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed Jan  4 10:53:41 2017 [try http://www.rsyslog.com/e/2007 ]

Jan  4 10:53:11 raspberrypi systemd[1]: Started LSB: weewx weather system.

Jan  4 13:30:56 raspberrypi systemd[1]: Stopping LSB: weewx weather system...

Jan  4 13:30:56 raspberrypi weewx[1567]: Stopping weewx weather system: weewx not running....

Jan  4 13:30:56 raspberrypi systemd[1]: Stopped LSB: weewx weather system.

Jan  4 13:31:09 raspberrypi systemd[1]: Starting LSB: weewx weather system...

Jan  4 13:31:09 raspberrypi weewx[1627]: engine: Initializing weewx version 3.6.2

Jan  4 13:31:09 raspberrypi weewx[1627]: engine: Using Python 2.7.9 (default, Sep 17 2016, 20:26:04) #012[GCC 4.9.2]

Jan  4 13:31:09 raspberrypi weewx[1627]: engine: Platform Linux-4.4.34-v7+-armv7l-with-debian-8.0

Jan  4 13:31:09 raspberrypi weewx[1627]: engine: pid file is /var/run/weewx.pid

Jan  4 13:31:09 raspberrypi weewx[1631]: engine: Using configuration file /home/weewx/weewx.conf

Jan  4 13:31:09 raspberrypi weewx[1631]: engine: Loading station type ObserverIP (user.observerip)

Jan  4 13:31:09 raspberrypi weewx[1616]: Starting weewx weather system: weewx.

Jan  4 13:31:09 raspberrypi systemd[1]: Started LSB: weewx weather system.

Jan  4 13:31:09 raspberrypi weewx[1631]: observerip: version is 0.5mw

Jan  4 13:31:10 raspberrypi weewx[1631]: observerip: Unknown firmware version: ����������

Jan  4 13:31:10 raspberrypi weewx[1631]: observerip: polling interval is 16.0

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: StdConvert target unit is 0x1

Jan  4 13:31:10 raspberrypi weewx[1631]: 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

Jan  4 13:31:10 raspberrypi weewx[1631]: wxcalculate: The following algorithms will be used for calculations: altimeter=aaNOAA, maxSolarRad=RS

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Archive will use data binding wx_binding

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Record generation will be attempted in 'hardware'

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Using archive interval of 300 seconds (specified in weewx configuration)

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Using binding 'wx_binding' to database 'weewx.sdb'

Jan  4 13:31:10 raspberrypi weewx[1631]: manager: Starting backfill of daily summaries

Jan  4 13:31:10 raspberrypi weewx[1631]: manager: Daily summaries up to date

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: StationRegistry: Registration not requested.

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: Wunderground: Posting not enabled.

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: PWSweather: Posting not enabled.

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: CWOP: Posting not enabled.

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: WOW: Posting not enabled.

Jan  4 13:31:10 raspberrypi weewx[1631]: restx: AWEKAS: Posting not enabled.

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Starting up weewx version 3.6.2

Jan  4 13:31:10 raspberrypi weewx[1631]: engine: Starting main packet loop.

AS YOU CAN SEE IN THE LOG..   NOTHING HAPPENS AFTER THE 1ST START,   BUT IT'S OK AFTER I START IT THE SECOND TIME.

Anyone have any ideas??

Jerry

PS.     Not related, but somehow the other day the archive shows 30" of rain in one day.?????

How can I remove that entry from the database (SQLITE).

IHow can you display the archive.sdb data?   I tried using the sqlilte3 command line, but I dont even know what table to select to even look at it..

[Andrew Milner]

1. Install phpliteadmin to view/amend SQLite databases

2. check user guide for how to remove 'spikes' for your incorrect rain reading

3. if you installed via setup.py the daemon is located at sudo /etc/init.d/weewx start or sudo /etc/init.d/weewx stop etc etc etc

[mwall]

jerry,

you might try using a pure systemd configuration instead of using an rc script.  the weewx rc script *should* work with systemd, but lately there have been postings to this forum that indicate that might be changing.

get rid of the rc script:

sudo /etc/init.d/weewx stop
sudo update-rc.d weewx remove
sudo rm /etc/init.d/weewx

install the weewx unit file:

https://github.com/weewx/weewx/wiki/systemd

data are stored in the 'archive' table, which is in the file weewx.sdb if you are using sqlite.  the other tables in that database are for daily aggregates.

you can use the .schema command to see all of the tables and their schemas.

m

[Jerry Deibel]

mwall,

I tried the weewx unit file and I can start it using

sudo systemctl start weewx

and that works  and I can stop it using...

sudo systemctl stop weewx

But weewx still will not start on a reboot.

I did the ....
sudo systemctl enable weewx

Jerry

--
You received this message because you are subscribed to a topic in the Google Groups "weewx-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/weewx-user/4tqBDJjpKuc/unsubscribe.
To unsubscribe from this group and all its topics, send an email to weewx-user+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[mwall]

On Wednesday, January 4, 2017 at 5:48:49 PM UTC-5, Jerry Deibel wrote:

mwall,

I tried the weewx unit file and I can start it using

sudo systemctl start weewx

and that works  and I can stop it using...

sudo systemctl stop weewx

But weewx still will not start on a reboot.

I did the ....
sudo systemctl enable weewx

Jerry

well, that is good news because it means that the rc scripts are not broken.

but it is bad news because it means we do not know what is causing weewx to not start up at system boot.

what does the log say on a fresh boot (not a restart)?

m

[Jerry Deibel]

Mwall,

Here is the log after a shutdown and start.    I started the log as soon as it booted,  but how does that tell up anything.

pi@raspberrypi:~ $ tail -f /var/log/syslog

Jan  4 18:33:31 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[655]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/index.bdmv

Jan  4 18:33:31 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[655]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/BACKUP/index.bdmv

Jan  4 18:33:31 raspberrypi ntpd_intres[533]: DNS 0.debian.pool.ntp.org -> 104.156.99.226

Jan  4 18:33:31 raspberrypi ntpd_intres[533]: DNS 1.debian.pool.ntp.org -> 138.68.2.126

Jan  4 18:33:31 raspberrypi ntpd_intres[533]: DNS 2.debian.pool.ntp.org -> 199.223.248.99

Jan  4 18:33:31 raspberrypi ntpd_intres[533]: DNS 3.debian.pool.ntp.org -> 108.59.2.24

Jan  4 18:33:36 raspberrypi dhcpcd[412]: eth0: no IPv6 Routers available

Jan  4 18:33:54 raspberrypi systemd[1]: Time has been changed

Jan  4 18:33:54 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Wed Jan  4 18:34:24 2017 [try http://www.rsyslog.com/e/2007 ]

jerry

[vince]

On Wednesday, January 4, 2017 at 2:54:33 PM UTC-8, mwall wrote:

On Wednesday, January 4, 2017 at 5:48:49 PM UTC-5, Jerry Deibel wrote:

But weewx still will not start on a reboot.

I did the ....
sudo systemctl enable weewx

Jerry

but it is bad news because it means we do not know what is causing weewx to not start up at system boot.

Just as a reference, I rebuilt a vagrant box with the setup.py install method and systemctl startup method and it 'does' start fine at boot.

Jerry - try a "systemctl status weewx" and see what it tells you....

[vince]

On Wednesday, January 4, 2017 at 3:39:35 PM UTC-8, Jerry Deibel wrote:

Mwall,

Here is the log after a shutdown and start.    I started the log as soon as it booted,  but how does that tell up anything.

pi@raspberrypi:~ $ tail -f /var/log/syslog

try "tail -n 300 -f /var/log/syslog" to go back 300 lines....

"tail -f" just shows you the lines from now forward, not stuff that happened before you typed the command 

[Jerry Deibel]

Mwall,

HERE is the log    at reboot time.    It shows unable to load driver   network unreachable.

I do have "Wait for network before booting "   set in Raspi-config

an  5 08:10:44 raspberrypi kernel: [    8.385107] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready

Jan  5 08:10:44 raspberrypi weewx[383]: engine: Initializing weewx version 3.6.2

Jan  5 08:10:44 raspberrypi weewx[383]: engine: Using Python 2.7.9 (default, Sep 17 2016, 20:26:04) #012[GCC 4.9.2]

Jan  5 08:10:44 raspberrypi weewx[383]: engine: Platform Linux-4.4.34-v7+-armv7l-with-debian-8.0

Jan  5 08:10:44 raspberrypi weewx[383]: engine: pid file is /var/run/weewx.pid

Jan  5 08:10:44 raspberrypi systemd[1]: weewx.service: Supervising process 504 which is not our child. We'll most likely not notice when it exits.

Jan  5 08:10:44 raspberrypi weewx[504]: engine: Using configuration file /home/weewx/weewx.conf

Jan  5 08:10:44 raspberrypi weewx[504]: engine: Loading station type ObserverIP (user.observerip)

Jan  5 08:10:44 raspberrypi weewx[504]: observerip: version is 0.5mw

Jan  5 08:10:44 raspberrypi weewx[504]: import of driver failed: [Errno 101] Network is unreachable (<class 'socket.error'>)

Jan  5 08:10:44 raspberrypi weewx[504]: engine: Unable to load driver: [Errno 101] Network is unreachable

Jan  5 08:10:44 raspberrypi weewx[504]:     ****  Exiting...

Jan  5 08:10:44 raspberrypi systemd[1]: weewx.service: main process exited, code=exited, status=4/NOPERMISSION

Jan  5 08:10:44 raspberrypi systemd[1]: Unit weewx.service entered failed state.

Jan  5 08:10:45 raspberrypi dhcpcd[382]: eth0: carrier acquired

Jerry

[Andrew Milner]

can you verify the config by

“sudo raspi-config nonint do_wait_for_network Slow” to make sure wait for network is set.  It sure looks as though the booting has continued without waiting for the network, unless specific access to a specific network node is required to obtain the driver - rather than just a network connection.

[Jerry Deibel]

When I ran....   " sudo raspi-config nonint do_wait_for_network Slow"

I get   ...       /usr/bin/raspi-config nonint do_wait_for_network Slow:  NOT FOUND

[Thomas Keffer]

Weewx forms a daemon by forking twice. I'm grasping here, but it's possible that systemd cannot follow this.

The forking can be suppressed by leaving out the --daemon command line option. Change weewx.service from this

[Service]
...ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf
...

to this

# systemd configuration to run a single instance of weewx as a daemon

[Unit]
Description=weewx weather system
Requires=time-sync.target
After=time-sync.target
RequiresMountsFor=/home

[Service]
ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf
ExecReload=/bin/kill -HUP $MAINPID
Type=simple
PIDFile=/var/run/weewx.pid
#User=weewx
#Group=weewx

[Install]
WantedBy=multi-user.target

--
You received this message because you are subscribed to the Google Groups "weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to weewx-user+unsubscribe@googlegroups.com.

[Thomas Keffer]

Dang it! That last email got away from me before I finished it. Here's the correct change. From this

# systemd configuration to run a single instance of weewx as a daemon

[Unit]
Description=weewx weather system
Requires=time-sync.target
After=time-sync.target
RequiresMountsFor=/home

[Service]
ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf
ExecReload=/bin/kill -HUP $MAINPID
Type=simple
PIDFile=/var/run/weewx.pid
#User=weewx
#Group=weewx

[Install]
WantedBy=multi-user.target

to this

# systemd configuration to run a single instance of weewx as a daemon

[Unit]
Description=weewx weather system
Requires=time-sync.target
After=time-sync.target
RequiresMountsFor=/home

[Service]
ExecStart=/home/weewx/bin/weewxd --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf
ExecReload=/bin/kill -HUP $MAINPID
Type=simple
PIDFile=/var/run/weewx.pid
#User=weewx
#Group=weewx

[Install]
WantedBy=multi-user.target

[Jerry Deibel]

Tom,
Taking out the --daemon in the weewx.service file did NOT work.

Jerry

On Wednesday, January 4, 2017 at 1:41:46 PM UTC-5, Jerry Deibel wrote:

[vince]

Your logfile is where it gets interesting:

Jan  5 08:10:44 raspberrypi weewx[504]: engine: Loading station type ObserverIP (user.observerip)

Jan  5 08:10:44 raspberrypi weewx[504]: observerip: version is 0.5mw

Jan  5 08:10:44 raspberrypi weewx[504]: import of driver failed: [Errno 101] Network is unreachable (<class 'socket.error'>)

Jan  5 08:10:44 raspberrypi weewx[504]: engine: Unable to load driver: [Errno 101] Network is unreachable

Jan  5 08:10:44 raspberrypi weewx[504]:     ****  Exiting...

My guess is you're trying to connect to a ip-based station before networking is up fully on your computer.   You are only posting a tiny snippet of your logfile, so we can't debug more than that really.

I brought up a vagrant VM in simulator mode and saw this interesting /var/log/messages stuff after a reboot:

Jan  5 16:39:46 jessie kernel: [    6.932995] EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro
Jan  5 16:39:46 jessie kernel: [    7.131961] snd_intel8x0 0000:00:05.0: intel8x0_measure_ac97_clock: measured 111338 usecs (4820 samples)
Jan  5 16:39:46 jessie kernel: [    7.131968] snd_intel8x0 0000:00:05.0: clocking to 53221
Jan  5 16:39:46 jessie kernel: [    7.133017] piix4_smbus 0000:00:07.0: SMBus Host Controller at 0x4100, revision 0
Jan  5 16:39:46 jessie kernel: [    7.248703] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
Jan  5 16:39:46 jessie kernel: [    7.249703] e1000: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
Jan  5 16:39:46 jessie kernel: [    7.250016] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
==> Jan  5 16:39:46 jessie kernel: [    7.338384] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
Jan  5 16:39:46 jessie kernel: [    7.348248] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jan  5 16:39:46 jessie kernel: [    7.348267] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Jan  5 16:39:46 jessie kernel: [    7.690252] RPC: Registered named UNIX socket transport module.
Jan  5 16:39:46 jessie kernel: [    7.690255] RPC: Registered udp transport module.
Jan  5 16:39:46 jessie kernel: [    7.690256] RPC: Registered tcp transport module.
Jan  5 16:39:46 jessie kernel: [    7.690257] RPC: Registered tcp NFSv4.1 backchannel transport module.
Jan  5 16:39:46 jessie kernel: [    7.693919] FS-Cache: Loaded
Jan  5 16:39:46 jessie kernel: [    7.700313] FS-Cache: Netfs 'nfs' registered for caching
Jan  5 16:39:46 jessie kernel: [    7.712848] Installing knfsd (copyright (C) 1996 ok...@monad.swb.de).
==> Jan  5 16:39:46 jessie weewx[469]: engine: Initializing weewx version 3.6.2
Jan  5 16:39:46 jessie weewx[469]: engine: Using Python 2.7.9 (default, Jun 29 2016, 13:08:31) #012[GCC 4.9.2]

Notice that eth0 comes up before weewx starts, but we're talking a fraction of a second here......might be a timing thing on the pi since its usb/wifi/ethernet subsystems are so slow.....

You can always kludge it with a "systemctl start weewx" in rc.local if you wanted to brute-force it,

[mwall]

so once again the root cause is that the network is not ready.

i thought that the following systemd unit file snippet should prevent this problem:

Requires=time-sync.target
After=time-sync.target

weewx should not start until time is synchronized, and time won't synchronize until the network is up and running.

perhaps there as a fake clock installed that is breaking everything?

m

[Andrew Milner]

Matthew

If you are saying that the above snippet (which I assume is standard) only works if the fake clock is disabled on rpi's then perhaps the install should attempt to explicitly unload/disable the fakehwclock, or at least make it clear to the user.  I've not checkd the docs before this post so may be out of order with my comment in which case I accept the slapped wrists ..... ouch!!

On Thursday, 5 January 2017 20:39:24 UTC+2, mwall wrote

[Jerry Deibel]

Here is the whole log after a shutdown..

pi@raspberrypi:~ $ tail -n 300 -f /var/log/syslog

Jan  5 14:25:12 raspberrypi kernel: [    3.376729] hid-generic 0003:046D:C534.0002: input,hiddev0,hidraw1: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-3f980000.usb-1.5/input1

Jan  5 14:25:12 raspberrypi kernel: [    4.040212] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer

Jan  5 14:25:12 raspberrypi kernel: [    4.048868] scsi 0:0:0:0: Direct-Access     Staples                   1.22 PQ: 0 ANSI: 5

Jan  5 14:25:12 raspberrypi kernel: [    4.051941] sd 0:0:0:0: [sda] 31266816 512-byte logical blocks: (16.0 GB/14.9 GiB)

Jan  5 14:25:12 raspberrypi kernel: [    4.053033] sd 0:0:0:0: [sda] Write Protect is off

Jan  5 14:25:12 raspberrypi kernel: [    4.053064] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00

Jan  5 14:25:12 raspberrypi kernel: [    4.054315] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA

Jan  5 14:25:12 raspberrypi kernel: [    4.068623]  sda: sda1

Jan  5 14:25:12 raspberrypi kernel: [    4.069425] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000

Jan  5 14:25:12 raspberrypi kernel: [    4.072594] sd 0:0:0:0: [sda] Attached SCSI removable disk

Jan  5 14:25:12 raspberrypi kernel: [    4.286709] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)

Jan  5 14:25:12 raspberrypi kernel: [    4.423882] sd 0:0:0:0: Attached scsi generic sg0 type 0

Jan  5 14:25:12 raspberrypi kernel: [    4.864447] random: nonblocking pool is initialized

Jan  5 14:25:12 raspberrypi kernel: [    7.823059] Adding 102396k swap on /var/swap.  Priority:-1 extents:3 across:208896k SSFS

Jan  5 14:25:12 raspberrypi kernel: [    7.840497] cfg80211: World regulatory domain updated:

Jan  5 14:25:12 raspberrypi kernel: [    7.840535] cfg80211:  DFS Master region: unset

Jan  5 14:25:12 raspberrypi kernel: [    7.840547] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)

Jan  5 14:25:12 raspberrypi kernel: [    7.840564] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)

Jan  5 14:25:12 raspberrypi kernel: [    7.840576] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)

Jan  5 14:25:12 raspberrypi kernel: [    7.840587] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)

Jan  5 14:25:12 raspberrypi kernel: [    7.840601] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)

Jan  5 14:25:12 raspberrypi kernel: [    7.840614] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)

Jan  5 14:25:12 raspberrypi kernel: [    7.840625] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)

Jan  5 14:25:12 raspberrypi kernel: [    7.840636] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)

Jan  5 14:25:12 raspberrypi systemd-modules-load[110]: Inserted module 'i2c_dev'

Jan  5 14:25:12 raspberrypi kernel: [    7.840647] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Create Static Device Nodes in /dev...

Jan  5 14:25:12 raspberrypi systemd[1]: Mounted FUSE Control File System.

Jan  5 14:25:12 raspberrypi systemd[1]: Mounted Configuration File System.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Apply Kernel Variables.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Create Static Device Nodes in /dev.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting udev Kernel Device Manager...

Jan  5 14:25:12 raspberrypi systemd[1]: Started udev Kernel Device Manager.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Copy rules generated while the root was ro...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Set preliminary keymap...

Jan  5 14:25:12 raspberrypi systemd-fsck[100]: e2fsck 1.42.12 (29-Aug-2014)

Jan  5 14:25:12 raspberrypi systemd-fsck[100]: /dev/mmcblk0p2: clean, 137661/470112 files, 1101783/1923328 blocks

Jan  5 14:25:12 raspberrypi fake-hwclock[102]: Thu  5 Jan 19:25:07 UTC 2017

Jan  5 14:25:12 raspberrypi systemd-udevd[184]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3 1 4': No such file or directory

Jan  5 14:25:12 raspberrypi keyboard-setup[143]: Setting preliminary keymap...done.

Jan  5 14:25:12 raspberrypi systemd-udevd[199]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3 1 4': No such file or directory

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Set preliminary keymap.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Show Plymouth Boot Screen...

Jan  5 14:25:12 raspberrypi systemd-udevd[202]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1 1 3': No such file or directory

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Remount Root and Kernel File Systems...

Jan  5 14:25:12 raspberrypi systemd[1]: Found device /dev/ttyAMA0.

Jan  5 14:25:12 raspberrypi systemd[1]: Found device /dev/mmcblk0p1.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Remount Root and Kernel File Systems.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Various fixups to make systemd work better on Debian.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Load/Save Random Seed...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Local File Systems (Pre).

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Local File Systems (Pre).

Jan  5 14:25:12 raspberrypi systemd[1]: Starting File System Check on /dev/mmcblk0p1...

Jan  5 14:25:12 raspberrypi systemd-udevd[224]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5 1 5': No such file or directory

Jan  5 14:25:12 raspberrypi systemd[1]: Started Load/Save Random Seed.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Sound Card.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Sound Card.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Show Plymouth Boot Screen.

Jan  5 14:25:12 raspberrypi systemd-fsck[213]: fsck.fat 3.0.27 (2014-11-12)

Jan  5 14:25:12 raspberrypi systemd-fsck[213]: /dev/mmcblk0p1: 119 files, 2659/8057 clusters

Jan  5 14:25:12 raspberrypi systemd[1]: Started File System Check on /dev/mmcblk0p1.

Jan  5 14:25:12 raspberrypi systemd[1]: Mounting /boot...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Forward Password Requests to Plymouth Directory Watch.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Dispatch Password Requests to Console Directory Watch.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Paths.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Paths.

Jan  5 14:25:12 raspberrypi systemd[1]: Mounted /boot.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Local File Systems.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Local File Systems.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Create Volatile Files and Directories...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Remote File Systems.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Remote File Systems.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Prepare console...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Raise network interfaces....

Jan  5 14:25:12 raspberrypi systemd[1]: Started Tell Plymouth To Write Out Runtime Data.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Create Volatile Files and Directories.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.

Jan  5 14:25:12 raspberrypi kbd[239]: Setting console screen modes.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Update UTMP about System Boot/Shutdown...

Jan  5 14:25:12 raspberrypi kbd[239]: setterm: $TERM is not defined.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Update UTMP about System Boot/Shutdown.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Prepare console.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Set console font and keymap...

Jan  5 14:25:12 raspberrypi console-setup[290]: Setting up console font and keymap...done.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Set console font and keymap.

Jan  5 14:25:12 raspberrypi raspi-config[241]: Checking if shift key is held down: No. Switching to ondemand scaling governor.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).

Jan  5 14:25:12 raspberrypi systemd[1]: Received SIGRTMIN+20 from PID 211 (plymouthd).

Jan  5 14:25:12 raspberrypi networking[242]: Configuring network interfaces...done.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Raise network interfaces..

Jan  5 14:25:12 raspberrypi systemd[1]: Starting System Initialization.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target System Initialization.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack Activation Socket.

Jan  5 14:25:12 raspberrypi systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting D-Bus System Message Bus Socket.

Jan  5 14:25:12 raspberrypi systemd[1]: Listening on D-Bus System Message Bus Socket.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Sockets.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Sockets.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Daily Cleanup of Temporary Directories.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Daily Cleanup of Temporary Directories.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Timers.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Timers.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Manage Sound Card State (restore and store).

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Restore Sound Card State...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Basic System.

Jan  5 14:25:12 raspberrypi systemd[1]: Reached target Basic System.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Regular background program processing daemon...

Jan  5 14:25:12 raspberrypi systemd[1]: Started Regular background program processing daemon.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Turn on SSH if /boot/ssh is present.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting weewx weather system...

Jan  5 14:25:12 raspberrypi systemd[1]: Started weewx weather system.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.

Jan  5 14:25:12 raspberrypi systemd[1]: Started getty on tty2-tty6 if dbus and logind are not available.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Login Service...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: Autogenerate and use a swap file...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting LSB: triggerhappy hotkey daemon...

Jan  5 14:25:12 raspberrypi cron[381]: (CRON) INFO (pidfile fd = 3)

Jan  5 14:25:12 raspberrypi dhcpcd[382]: version 6.7.1 starting

Jan  5 14:25:12 raspberrypi dhcpcd[382]: dev: loaded udev

Jan  5 14:25:12 raspberrypi cron[381]: (CRON) INFO (Running @reboot jobs)

Jan  5 14:25:12 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...

Jan  5 14:25:12 raspberrypi systemd[1]: Starting D-Bus System Message Bus...

Jan  5 14:25:12 raspberrypi systemd[1]: Started D-Bus System Message Bus.

Jan  5 14:25:12 raspberrypi dphys-swapfile[385]: Starting dphys-swapfile swapfile setup ...

Jan  5 14:25:12 raspberrypi dhcpcd[382]: eth0: adding address fe80::1755:e9c3:287:d231

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Found user 'avahi' (UID 105) and group 'avahi' (GID 110).

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Successfully dropped root privileges.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: avahi-daemon 0.6.31 starting up.

Jan  5 14:25:12 raspberrypi dphys-swapfile[385]: want /var/swap=100MByte, checking existing: keeping it

Jan  5 14:25:12 raspberrypi dphys-swapfile[385]: done.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Successfully called chroot().

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Successfully dropped remaining capabilities.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: No service file found in /etc/avahi/services.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Network interface enumeration completed.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Registering HINFO record with values 'ARMV7L'/'LINUX'.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 1510790271.

Jan  5 14:25:12 raspberrypi dbus[391]: [system] Successfully activated service 'org.freedesktop.systemd1'

Jan  5 14:25:12 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.

Jan  5 14:25:12 raspberrypi systemd[1]: Starting System Logging Service...

Jan  5 14:25:12 raspberrypi systemd[1]: Started Restore Sound Card State.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: Autogenerate and use a swap file.

Jan  5 14:25:12 raspberrypi systemd[1]: Started LSB: triggerhappy hotkey daemon.

Jan  5 14:25:12 raspberrypi systemd[1]: Started Login Service.

Jan  5 14:25:12 raspberrypi systemd[1]: Started System Logging Service.

Jan  5 14:25:12 raspberrypi kernel: [    8.304912] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::1755:e9c3:287:d231.

Jan  5 14:25:12 raspberrypi kernel: [    8.305565] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: New relevant interface eth0.IPv6 for mDNS.

Jan  5 14:25:12 raspberrypi avahi-daemon[390]: Registering new address record for fe80::1755:e9c3:287:d231 on eth0.*.

Jan  5 14:25:12 raspberrypi dhcpcd[382]: eth0: waiting for carrier

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Initializing weewx version 3.6.2

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Using Python 2.7.9 (default, Sep 17 2016, 20:26:04) #012[GCC 4.9.2]

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Platform Linux-4.4.34-v7+-armv7l-with-debian-8.0

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Using configuration file /home/weewx/weewx.conf

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Loading station type ObserverIP (user.observerip)

Jan  5 14:25:12 raspberrypi weewx[383]: observerip: version is 0.5mw

Jan  5 14:25:12 raspberrypi weewx[383]: import of driver failed: [Errno 101] Network is unreachable (<class 'socket.error'>)

Jan  5 14:25:12 raspberrypi weewx[383]: engine: Unable to load driver: [Errno 101] Network is unreachable

Jan  5 14:25:12 raspberrypi weewx[383]:     ****  Exiting...

Jan  5 14:25:12 raspberrypi systemd[1]: weewx.service: main process exited, code=exited, status=4/NOPERMISSION

Jan  5 14:25:12 raspberrypi systemd[1]: Unit weewx.service entered failed state.

Jan  5 14:25:13 raspberrypi kernel: [    9.860171] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

Jan  5 14:25:13 raspberrypi kernel: [    9.861171] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1

Jan  5 14:25:13 raspberrypi dhcpcd[382]: eth0: carrier acquired

Jan  5 14:25:13 raspberrypi dhcpcd[382]: DUID 00:01:00:01:1f:cb:4b:30:40:a5:ef:07:14:6e

Jan  5 14:25:13 raspberrypi dhcpcd[382]: eth0: IAID eb:51:80:a6

Jan  5 14:25:14 raspberrypi dhcpcd[382]: eth0: rebinding lease of 192.168.0.23

Jan  5 14:25:14 raspberrypi dhcpcd[382]: eth0: soliciting an IPv6 router

Jan  5 14:25:19 raspberrypi dhcpcd[382]: eth0: leased 192.168.0.23 for 3600 seconds

Jan  5 14:25:19 raspberrypi dhcpcd[382]: eth0: adding route to 192.168.0.0/24

Jan  5 14:25:19 raspberrypi dhcpcd[382]: eth0: adding default route via 192.168.0.1

Jan  5 14:25:19 raspberrypi avahi-daemon[390]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.23.

Jan  5 14:25:19 raspberrypi avahi-daemon[390]: New relevant interface eth0.IPv4 for mDNS.

Jan  5 14:25:19 raspberrypi avahi-daemon[390]: Registering new address record for 192.168.0.23 on eth0.IPv4.

Jan  5 14:25:19 raspberrypi dhcpcd[382]: forked to background, child pid 588

Jan  5 14:25:19 raspberrypi systemd[1]: Started dhcpcd on all interfaces.

Jan  5 14:25:19 raspberrypi systemd[1]: Starting Network.

Jan  5 14:25:19 raspberrypi systemd[1]: Reached target Network.

Jan  5 14:25:19 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...

Jan  5 14:25:19 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.

Jan  5 14:25:19 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...

Jan  5 14:25:19 raspberrypi systemd[1]: Starting Network is Online.

Jan  5 14:25:19 raspberrypi systemd[1]: Reached target Network is Online.

Jan  5 14:25:19 raspberrypi systemd[1]: Starting LSB: Start NTP daemon...

Jan  5 14:25:19 raspberrypi systemd[1]: Starting Permit User Sessions...

Jan  5 14:25:19 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.

Jan  5 14:25:19 raspberrypi systemd[1]: Started Permit User Sessions.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Light Display Manager...

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Hold until boot process finishes up...

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Terminate Plymouth Boot Screen...

Jan  5 14:25:20 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 211 (plymouthd).

Jan  5 14:25:20 raspberrypi systemd[1]: Started Terminate Plymouth Boot Screen.

Jan  5 14:25:20 raspberrypi systemd[1]: Started Hold until boot process finishes up.

Jan  5 14:25:20 raspberrypi ntpd[610]: ntpd 4.2...@1.2349-o Mon Jul 25 22:35:28 UTC 2016 (1)

Jan  5 14:25:20 raspberrypi ntp[591]: Starting NTP server: ntpd.

Jan  5 14:25:20 raspberrypi ntpd[614]: proto: precision = 0.781 usec

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123

Jan  5 14:25:20 raspberrypi systemd[1]: Started LSB: Start NTP daemon.

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen and drop on 1 v6wildcard :: UDP 123

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen normally on 2 lo 127.0.0.1 UDP 123

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen normally on 3 eth0 192.168.0.23 UDP 123

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen normally on 4 lo ::1 UDP 123

Jan  5 14:25:20 raspberrypi ntpd[614]: Listen normally on 5 eth0 fe80::1755:e9c3:287:d231 UDP 123

Jan  5 14:25:20 raspberrypi ntpd[614]: peers refreshed

Jan  5 14:25:20 raspberrypi ntpd[614]: Listening on routing socket on fd #22 for interface updates

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Getty on tty1...

Jan  5 14:25:20 raspberrypi systemd[1]: Started Getty on tty1.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Serial Getty on ttyAMA0...

Jan  5 14:25:20 raspberrypi systemd[1]: Started Serial Getty on ttyAMA0.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Login Prompts.

Jan  5 14:25:20 raspberrypi systemd[1]: Reached target Login Prompts.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Multi-User System.

Jan  5 14:25:20 raspberrypi systemd[1]: Reached target Multi-User System.

Jan  5 14:25:20 raspberrypi lightdm[609]: ** (lightdm:609): WARNING **: 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

Jan  5 14:25:20 raspberrypi systemd[1]: Started Light Display Manager.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Graphical Interface.

Jan  5 14:25:20 raspberrypi systemd[1]: Reached target Graphical Interface.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...

Jan  5 14:25:20 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.

Jan  5 14:25:20 raspberrypi systemd[1]: Startup finished in 2.187s (kernel) + 14.492s (userspace) = 16.680s.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting user-1000.slice.

Jan  5 14:25:20 raspberrypi systemd[1]: Created slice user-1000.slice.

Jan  5 14:25:20 raspberrypi systemd[1]: Starting User Manager for UID 1000...

Jan  5 14:25:20 raspberrypi systemd[1]: Starting Session c1 of user pi.

Jan  5 14:25:20 raspberrypi systemd[1]: Started Session c1 of user pi.

Jan  5 14:25:21 raspberrypi systemd[632]: Starting Paths.

Jan  5 14:25:21 raspberrypi systemd[632]: Reached target Paths.

Jan  5 14:25:21 raspberrypi systemd[632]: Starting Timers.

Jan  5 14:25:21 raspberrypi systemd[632]: Reached target Timers.

Jan  5 14:25:21 raspberrypi systemd[632]: Starting Sockets.

Jan  5 14:25:21 raspberrypi systemd[632]: Reached target Sockets.

Jan  5 14:25:21 raspberrypi systemd[632]: Starting Basic System.

Jan  5 14:25:21 raspberrypi systemd[632]: Reached target Basic System.

Jan  5 14:25:21 raspberrypi systemd[632]: Starting Default.

Jan  5 14:25:21 raspberrypi systemd[632]: Reached target Default.

Jan  5 14:25:21 raspberrypi systemd[632]: Startup finished in 87ms.

Jan  5 14:25:21 raspberrypi systemd[1]: Started User Manager for UID 1000.

Jan  5 14:25:22 raspberrypi lightdm[609]: ** (process:678): WARNING **: 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

Jan  5 14:25:22 raspberrypi systemd[1]: Starting Session c2 of user pi.

Jan  5 14:25:22 raspberrypi systemd[1]: Started Session c2 of user pi.

Jan  5 14:25:24 raspberrypi dbus[391]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkitd.service'

Jan  5 14:25:24 raspberrypi systemd[1]: Starting Authenticate and Authorize Users to Run Privileged Tasks...

Jan  5 14:25:24 raspberrypi polkitd[774]: started daemon version 0.105 using authority implementation `local' version `0.105'

Jan  5 14:25:24 raspberrypi dbus[391]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'

Jan  5 14:25:24 raspberrypi systemd[1]: Started Authenticate and Authorize Users to Run Privileged Tasks.

Jan  5 14:25:25 raspberrypi dbus[391]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service'

Jan  5 14:25:25 raspberrypi systemd[1]: Starting RealtimeKit Scheduling Policy Service...

Jan  5 14:25:25 raspberrypi dbus[391]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service'

Jan  5 14:25:25 raspberrypi systemd[1]: Starting Disk Manager...

Jan  5 14:25:25 raspberrypi dbus[391]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'

Jan  5 14:25:25 raspberrypi systemd[1]: Started RealtimeKit Scheduling Policy Service.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Successfully called chroot.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Successfully dropped privileges.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Successfully limited resources.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Watchdog thread running.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Running.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Canary thread running.

Jan  5 14:25:25 raspberrypi udisksd[812]: udisks daemon version 2.1.3 starting

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Successfully made thread 809 of process 809 (/usr/bin/pulseaudio) owned by '1000' high priority at nice level -11.

Jan  5 14:25:25 raspberrypi rtkit-daemon[810]: Supervising 1 threads of 1 processes of 1 users.

Jan  5 14:25:25 raspberrypi dbus[391]: [system] Successfully activated service 'org.freedesktop.UDisks2'

Jan  5 14:25:25 raspberrypi udisksd[812]: Acquired the name org.freedesktop.UDisks2 on the system message bus

Jan  5 14:25:25 raspberrypi systemd[1]: Started Disk Manager.

Jan  5 14:25:25 raspberrypi udisksd[812]: Cleaning up mount point /media/pi/rootfs (device 8:1 is not mounted)

Jan  5 14:25:25 raspberrypi dbus[391]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service'

Jan  5 14:25:25 raspberrypi systemd[1]: Starting Bluetooth service...

Jan  5 14:25:26 raspberrypi bluetoothd[824]: Bluetooth daemon 5.23

Jan  5 14:25:26 raspberrypi dbus[391]: [system] Successfully activated service 'org.bluez'

Jan  5 14:25:26 raspberrypi systemd[1]: Started Bluetooth service.

Jan  5 14:25:26 raspberrypi kernel: [   22.290203] Bluetooth: Core ver 2.21

Jan  5 14:25:26 raspberrypi kernel: [   22.290791] NET: Registered protocol family 31

Jan  5 14:25:26 raspberrypi kernel: [   22.290808] Bluetooth: HCI device and connection manager initialized

Jan  5 14:25:26 raspberrypi kernel: [   22.290838] Bluetooth: HCI socket layer initialized

Jan  5 14:25:26 raspberrypi kernel: [   22.290855] Bluetooth: L2CAP socket layer initialized

Jan  5 14:25:26 raspberrypi kernel: [   22.290896] Bluetooth: SCO socket layer initialized

Jan  5 14:25:26 raspberrypi bluetoothd[824]: Starting SDP server

Jan  5 14:25:26 raspberrypi kernel: [   22.382274] Bluetooth: BNEP (Ethernet Emulation) ver 1.3

Jan  5 14:25:26 raspberrypi kernel: [   22.382312] Bluetooth: BNEP filters: protocol multicast

Jan  5 14:25:26 raspberrypi kernel: [   22.382347] Bluetooth: BNEP socket layer initialized

Jan  5 14:25:26 raspberrypi dbus[391]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'

Jan  5 14:25:26 raspberrypi bluetoothd[824]: Bluetooth management interface 1.10 initialized

Jan  5 14:25:26 raspberrypi systemd[1]: Starting Hostname Service...

Jan  5 14:25:26 raspberrypi pulseaudio[809]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist

Jan  5 14:25:26 raspberrypi pulseaudio[809]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist

Jan  5 14:25:26 raspberrypi systemd-hostnamed[836]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname!

Jan  5 14:25:26 raspberrypi dbus[391]: [system] Successfully activated service 'org.freedesktop.hostname1'

Jan  5 14:25:26 raspberrypi systemd[1]: Started Hostname Service.

Jan  5 14:25:26 raspberrypi org.gtk.Private.AfcVolumeMonitor[735]: Volume monitor alive

Jan  5 14:25:27 raspberrypi dhcpcd[588]: eth0: no IPv6 Routers available

Jan  5 14:26:35 raspberrypi systemd[632]: Time has been changed

Jan  5 14:26:35 raspberrypi systemd[1]: Time has been changed

Jan  5 14:26:37 raspberrypi kernel: [   25.623732] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)

Jan  5 14:26:37 raspberrypi udisksd[812]: Mounted /dev/sda1 at /media/pi/rootfs on behalf of uid 1000

Jan  5 14:26:37 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[735]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/index.bdmv

Jan  5 14:26:37 raspberrypi org.gtk.Private.UDisks2VolumeMonitor[735]: index_parse.c:191: indx_parse(): error opening /media/pi/rootfs/BDMV/BACKUP/index.bdmv

On Wednesday, January 4, 2017 at 1:41:46 PM UTC-5, Jerry Deibel wrote:

[mwall]

On Thursday, January 5, 2017 at 2:31:46 PM UTC-5, Jerry Deibel wrote:

Here is the whole log after a shutdown..

jerry,

according to the log, weewx is starting up well before the network has been configured.

so if you want to fix the problem, you'll have to do some systemd research to figure out the magic incantations to put in the unit file.  you could try adding network-target to the 'Requires' and/or 'After' items.

if you want to work around the problem, set loop_on_init in weewx.conf:

loop_on_init=True

this will make weewx keep trying to start up, no matter what the operating system is doing.

m

(where is the official list of systemd targets that works across distributions?  every program has incantations, they just tend to be 'magic' for those who do not know them, or they are *all* magic if the grammar is really whacked, or if the software is poorly documented, or if the developers are arrogant, or if the software is too advanced for its time :)  trying to not be a pot calling out the kettle...)

[vince]

On Thursday, January 5, 2017 at 12:12:04 PM UTC-8, mwall wrote:

On Thursday, January 5, 2017 at 2:31:46 PM UTC-5, Jerry Deibel wrote:

Here is the whole log after a shutdown..

(where is the official list of systemd targets that works across distributions?  every program has incantations, they just tend to be 'magic' for those who do not know them, or they are *all* magic if the grammar is really whacked, or if the software is poorly documented, or if the developers are arrogant, or if the software is too advanced for its time :)  trying to not be a pot calling out the kettle...)

Years ago you'd have a more hellish upstart or sysVinit set of logic, so I wouldn't sweat this one too much.

Setting loop_on_init is a reasonable workaround for this one, as would be a quick FAQ or wiki one-paragraph writeup.

That said, it would be pretty interesting to hear from weewx on pi users (wired and wireless, pi3 and older ones) what their timings look like.  It might just be that this one network is slow providing DHCP addresses (in which case switching to a static address might be a good non-weewx way for this end case).

[Jerry Deibel]

Thanks to everyone for their help.   What puzzles me is that I am using the same Raspberry Pi (2) that I have been using for 2 years...
Of course, when my USB went south I had to reload the raspberry pi op system...   The last 2 years I have been using the Jessie raspberry pi OP system and I now I am using the same OP system.. ( maybe different version after 2 years). I download the current version of  Weewx   and the  obseverip driver.   I did not have a problem the last 2 years on weeew started up after a shutdown.. ( its been done more than a few times this past 2 years.   
I will now start from scratch and reload the raspberry pi and weewx and see if the problem goes away...
Will post back on the result.
Jerry

[Thomas Keffer]

Jerry, could you give me the result of the commands

uname -a

and

cat /etc/*-release

I'd like to try and reproduce your results.

-tk

[Jerry Deibel]

tk

pi@raspberrypi:~ $ uname -a

Linux raspberrypi 4.4.34-v7+ #930 SMP Wed Nov 23 15:20:41 GMT 2016 armv7l GNU/Linux

and

pi@raspberrypi:~ $ cat /etc/*-release

PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)"

NAME="Raspbian GNU/Linux"

VERSION_ID="8"

VERSION="8 (jessie)"

ID=raspbian

ID_LIKE=debian

HOME_URL="http://www.raspbian.org/"

SUPPORT_URL="http://www.raspbian.org/RaspbianForums"

BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

Jerry

On Wednesday, January 4, 2017 at 1:41:46 PM UTC-5, Jerry Deibel wrote:

[Thomas Keffer]

OK, I have an RPi2 with a pretty close configuration (kernel 4.4.26 instead of 4.4.34), which I can try this on.

-tk

[vince]

On Thursday, January 5, 2017 at 3:48:40 PM UTC-8, Tom Keffer wrote:

OK, I have an RPi2 with a pretty close configuration (kernel 4.4.26 instead of 4.4.34), which I can try this on.

Not a problem here on a pi3 here using its onboard wifi:

• clean raspbian lite from Nov-2016 reflashed on fast class-10 SD card
• weewx 3.6.2 installed via setup.py, running in Simulator mode with debug=1
• nginx installed as the webserver

The wlan0 interface was up a number of seconds before weewx started its sequence.  Started just fine.

[Jerry Deibel]

Ok,   It is now working both on restart and shutdown.

It was the SD card.   Last week when I re-installed the pi software and weewx on the SD card (remember before I was running with a USB stick and that went bad.)
I have 2 pi's, one was a spare, so last week after the reinstall I made a image copy to the other  SD card.  ( I don't know which SD card I was using this past year with the USB stick)
Well one SD card  was a sandisk 8g and the other was  sandisk 8g ULTRA.
I was using the regular SD card which  was causing the boot up problem.

Today I  put the ULTRA SD card in the pi and  the first boot did not work.
But then I removed the rc script and used systemctl that Mwall gave me a few days ago and that did the trick.

Thanks to everyone for their help.

Jerry

On Wednesday, January 4, 2017 at 1:41:46 PM UTC-5, Jerry Deibel wrote: