Autostart WeeWX with systemd
1,223 views
Skip to first unread message
David Porter
Aug 23, 2017, 6:27:32 AM8/23/17
to weewx-user
I am attempting to use systemd on a Raspberry Pi 3 (Jessie) to autostart WeeWX. The goal being that WeeWX will automatically start up and start recording data and sending it to Wunderground after a reboot (e.g following a blackout).
Here is my /etc/systemd/system/weewx.service file:
# systemd configuration to run a single instance of weewx as a daemon[Unit]Description=weewx weather systemRequires=time-sync.targetAfter=time-sync.targetRequiresMountsFor=/home[Service]ExecStart=/usr/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /etc/weewx/weewx.confExecReload=/bin/kill -HUP $MAINPIDType=simplePIDFile=/var/run/weewx.pid#User=weewx#Group=weewx[Install]WantedBy=multi-user.target
That .service file runs fine at start up. The terminal command "systemctl is-enabled weewx" returns "enabled". The terminal command "systemctl is-active weewx" returns "failed". That is, WeeWX has been enable, but is not active.
I can then manually start WeeWX with "systemctl start weewx" and everything works fine. But I want to automate this manual step on the RPi boot up.
How do I get "systemctl start weewx" to run automatically at boot up?
Andrew Milner
Aug 23, 2017, 6:35:06 AM8/23/17
to weewx-user
Andrew Milner
Aug 23, 2017, 6:41:21 AM8/23/17
to weewx-user
have you checked that a) weewx is not waiting for a valid time and b) the designated user has write access to required directories snd databases.
and finally c) what does the log say??
vince
Aug 23, 2017, 11:08:59 AM8/23/17
to weewx-user
How do I get "systemctl start weewx" to run automatically at boot up?
Adding to Andrew's "is your clock configured right" thinking....
- is ntp running ? Do a 'ntpq -pn' and verify you're synched with the upstream clock servers
- if so, do a reboot (not powerdown/up) of your system and see if it works..... I'm guesing it will
- then do a shutdown and pull the power for a few minutes and try it again and see if it fails or works, to redo your power loss scenario
And please set debug=1 in weewx.conf and post the syslog from powerup to when weewx runs (or doesn't) in the last test...
vk3...@gmail.com
Aug 23, 2017, 10:32:56 PM8/23/17
to weewx-user
If you are trying to use the network to send to WeatherUnderground, then you may need to wait for it to start as well.
Something like:
Requires=Network-online.target
After=Network-online.target
if I remember correctly.
Susan
vk3...@gmail.com
Aug 23, 2017, 10:34:08 PM8/23/17
to weewx-user
Sorry - I didn't mean to make the 'N' a capital but I'm not sure if it matters.
Susan
David Porter
Aug 24, 2017, 2:42:05 AM8/24/17
to weewx-user
Thanks for the suggestions. The githib instructions for WeeWX/systemd was where I started.
ntpq -pn returns "command not found". However, time is being updated from an ntp server: see syslog entry at Aug 24 16:16:18 below.
I have pasted below that part of my syslog file following a "reboot" command given at Aug 24 16:15:19. I have changed the weewx.conf debug option to 1 (on). You can see the whole reboot sequence in the syslog file from 16:15:09 to 16:16:18. I then manually typed "sudo systemctl start weewx" at Aug 24 16:19:09.
There are no obvious error messages in the syslog (or at least, none I can see). "sudo systemctl start weewx" works fine when I manually type it into the terminal. But I'm still at a loss how to automate that command.
/var/log/syslog dump
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping User Manager for UID 1000...
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Session c2 of user pi.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped target Sound Card.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped target Bluetooth.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped target Timers.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Authorization Manager...
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped Daily apt upgrade and clean activities.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped Daily apt download activities.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Save/Restore Sound Card State...
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Session c1 of user pi.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped target Graphical Interface.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Light Display Manager...
Aug 24 16:15:19 raspberrypi systemd[1]: Stopped Trigger anacron every hour.
Aug 24 16:15:19 raspberrypi systemd[1]: Stopping Disk Manager...
Aug 24 16:15:26 raspberrypi systemd-modules-load[116]: Inserted module 'i2c_dev'
Aug 24 16:15:26 raspberrypi systemd-fsck[119]: e2fsck 1.43.4 (31-Jan-2017)
Aug 24 16:15:26 raspberrypi systemd-fsck[119]: root0: clean, 169411/881280 files, 1305187/3521280 blocks
Aug 24 16:15:26 raspberrypi systemd[1]: Started Remount Root and Kernel File Systems.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Apply Kernel Variables.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Load/Save Random Seed...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting udev Coldplug all Devices...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Flush Journal to Persistent Storage...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Create Static Device Nodes in /dev.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting udev Kernel Device Manager...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Load/Save Random Seed.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Flush Journal to Persistent Storage.
Aug 24 16:15:26 raspberrypi systemd[1]: Started udev Kernel Device Manager.
Aug 24 16:15:26 raspberrypi systemd[1]: Started udev Coldplug all Devices.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Set the console keyboard layout.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Show Plymouth Boot Screen...
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Local File Systems (Pre).
Aug 24 16:15:26 raspberrypi systemd[1]: Started Show Plymouth Boot Screen.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Paths.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Encrypted Volumes.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
Aug 24 16:15:26 raspberrypi systemd[1]: Found device /dev/serial1.
Aug 24 16:15:26 raspberrypi mtp-probe: checking bus 1, device 3: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1"
Aug 24 16:15:26 raspberrypi mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4"
Aug 24 16:15:26 raspberrypi mtp-probe: bus: 1, device: 4 was not an MTP device
Aug 24 16:15:26 raspberrypi mtp-probe: bus: 1, device: 3 was not an MTP device
Aug 24 16:15:26 raspberrypi systemd[1]: Found device /dev/mmcblk0p6.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting File System Check on /dev/mmcblk0p6...
Aug 24 16:15:26 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Sound Card.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Aug 24 16:15:26 raspberrypi systemd-udevd[160]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Aug 24 16:15:26 raspberrypi systemd-udevd[166]: Process '/usr/lib/raspberrypi-sys-mods/rfkill-persist' failed with exit code 1.
Aug 24 16:15:26 raspberrypi systemd-fsck[237]: fsck.fat 4.1 (2017-01-24)
Aug 24 16:15:26 raspberrypi systemd-fsck[237]: /dev/mmcblk0p6: 145 files, 42945/139106 clusters
Aug 24 16:15:26 raspberrypi systemd[1]: Started File System Check on /dev/mmcblk0p6.
Aug 24 16:15:26 raspberrypi systemd[1]: Mounting /boot...
Aug 24 16:15:26 raspberrypi systemd[1]: Mounted /boot.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Local File Systems.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Set console font and keymap...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Preprocess NFS configuration...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Raise network interfaces...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Create Volatile Files and Directories...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Set console font and keymap.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Preprocess NFS configuration.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Tell Plymouth To Write Out Runtime Data.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target NFS client services.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Remote File Systems (Pre).
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Remote File Systems.
Aug 24 16:15:26 raspberrypi systemd-udevd[174]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Aug 24 16:15:26 raspberrypi systemd-udevd[164]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Aug 24 16:15:26 raspberrypi systemd-udevd[169]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Create Volatile Files and Directories.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Network Time Synchronization...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Update UTMP about System Boot/Shutdown.
Aug 24 16:15:26 raspberrypi systemd-timesyncd[294]: System clock time unset or jumped backwards, restoring from recorded timestamp: Thu 2017-08-24 16:15:26 AEST
Aug 24 16:15:26 raspberrypi systemd[1]: Time has been changed
Aug 24 16:15:26 raspberrypi systemd[1]: Started Network Time Synchronization.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target System Initialization.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Daily Cleanup of Temporary Directories.
Aug 24 16:15:26 raspberrypi systemd[1]: Listening on D-Bus System Message Bus Socket.
Aug 24 16:15:26 raspberrypi systemd[1]: Listening on triggerhappy.socket.
Aug 24 16:15:26 raspberrypi systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Sockets.
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target Basic System.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Configure Bluetooth Modems connected by UART...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting triggerhappy global hotkey daemon...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting LSB: Autogenerate and use a swap file...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Login Service...
Aug 24 16:15:26 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Aug 24 16:15:26 raspberrypi thd[318]: Found socket passed from systemd
Aug 24 16:15:26 raspberrypi dhcpcd[320]: forked to background, child pid 332
Aug 24 16:15:26 raspberrypi dbus[323]: [system] Successfully activated service 'org.freedesktop.systemd1'
Aug 24 16:15:26 raspberrypi systemd[1]: Starting LSB: Starts and stops Wicd...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting System Logging Service...
Aug 24 16:15:26 raspberrypi systemd[1]: Started Deferred execution scheduler.
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Check for v3d driver...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Aug 24 16:15:26 raspberrypi systemd[1]: Starting Save/Restore Sound Card State...
Aug 24 16:15:26 raspberrypi systemd[1]: Reached target System Time Synchronized.
Aug 24 16:15:26 raspberrypi systemd[1]: Started weewx weather system.
Aug 24 16:15:26 raspberrypi systemd[1]: anacron.timer: Adding 4min 16.638477s random time.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Trigger anacron every hour.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Run anacron jobs.
Aug 24 16:15:26 raspberrypi systemd[1]: anacron.timer: Adding 1min 1.352906s random time.
Aug 24 16:15:26 raspberrypi systemd[1]: anacron.timer: Adding 3min 44.937518s random time.
Aug 24 16:15:26 raspberrypi anacron[361]: Anacron 2.3 started on 2017-08-24
Aug 24 16:15:26 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Aug 24 16:15:26 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Aug 24 16:15:26 raspberrypi anacron[361]: Normal exit (0 jobs run)
Aug 24 16:15:26 raspberrypi dhcpcd-run-hooks[363]: wlan0: starting wpa_supplicant
Aug 24 16:15:26 raspberrypi systemd[1]: anacron.timer: Adding 3min 34.493990s random time.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Check for v3d driver.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Login Service.
Aug 24 16:15:26 raspberrypi liblogging-stdlog: [origin software="rsyslogd" swVersion="8.24.0" x-pid="346" x-info="http://www.rsyslog.com"] start
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Booting Linux on physical CPU 0x0
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Linux version 4.9.41-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1023 SMP Tue Aug 8 16:00:15 BST 2017
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] CPU: div instructions available: patching division code
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] OF: fdt:Machine model: Raspberry Pi 3 Model B Rev 1.2
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] cma: Reserved 8 MiB at 0x3a800000
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Memory policy: Data cache writealloc
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] On node 0 totalpages: 241664
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] free_area_init_node: node 0, pgdat 80c6eec0, node_mem_map b9faa000
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Normal zone: 2124 pages used for memmap
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Normal zone: 0 pages reserved
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Normal zone: 241664 pages, LIFO batch:31
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] percpu: Embedded 14 pages/cpu @b9f64000 s25600 r8192 d23552 u57344
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] pcpu-alloc: s25600 r8192 d23552 u57344 alloc=14*4096
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 239540
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Kernel command line: 8250.nr_uarts=0 bcm2708_fb.fbwidth=1680 bcm2708_fb.fbheight=1050 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=/dev/mmcblk0p7 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait splash plymouth.ignore-serial-consoles
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Memory: 936296K/966656K available (7168K kernel code, 484K rwdata, 2012K rodata, 1024K init, 778K bss, 22168K reserved, 8192K cma-reserved)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Virtual kernel memory layout:
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] vmalloc : 0xbb800000 - 0xff800000 (1088 MB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] lowmem : 0x80000000 - 0xbb000000 ( 944 MB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] modules : 0x7f000000 - 0x80000000 ( 16 MB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] .text : 0x80008000 - 0x80800000 (8160 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] .init : 0x80b00000 - 0x80c00000 (1024 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] .data : 0x80c00000 - 0x80c79094 ( 485 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] .bss : 0x80c7b000 - 0x80d3da64 ( 779 kB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Hierarchical RCU implementation.
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] Build-time adjustment of leaf fanout to 32.
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] NR_IRQS:16 nr_irqs:16 16
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] arm_arch_timer: Architected cp15 timer(s) running at 19.20MHz (phys).
Aug 24 16:15:26 raspberrypi kernel: [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
Aug 24 16:15:26 raspberrypi kernel: [ 0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
Aug 24 16:15:26 raspberrypi kernel: [ 0.000023] Switching to timer-based delay loop, resolution 52ns
Aug 24 16:15:26 raspberrypi kernel: [ 0.000298] Console: colour dummy device 80x30
Aug 24 16:15:26 raspberrypi kernel: [ 0.001206] console [tty1] enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.001250] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
Aug 24 16:15:26 raspberrypi kernel: [ 0.001318] pid_max: default: 32768 minimum: 301
Aug 24 16:15:26 raspberrypi kernel: [ 0.001649] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.001691] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.002582] Disabling cpuset control group subsystem
Aug 24 16:15:26 raspberrypi kernel: [ 0.002740] CPU: Testing write buffer coherency: ok
Aug 24 16:15:26 raspberrypi kernel: [ 0.002803] ftrace: allocating 22396 entries in 66 pages
Aug 24 16:15:26 raspberrypi kernel: [ 0.049259] CPU0: update cpu_capacity 1024
Aug 24 16:15:26 raspberrypi kernel: [ 0.049311] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Aug 24 16:15:26 raspberrypi kernel: [ 0.049372] Setting up static identity map for 0x100000 - 0x100034
Aug 24 16:15:26 raspberrypi kernel: [ 0.051244] CPU1: update cpu_capacity 1024
Aug 24 16:15:26 raspberrypi kernel: [ 0.051251] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
Aug 24 16:15:26 raspberrypi kernel: [ 0.051933] CPU2: update cpu_capacity 1024
Aug 24 16:15:26 raspberrypi kernel: [ 0.051939] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
Aug 24 16:15:26 raspberrypi kernel: [ 0.052605] CPU3: update cpu_capacity 1024
Aug 24 16:15:26 raspberrypi kernel: [ 0.052612] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
Aug 24 16:15:26 raspberrypi kernel: [ 0.052700] Brought up 4 CPUs
Aug 24 16:15:26 raspberrypi kernel: [ 0.052872] SMP: Total of 4 processors activated (153.60 BogoMIPS).
Aug 24 16:15:26 raspberrypi kernel: [ 0.052901] CPU: All CPU(s) started in HYP mode.
Aug 24 16:15:26 raspberrypi kernel: [ 0.052927] CPU: Virtualization extensions available.
Aug 24 16:15:26 raspberrypi kernel: [ 0.053753] devtmpfs: initialized
Aug 24 16:15:26 raspberrypi kernel: [ 0.065018] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
Aug 24 16:15:26 raspberrypi kernel: [ 0.065339] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Aug 24 16:15:26 raspberrypi kernel: [ 0.065401] futex hash table entries: 1024 (order: 4, 65536 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.065959] pinctrl core: initialized pinctrl subsystem
Aug 24 16:15:26 raspberrypi kernel: [ 0.066873] NET: Registered protocol family 16
Aug 24 16:15:26 raspberrypi kernel: [ 0.069244] DMA: preallocated 1024 KiB pool for atomic coherent allocations
Aug 24 16:15:26 raspberrypi kernel: [ 0.078124] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
Aug 24 16:15:26 raspberrypi kernel: [ 0.078173] hw-breakpoint: maximum watchpoint size is 8 bytes.
Aug 24 16:15:26 raspberrypi kernel: [ 0.078341] Serial: AMBA PL011 UART driver
Aug 24 16:15:26 raspberrypi kernel: [ 0.080237] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.080784] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
Aug 24 16:15:26 raspberrypi kernel: [ 0.150107] bcm2835-dma 3f007000.dma: DMA legacy API manager at bb80f000, dmachans=0x1
Aug 24 16:15:26 raspberrypi kernel: [ 0.151956] SCSI subsystem initialized
Aug 24 16:15:26 raspberrypi kernel: [ 0.152138] usbcore: registered new interface driver usbfs
Aug 24 16:15:26 raspberrypi kernel: [ 0.152239] usbcore: registered new interface driver hub
Aug 24 16:15:26 raspberrypi kernel: [ 0.152354] usbcore: registered new device driver usb
Aug 24 16:15:26 raspberrypi kernel: [ 0.159069] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-08-08 12:01
Aug 24 16:15:26 raspberrypi kernel: [ 0.160577] clocksource: Switched to clocksource arch_sys_counter
Aug 24 16:15:26 raspberrypi kernel: [ 0.207723] VFS: Disk quotas dquot_6.6.0
Aug 24 16:15:26 raspberrypi kernel: [ 0.207833] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.208053] FS-Cache: Loaded
Aug 24 16:15:26 raspberrypi kernel: [ 0.208320] CacheFiles: Loaded
Aug 24 16:15:26 raspberrypi kernel: [ 0.220429] NET: Registered protocol family 2
Aug 24 16:15:26 raspberrypi kernel: [ 0.221361] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.221497] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.221709] TCP: Hash tables configured (established 8192 bind 8192)
Aug 24 16:15:26 raspberrypi kernel: [ 0.221821] UDP hash table entries: 512 (order: 2, 16384 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.221888] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 0.222121] NET: Registered protocol family 1
Aug 24 16:15:26 raspberrypi kernel: [ 0.222562] RPC: Registered named UNIX socket transport module.
Aug 24 16:15:26 raspberrypi kernel: [ 0.222594] RPC: Registered udp transport module.
Aug 24 16:15:26 raspberrypi kernel: [ 0.222622] RPC: Registered tcp transport module.
Aug 24 16:15:26 raspberrypi kernel: [ 0.222649] RPC: Registered tcp NFSv4.1 backchannel transport module.
Aug 24 16:15:26 raspberrypi kernel: [ 0.223691] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
Aug 24 16:15:26 raspberrypi kernel: [ 0.225996] workingset: timestamp_bits=14 max_order=18 bucket_order=4
Aug 24 16:15:26 raspberrypi kernel: [ 0.242071] FS-Cache: Netfs 'nfs' registered for caching
Aug 24 16:15:26 raspberrypi kernel: [ 0.243069] NFS: Registering the id_resolver key type
Aug 24 16:15:26 raspberrypi kernel: [ 0.243120] Key type id_resolver registered
Aug 24 16:15:26 raspberrypi kernel: [ 0.243148] Key type id_legacy registered
Aug 24 16:15:26 raspberrypi kernel: [ 0.245582] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
Aug 24 16:15:26 raspberrypi kernel: [ 0.245726] io scheduler noop registered
Aug 24 16:15:26 raspberrypi kernel: [ 0.245757] io scheduler deadline registered (default)
Aug 24 16:15:26 raspberrypi kernel: [ 0.246082] io scheduler cfq registered
Aug 24 16:15:26 raspberrypi kernel: [ 0.251726] BCM2708FB: allocated DMA memory fa910000
Aug 24 16:15:26 raspberrypi kernel: [ 0.251778] BCM2708FB: allocated DMA channel 0 @ bb80f000
Aug 24 16:15:26 raspberrypi kernel: [ 0.300945] Console: switching to colour frame buffer device 210x65
Aug 24 16:15:26 raspberrypi kernel: [ 0.331077] bcm2835-rng 3f104000.rng: hwrng registered
Aug 24 16:15:26 raspberrypi kernel: [ 0.331333] vc-cma: Videocore CMA driver
Aug 24 16:15:26 raspberrypi kernel: [ 0.331454] vc-cma: vc_cma_base = 0x00000000
Aug 24 16:15:26 raspberrypi kernel: [ 0.331592] vc-cma: vc_cma_size = 0x00000000 (0 MiB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.331747] vc-cma: vc_cma_initial = 0x00000000 (0 MiB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.332106] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
Aug 24 16:15:26 raspberrypi kernel: [ 0.347798] brd: module loaded
Aug 24 16:15:26 raspberrypi kernel: [ 0.356839] loop: module loaded
Aug 24 16:15:26 raspberrypi kernel: [ 0.356972] Loading iSCSI transport class v2.0-870.
Aug 24 16:15:26 raspberrypi kernel: [ 0.357662] usbcore: registered new interface driver smsc95xx
Aug 24 16:15:26 raspberrypi kernel: [ 0.357842] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Aug 24 16:15:26 raspberrypi kernel: [ 0.586078] Core Release: 2.80a
Aug 24 16:15:26 raspberrypi kernel: [ 0.586184] Setting default values for core params
Aug 24 16:15:26 raspberrypi kernel: [ 0.586351] Finished setting default values for core params
Aug 24 16:15:26 raspberrypi kernel: [ 0.786898] Using Buffer DMA mode
Aug 24 16:15:26 raspberrypi kernel: [ 0.787004] Periodic Transfer Interrupt Enhancement - disabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.787171] Multiprocessor Interrupt Enhancement - disabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.787330] OTG VER PARAM: 0, OTG VER FLAG: 0
Aug 24 16:15:26 raspberrypi kernel: [ 0.787469] Dedicated Tx FIFOs mode
Aug 24 16:15:26 raspberrypi kernel: [ 0.787910] WARN::dwc_otg_hcd_init:1032: FIQ DMA bounce buffers: virt = 0xba904000 dma = 0xfa904000 len=9024
Aug 24 16:15:26 raspberrypi kernel: [ 0.788202] FIQ FSM acceleration enabled for :
Aug 24 16:15:26 raspberrypi kernel: [ 0.788202] Non-periodic Split Transactions
Aug 24 16:15:26 raspberrypi kernel: [ 0.788202] Periodic Split Transactions
Aug 24 16:15:26 raspberrypi kernel: [ 0.788202] High-Speed Isochronous Endpoints
Aug 24 16:15:26 raspberrypi kernel: [ 0.788202] Interrupt/Control Split Transaction hack enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.788798] dwc_otg: Microframe scheduler enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.788847] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x8058f7fc
Aug 24 16:15:26 raspberrypi kernel: [ 0.789027] WARN::hcd_init_fiq:460: FIQ ASM at 0x8058fb6c length 36
Aug 24 16:15:26 raspberrypi kernel: [ 0.789211] WARN::hcd_init_fiq:486: MPHI regs_base at 0xbb87a000
Aug 24 16:15:26 raspberrypi kernel: [ 0.789437] dwc_otg 3f980000.usb: DWC OTG Controller
Aug 24 16:15:26 raspberrypi kernel: [ 0.789615] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
Aug 24 16:15:26 raspberrypi kernel: [ 0.796839] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
Aug 24 16:15:26 raspberrypi kernel: [ 0.803975] Init: Port Power? op_state=1
Aug 24 16:15:26 raspberrypi kernel: [ 0.810989] Init: Power Port (0)
Aug 24 16:15:26 raspberrypi kernel: [ 0.818190] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Aug 24 16:15:26 raspberrypi kernel: [ 0.825355] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Aug 24 16:15:26 raspberrypi kernel: [ 0.832498] usb usb1: Product: DWC OTG Controller
Aug 24 16:15:26 raspberrypi kernel: [ 0.839539] usb usb1: Manufacturer: Linux 4.9.41-v7+ dwc_otg_hcd
Aug 24 16:15:26 raspberrypi kernel: [ 0.846622] usb usb1: SerialNumber: 3f980000.usb
Aug 24 16:15:26 raspberrypi kernel: [ 0.854477] hub 1-0:1.0: USB hub found
Aug 24 16:15:26 raspberrypi kernel: [ 0.861477] hub 1-0:1.0: 1 port detected
Aug 24 16:15:26 raspberrypi kernel: [ 0.869048] dwc_otg: FIQ enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.869053] dwc_otg: NAK holdoff enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.869057] dwc_otg: FIQ split-transaction FSM enabled
Aug 24 16:15:26 raspberrypi kernel: [ 0.869071] Module dwc_common_port init
Aug 24 16:15:26 raspberrypi kernel: [ 0.869309] usbcore: registered new interface driver usb-storage
Aug 24 16:15:26 raspberrypi kernel: [ 0.876500] mousedev: PS/2 mouse device common for all mice
Aug 24 16:15:26 raspberrypi kernel: [ 0.884519] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
Aug 24 16:15:26 raspberrypi kernel: [ 0.891942] bcm2835-cpufreq: min=600000 max=1200000
Aug 24 16:15:26 raspberrypi kernel: [ 0.899456] sdhci: Secure Digital Host Controller Interface driver
Aug 24 16:15:26 raspberrypi kernel: [ 0.906600] sdhci: Copyright(c) Pierre Ossman
Aug 24 16:15:26 raspberrypi kernel: [ 0.913937] sdhost-bcm2835 3f202000.sdhost: could not get clk, deferring probe
Aug 24 16:15:26 raspberrypi kernel: [ 0.923226] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe
Aug 24 16:15:26 raspberrypi kernel: [ 0.930429] sdhci-pltfm: SDHCI platform and OF driver helper
Aug 24 16:15:26 raspberrypi kernel: [ 0.940178] ledtrig-cpu: registered to indicate activity on CPUs
Aug 24 16:15:26 raspberrypi kernel: [ 0.947543] hidraw: raw HID events driver (C) Jiri Kosina
Aug 24 16:15:26 raspberrypi kernel: [ 0.954977] usbcore: registered new interface driver usbhid
Aug 24 16:15:26 raspberrypi kernel: [ 0.962177] usbhid: USB HID core driver
Aug 24 16:15:26 raspberrypi kernel: [ 0.970097] vchiq: vchiq_init_state: slot_zero = 0xba980000, is_master = 0
Aug 24 16:15:26 raspberrypi kernel: [ 0.979308] Initializing XFRM netlink socket
Aug 24 16:15:26 raspberrypi kernel: [ 0.986645] NET: Registered protocol family 17
Aug 24 16:15:26 raspberrypi kernel: [ 0.994020] Key type dns_resolver registered
Aug 24 16:15:26 raspberrypi kernel: [ 1.001735] Registering SWP/SWPB emulation handler
Aug 24 16:15:26 raspberrypi kernel: [ 1.009747] registered taskstats version 1
Aug 24 16:15:26 raspberrypi kernel: [ 1.017319] vc-sm: Videocore shared memory driver
Aug 24 16:15:26 raspberrypi kernel: [ 1.024528] [vc_sm_connected_init]: start
Aug 24 16:15:26 raspberrypi kernel: [ 1.032193] [vc_sm_connected_init]: end - returning 0
Aug 24 16:15:26 raspberrypi kernel: [ 1.045420] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
Aug 24 16:15:26 raspberrypi kernel: [ 1.054537] sdhost: log_buf @ ba907000 (fa907000)
Aug 24 16:15:26 raspberrypi kernel: [ 1.082549] Indeed it is in host mode hprt0 = 00021501
Aug 24 16:15:26 raspberrypi kernel: [ 1.170607] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Aug 24 16:15:26 raspberrypi kernel: [ 1.177483] random: fast init done
Aug 24 16:15:26 raspberrypi kernel: [ 1.187562] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
Aug 24 16:15:26 raspberrypi kernel: [ 1.195015] mmc-bcm2835 3f300000.mmc: DMA channel allocated
Aug 24 16:15:26 raspberrypi kernel: [ 1.260716] of_cfs_init
Aug 24 16:15:26 raspberrypi kernel: [ 1.268218] of_cfs_init: OK
Aug 24 16:15:26 raspberrypi kernel: [ 1.272079] mmc0: host does not support reading read-only switch, assuming write-enable
Aug 24 16:15:26 raspberrypi kernel: [ 1.274094] mmc0: new high speed SDHC card at address 59b4
Aug 24 16:15:26 raspberrypi kernel: [ 1.274818] mmcblk0: mmc0:59b4 USD 14.7 GiB
Aug 24 16:15:26 raspberrypi kernel: [ 1.280844] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 1.282399] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 1.283958] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 1.286751] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Aug 24 16:15:26 raspberrypi kernel: [ 1.300606] usb 1-1: new high-speed USB device number 2 using dwc_otg
Aug 24 16:15:26 raspberrypi kernel: [ 1.300757] Indeed it is in host mode hprt0 = 00001101
Aug 24 16:15:26 raspberrypi kernel: [ 1.364184] mmcblk0: p1 p2 < p5 p6 p7 >
Aug 24 16:15:26 raspberrypi kernel: [ 1.387645] EXT4-fs (mmcblk0p7): mounted filesystem with ordered data mode. Opts: (null)
Aug 24 16:15:26 raspberrypi kernel: [ 1.395141] VFS: Mounted root (ext4 filesystem) readonly on device 179:7.
Aug 24 16:15:26 raspberrypi kernel: [ 1.412764] devtmpfs: mounted
Aug 24 16:15:26 raspberrypi kernel: [ 1.421929] Freeing unused kernel memory: 1024K (80b00000 - 80c00000)
Aug 24 16:15:26 raspberrypi kernel: [ 1.445611] mmc1: new high speed SDIO card at address 0001
Aug 24 16:15:26 raspberrypi kernel: [ 1.530937] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
Aug 24 16:15:26 raspberrypi kernel: [ 1.538478] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Aug 24 16:15:26 raspberrypi kernel: [ 1.546945] hub 1-1:1.0: USB hub found
Aug 24 16:15:26 raspberrypi kernel: [ 1.554579] hub 1-1:1.0: 5 ports detected
Aug 24 16:15:26 raspberrypi kernel: [ 1.880632] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Aug 24 16:15:26 raspberrypi kernel: [ 1.982636] NET: Registered protocol family 10
Aug 24 16:15:26 raspberrypi kernel: [ 2.000700] ip_tables: (C) 2000-2006 Netfilter Core Team
Aug 24 16:15:26 raspberrypi kernel: [ 2.011033] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
Aug 24 16:15:26 raspberrypi kernel: [ 2.018692] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Aug 24 16:15:26 raspberrypi kernel: [ 2.029125] smsc95xx v1.0.5
Aug 24 16:15:26 raspberrypi kernel: [ 2.124732] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:f0:4f:20
Aug 24 16:15:26 raspberrypi kernel: [ 2.230624] usb 1-1.4: new full-speed USB device number 4 using dwc_otg
Aug 24 16:15:26 raspberrypi kernel: [ 2.385148] usb 1-1.4: New USB device found, idVendor=045e, idProduct=0745
Aug 24 16:15:26 raspberrypi kernel: [ 2.393602] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Aug 24 16:15:26 raspberrypi kernel: [ 2.401994] usb 1-1.4: Product: Microsoft® 2.4GHz Transceiver v7.0
Aug 24 16:15:26 raspberrypi kernel: [ 2.410302] usb 1-1.4: Manufacturer: Microsoft
Aug 24 16:15:26 raspberrypi kernel: [ 2.424945] input: Microsoft Microsoft® 2.4GHz Transceiver v7.0 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/0003:045E:0745.0001/input/input0
Aug 24 16:15:26 raspberrypi kernel: [ 2.501415] hid-generic 0003:045E:0745.0001: input,hidraw0: USB HID v1.11 Keyboard [Microsoft Microsoft® 2.4GHz Transceiver v7.0] on usb-3f980000.usb-1.4/input0
Aug 24 16:15:26 raspberrypi kernel: [ 2.524357] input: Microsoft Microsoft® 2.4GHz Transceiver v7.0 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.1/0003:045E:0745.0002/input/input1
Aug 24 16:15:26 raspberrypi kernel: [ 2.601135] hid-generic 0003:045E:0745.0002: input,hidraw1: USB HID v1.11 Mouse [Microsoft Microsoft® 2.4GHz Transceiver v7.0] on usb-3f980000.usb-1.4/input1
Aug 24 16:15:26 raspberrypi kernel: [ 2.647566] input: Microsoft Microsoft® 2.4GHz Transceiver v7.0 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.2/0003:045E:0745.0003/input/input2
Aug 24 16:15:26 raspberrypi kernel: [ 2.741193] hid-generic 0003:045E:0745.0003: input,hiddev0,hidraw2: USB HID v1.11 Device [Microsoft Microsoft® 2.4GHz Transceiver v7.0] on usb-3f980000.usb-1.4/input2
Aug 24 16:15:26 raspberrypi kernel: [ 3.013146] i2c /dev entries driver
Aug 24 16:15:26 raspberrypi kernel: [ 3.327740] EXT4-fs (mmcblk0p7): re-mounted. Opts: (null)
Aug 24 16:15:26 raspberrypi kernel: [ 3.966623] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
Aug 24 16:15:26 raspberrypi kernel: [ 4.527676] usbcore: registered new interface driver brcmfmac
Aug 24 16:15:26 raspberrypi kernel: [ 4.625562] smsc95xx 1-1.1:1.0 enxb827ebf04f20: renamed from eth0
Aug 24 16:15:26 raspberrypi kernel: [ 4.678998] brcmfmac: Firmware version = wl0: Aug 7 2017 00:46:29 version 7.45.41.46 (r666254 CY) FWID 01-f8a78378
Aug 24 16:15:26 raspberrypi kernel: [ 5.301163] random: crng init done
Aug 24 16:15:26 raspberrypi kernel: [ 5.864276] uart-pl011 3f201000.serial: no DMA platform data
Aug 24 16:15:26 raspberrypi systemd[1]: Started System Logging Service.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Found user 'avahi' (UID 108) and group 'avahi' (GID 112).
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Successfully dropped root privileges.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: avahi-daemon 0.6.32 starting up.
Aug 24 16:15:26 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Successfully called chroot().
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Successfully dropped remaining capabilities.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: No service file found in /etc/avahi/services.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Network interface enumeration completed.
Aug 24 16:15:26 raspberrypi avahi-daemon[352]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 3454406128.
Aug 24 16:15:26 raspberrypi systemd[1]: Received SIGRTMIN+20 from PID 176 (plymouthd).
Aug 24 16:15:27 raspberrypi dhcpcd[332]: enxb827ebf04f20: waiting for carrier
Aug 24 16:15:27 raspberrypi dhcpcd[332]: wlan0: if_up: Operation not possible due to RF-kill
Aug 24 16:15:27 raspberrypi dhcpcd[332]: wlan0: waiting for carrier
Aug 24 16:15:27 raspberrypi dhcpcd[332]: enxb827ebf04f20: carrier acquired
Aug 24 16:15:27 raspberrypi kernel: [ 7.233041] smsc95xx 1-1.1:1.0 enxb827ebf04f20: hardware isn't capable of remote wakeup
Aug 24 16:15:27 raspberrypi dhcpcd[332]: enxb827ebf04f20: adding address fe80::1f9d:7627:d979:865d
Aug 24 16:15:27 raspberrypi dhcpcd[332]: DUID 00:01:00:01:21:26:5f:1c:b8:27:eb:a5:1a:75
Aug 24 16:15:27 raspberrypi dhcpcd[332]: enxb827ebf04f20: IAID eb:f0:4f:20
Aug 24 16:15:28 raspberrypi dphys-swapfile[321]: Starting dphys-swapfile swapfile setup ...
Aug 24 16:15:28 raspberrypi dhcpcd[332]: enxb827ebf04f20: rebinding lease of 192.168.2.3
Aug 24 16:15:28 raspberrypi dphys-swapfile[321]: want /var/swap=100MByte, checking existing: keeping it
Aug 24 16:15:28 raspberrypi weewx[355]: engine: Initializing weewx version 3.7.1
Aug 24 16:15:28 raspberrypi weewx[355]: engine: Using Python 2.7.13 (default, Jan 19 2017, 14:48:08) #012[GCC 6.3.0 20170124]
Aug 24 16:15:28 raspberrypi weewx[355]: engine: Platform Linux-4.9.41-v7+-armv7l-with-debian-9.1
Aug 24 16:15:28 raspberrypi weewx[355]: engine: Locale is 'en_AU.UTF-8'
Aug 24 16:15:28 raspberrypi weewx[355]: engine: pid file is /var/run/weewx.pid
Aug 24 16:15:28 raspberrypi systemd[1]: Started Raise network interfaces.
Aug 24 16:15:28 raspberrypi systemd[1]: Reached target Network.
Aug 24 16:15:28 raspberrypi systemd[1]: Starting The Apache HTTP Server...
Aug 24 16:15:28 raspberrypi kernel: [ 7.802029] Adding 102396k swap on /var/swap. Priority:-1 extents:1 across:102396k SSFS
Aug 24 16:15:28 raspberrypi systemd[1]: Starting Permit User Sessions...
Aug 24 16:15:28 raspberrypi dphys-swapfile[321]: done.
Aug 24 16:15:28 raspberrypi systemd[1]: Reached target Network is Online.
Aug 24 16:15:28 raspberrypi systemd[1]: Starting LSB: exim Mail Transport Agent...
Aug 24 16:15:28 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Aug 24 16:15:28 raspberrypi systemd[1]: apt-daily.timer: Adding 3h 51min 35.559740s random time.
Aug 24 16:15:28 raspberrypi systemd[1]: Started Daily apt download activities.
Aug 24 16:15:28 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 48min 47.883324s random time.
Aug 24 16:15:28 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Aug 24 16:15:28 raspberrypi systemd[1]: Reached target Timers.
Aug 24 16:15:28 raspberrypi systemd[1]: Started LSB: Autogenerate and use a swap file.
Aug 24 16:15:28 raspberrypi systemd[1]: Started Permit User Sessions.
Aug 24 16:15:28 raspberrypi weewx[430]: engine: Using configuration file /etc/weewx/weewx.conf
Aug 24 16:15:28 raspberrypi weewx[430]: engine: debug is 1
Aug 24 16:15:28 raspberrypi weewx[430]: engine: Initializing engine
Aug 24 16:15:28 raspberrypi weewx[430]: engine: Loading station type Interceptor (user.interceptor)
Aug 24 16:15:28 raspberrypi systemd[1]: Starting Light Display Manager...
Aug 24 16:15:28 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Aug 24 16:15:28 raspberrypi systemd[1]: Starting Terminate Plymouth Boot Screen...
Aug 24 16:15:28 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Aug 24 16:15:28 raspberrypi systemd[1]: weewx.service: Supervising process 430 which is not our child. We'll most likely not notice when it exits.
Aug 24 16:15:28 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 176 (plymouthd).
Aug 24 16:15:28 raspberrypi dhcpcd[332]: enxb827ebf04f20: soliciting an IPv6 router
Aug 24 16:15:28 raspberrypi systemd[1]: Started Terminate Plymouth Boot Screen.
Aug 24 16:15:28 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Aug 24 16:15:28 raspberrypi systemd[1]: Started Getty on tty1.
Aug 24 16:15:28 raspberrypi systemd[1]: Reached target Login Prompts.
Aug 24 16:15:28 raspberrypi dhcpcd[332]: enxb827ebf04f20: carrier lost
Aug 24 16:15:28 raspberrypi dhcpcd[332]: enxb827ebf04f20: deleting address fe80::1f9d:7627:d979:865d
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: driver version is 0.30
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: device type: observer
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: sensor map: None
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: mode is listen
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: listen on 192.168.2.3:55
Aug 24 16:15:28 raspberrypi weewx[430]: import of driver failed: [Errno 99] Cannot assign requested address (<class 'socket.error'>)
Aug 24 16:15:28 raspberrypi weewx[430]: engine: Unable to load driver: [Errno 99] Cannot assign requested address
Aug 24 16:15:28 raspberrypi weewx[430]: **** Exiting...
Aug 24 16:15:28 raspberrypi systemd[1]: weewx.service: Main process exited, code=exited, status=4/NOPERMISSION
Aug 24 16:15:28 raspberrypi systemd[1]: weewx.service: Unit entered failed state.
Aug 24 16:15:28 raspberrypi systemd[1]: weewx.service: Failed with result 'exit-code'.
Aug 24 16:15:29 raspberrypi raspi-config[350]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Aug 24 16:15:29 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: carrier acquired
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: adding address fe80::1f9d:7627:d979:865d
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: IAID eb:f0:4f:20
Aug 24 16:15:29 raspberrypi kernel: [ 8.732490] smsc95xx 1-1.1:1.0 enxb827ebf04f20: link up, 100Mbps, full-duplex, lpa 0xCDE1
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: rebinding lease of 192.168.2.3
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: probing address 192.168.2.3/24
Aug 24 16:15:30 raspberrypi lightdm[455]: 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
Aug 24 16:15:30 raspberrypi dhcpcd[332]: enxb827ebf04f20: soliciting an IPv6 router
Aug 24 16:15:30 raspberrypi systemd[1]: Started Light Display Manager.
Aug 24 16:15:30 raspberrypi apachectl[428]: AH00557: apache2: apr_sockaddr_info_get() failed for raspberrypi
Aug 24 16:15:30 raspberrypi apachectl[428]: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1. Set the 'ServerName' directive globally to suppress this message
Aug 24 16:15:30 raspberrypi systemd[1]: Started The Apache HTTP Server.
Aug 24 16:15:30 raspberrypi avahi-daemon[352]: Joining mDNS multicast group on interface enxb827ebf04f20.IPv6 with address fe80::1f9d:7627:d979:865d.
Aug 24 16:15:30 raspberrypi avahi-daemon[352]: New relevant interface enxb827ebf04f20.IPv6 for mDNS.
Aug 24 16:15:30 raspberrypi avahi-daemon[352]: Registering new address record for fe80::1f9d:7627:d979:865d on enxb827ebf04f20.*.
Aug 24 16:15:30 raspberrypi kernel: [ 10.320232] Bluetooth: Core ver 2.22
Aug 24 16:15:30 raspberrypi kernel: [ 10.320285] NET: Registered protocol family 31
Aug 24 16:15:30 raspberrypi kernel: [ 10.320289] Bluetooth: HCI device and connection manager initialized
Aug 24 16:15:30 raspberrypi kernel: [ 10.320301] Bluetooth: HCI socket layer initialized
Aug 24 16:15:30 raspberrypi kernel: [ 10.320308] Bluetooth: L2CAP socket layer initialized
Aug 24 16:15:30 raspberrypi kernel: [ 10.320326] Bluetooth: SCO socket layer initialized
Aug 24 16:15:30 raspberrypi kernel: [ 10.339433] Bluetooth: HCI UART driver ver 2.3
Aug 24 16:15:30 raspberrypi kernel: [ 10.339440] Bluetooth: HCI UART protocol H4 registered
Aug 24 16:15:30 raspberrypi kernel: [ 10.339443] Bluetooth: HCI UART protocol Three-wire (H5) registered
Aug 24 16:15:30 raspberrypi kernel: [ 10.339542] Bluetooth: HCI UART protocol Broadcom registered
Aug 24 16:15:30 raspberrypi btuart[317]: bcm43xx_init
Aug 24 16:15:30 raspberrypi btuart[317]: Flash firmware /lib/firmware/BCM43430A1.hcd
Aug 24 16:15:30 raspberrypi btuart[317]: Set Controller UART speed to 921600 bit/s
Aug 24 16:15:30 raspberrypi btuart[317]: Device setup complete
Aug 24 16:15:30 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Aug 24 16:15:30 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Aug 24 16:15:30 raspberrypi systemd[1]: Starting Bluetooth service...
Aug 24 16:15:30 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Aug 24 16:15:30 raspberrypi systemd-udevd[806]: Process '/usr/lib/raspberrypi-sys-mods/rfkill-persist' failed with exit code 1.
Aug 24 16:15:30 raspberrypi bluetoothd[802]: Bluetooth daemon 5.43
Aug 24 16:15:31 raspberrypi systemd[1]: Started Bluetooth service.
Aug 24 16:15:31 raspberrypi systemd[1]: Started BluezALSA proxy.
Aug 24 16:15:31 raspberrypi systemd[1]: Reached target Bluetooth.
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Starting SDP server
Aug 24 16:15:31 raspberrypi wicd[345]: Starting Network connection manager: wicd.
Aug 24 16:15:31 raspberrypi systemd[1]: Started LSB: Starts and stops Wicd.
Aug 24 16:15:31 raspberrypi exim4[434]: Starting MTA: exim4.
Aug 24 16:15:31 raspberrypi systemd[1]: Started LSB: exim Mail Transport Agent.
Aug 24 16:15:31 raspberrypi systemd[1]: Reached target Multi-User System.
Aug 24 16:15:31 raspberrypi kernel: [ 10.721384] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Aug 24 16:15:31 raspberrypi kernel: [ 10.721391] Bluetooth: BNEP filters: protocol multicast
Aug 24 16:15:31 raspberrypi kernel: [ 10.721404] Bluetooth: BNEP socket layer initialized
Aug 24 16:15:31 raspberrypi systemd[1]: Reached target Graphical Interface.
Aug 24 16:15:31 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Bluetooth management interface 1.14 initialized
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Failed to obtain handles for "Service Changed" characteristic
Aug 24 16:15:31 raspberrypi dbus[323]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
Aug 24 16:15:31 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Sap driver initialization failed.
Aug 24 16:15:31 raspberrypi bluetoothd[802]: sap-server: Operation not permitted (1)
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Endpoint registered: sender=:1.7 path=/MediaEndpoint/A2DPSource
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Failed to set mode: Blocked through rfkill (0x12)
Aug 24 16:15:31 raspberrypi bluetoothd[802]: Endpoint registered: sender=:1.7 path=/MediaEndpoint/A2DPSink
Aug 24 16:15:31 raspberrypi systemd[1]: Starting Hostname Service...
Aug 24 16:15:31 raspberrypi kernel: [ 10.826181] Bluetooth: RFCOMM TTY layer initialized
Aug 24 16:15:31 raspberrypi kernel: [ 10.826204] Bluetooth: RFCOMM socket layer initialized
Aug 24 16:15:31 raspberrypi kernel: [ 10.826227] Bluetooth: RFCOMM ver 1.11
Aug 24 16:15:31 raspberrypi kernel: [ 11.013440] NET: Registered protocol family 3
Aug 24 16:15:31 raspberrypi dbus[323]: [system] Successfully activated service 'org.freedesktop.hostname1'
Aug 24 16:15:31 raspberrypi systemd[1]: Started Hostname Service.
Aug 24 16:15:31 raspberrypi systemd[1]: Startup finished in 1.801s (kernel) + 9.252s (userspace) = 11.054s.
Aug 24 16:15:31 raspberrypi kernel: [ 11.074088] NET: Registered protocol family 5
Aug 24 16:15:32 raspberrypi systemd[1]: Created slice User Slice of pi.
Aug 24 16:15:32 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Aug 24 16:15:32 raspberrypi systemd[1]: Started Session c1 of user pi.
Aug 24 16:15:32 raspberrypi systemd[848]: Listening on GnuPG cryptographic agent (access for web browsers).
Aug 24 16:15:32 raspberrypi systemd[848]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Aug 24 16:15:32 raspberrypi systemd[848]: Starting D-Bus User Message Bus Socket.
Aug 24 16:15:32 raspberrypi systemd[848]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Aug 24 16:15:32 raspberrypi systemd[848]: Reached target Paths.
Aug 24 16:15:32 raspberrypi systemd[848]: Listening on GnuPG cryptographic agent and passphrase cache.
Aug 24 16:15:32 raspberrypi systemd[848]: Reached target Timers.
Aug 24 16:15:32 raspberrypi systemd[848]: Listening on D-Bus User Message Bus Socket.
Aug 24 16:15:32 raspberrypi systemd[848]: Reached target Sockets.
Aug 24 16:15:32 raspberrypi systemd[848]: Reached target Basic System.
Aug 24 16:15:32 raspberrypi systemd[848]: Reached target Default.
Aug 24 16:15:32 raspberrypi systemd[848]: Startup finished in 249ms.
Aug 24 16:15:32 raspberrypi systemd[1]: Started User Manager for UID 1000.
Aug 24 16:15:33 raspberrypi lightdm[882]: 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
Aug 24 16:15:33 raspberrypi systemd[1]: Started Session c2 of user pi.
Aug 24 16:15:33 raspberrypi lightdm[455]: Error opening audit socket: Protocol not supported
Aug 24 16:15:33 raspberrypi systemd[848]: Started D-Bus User Message Bus.
Aug 24 16:15:33 raspberrypi dbus-daemon[900]: Successfully activated service 'org.freedesktop.systemd1'
Aug 24 16:15:35 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service'
Aug 24 16:15:35 raspberrypi systemd[848]: Starting Virtual filesystem service...
Aug 24 16:15:35 raspberrypi dhcpcd[332]: enxb827ebf04f20: leased 192.168.2.3 for 86400 seconds
Aug 24 16:15:35 raspberrypi avahi-daemon[352]: Joining mDNS multicast group on interface enxb827ebf04f20.IPv4 with address 192.168.2.3.
Aug 24 16:15:35 raspberrypi dhcpcd[332]: enxb827ebf04f20: adding route to 192.168.2.0/24
Aug 24 16:15:35 raspberrypi avahi-daemon[352]: New relevant interface enxb827ebf04f20.IPv4 for mDNS.
Aug 24 16:15:35 raspberrypi avahi-daemon[352]: Registering new address record for 192.168.2.3 on enxb827ebf04f20.IPv4.
Aug 24 16:15:35 raspberrypi dhcpcd[332]: enxb827ebf04f20: adding default route via 192.168.2.1
Aug 24 16:15:35 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.Daemon'
Aug 24 16:15:35 raspberrypi systemd[848]: Started Virtual filesystem service.
Aug 24 16:15:35 raspberrypi kernel: [ 14.751541] fuse init (API version 7.26)
Aug 24 16:15:35 raspberrypi dhcpcd[332]: enxb827ebf04f20: removing route to 192.168.2.0/24
Aug 24 16:15:35 raspberrypi systemd[1]: Mounting FUSE Control File System...
Aug 24 16:15:35 raspberrypi systemd[1]: Mounted FUSE Control File System.
Aug 24 16:15:35 raspberrypi dbus[323]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service'
Aug 24 16:15:35 raspberrypi systemd[1]: Starting Authorization Manager...
Aug 24 16:15:35 raspberrypi polkitd[1030]: started daemon version 0.105 using authority implementation `local' version `0.105'
Aug 24 16:15:35 raspberrypi dbus[323]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Aug 24 16:15:35 raspberrypi systemd[1]: Started Authorization Manager.
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service'
Aug 24 16:15:37 raspberrypi systemd[848]: Starting Virtual filesystem service - disk device monitor...
Aug 24 16:15:37 raspberrypi dbus[323]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service'
Aug 24 16:15:37 raspberrypi systemd[1]: Starting Disk Manager...
Aug 24 16:15:37 raspberrypi udisksd[1066]: udisks daemon version 2.1.8 starting
Aug 24 16:15:37 raspberrypi dbus[323]: [system] Successfully activated service 'org.freedesktop.UDisks2'
Aug 24 16:15:37 raspberrypi systemd[1]: Started Disk Manager.
Aug 24 16:15:37 raspberrypi udisksd[1066]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Aug 24 16:15:37 raspberrypi udisksd[1066]: Cleaning up mount point /media/pi/SETTINGS (device 179:5 is not mounted)
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Aug 24 16:15:37 raspberrypi systemd[848]: Started Virtual filesystem service - disk device monitor.
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service'
Aug 24 16:15:37 raspberrypi systemd[848]: Starting Virtual filesystem service - Apple File Conduit monitor...
Aug 24 16:15:37 raspberrypi gvfs-afc-volume-monitor[1080]: Volume monitor alive
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Aug 24 16:15:37 raspberrypi systemd[848]: Started Virtual filesystem service - Apple File Conduit monitor.
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service'
Aug 24 16:15:37 raspberrypi systemd[848]: Starting Virtual filesystem service - digital camera monitor...
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Aug 24 16:15:37 raspberrypi systemd[848]: Started Virtual filesystem service - digital camera monitor.
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service'
Aug 24 16:15:37 raspberrypi systemd[848]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Aug 24 16:15:37 raspberrypi systemd[848]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service'
Aug 24 16:15:37 raspberrypi systemd[848]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Aug 24 16:15:37 raspberrypi dbus-daemon[900]: Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Aug 24 16:15:37 raspberrypi systemd[848]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Aug 24 16:15:38 raspberrypi kernel: [ 18.403765] EXT4-fs (mmcblk0p5): mounted filesystem with ordered data mode. Opts: (null)
Aug 24 16:15:38 raspberrypi udisksd[1066]: Mounted /dev/mmcblk0p5 at /media/pi/SETTINGS on behalf of uid 1000
Aug 24 16:15:42 raspberrypi dhcpcd[332]: enxb827ebf04f20: no IPv6 Routers available
Aug 24 16:16:18 raspberrypi systemd[1]: Time has been changed
Aug 24 16:16:18 raspberrypi systemd[848]: Time has been changed
Aug 24 16:16:18 raspberrypi systemd-timesyncd[294]: Synchronized to time server 203.122.222.149:123 (2.debian.pool.ntp.org).
Aug 24 16:16:18 raspberrypi systemd[1]: apt-daily.timer: Adding 5h 2min 18.621141s random time.
Aug 24 16:16:18 raspberrypi systemd[1]: anacron.timer: Adding 2min 48.445281s random time.
Aug 24 16:16:18 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 56min 24.585400s random time.
Aug 24 16:19:09 raspberrypi systemd[1]: Started weewx weather system.
Aug 24 16:19:10 raspberrypi weewx[1251]: engine: Initializing weewx version 3.7.1
Aug 24 16:19:10 raspberrypi weewx[1251]: engine: Using Python 2.7.13 (default, Jan 19 2017, 14:48:08) #012[GCC 6.3.0 20170124]
Aug 24 16:19:10 raspberrypi weewx[1251]: engine: Platform Linux-4.9.41-v7+-armv7l-with-debian-9.1
Aug 24 16:19:10 raspberrypi weewx[1251]: engine: Locale is 'en_AU.UTF-8'
Aug 24 16:19:10 raspberrypi weewx[1251]: engine: pid file is /var/run/weewx.pid
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Using configuration file /etc/weewx/weewx.conf
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: debug is 1
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Initializing engine
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading station type Interceptor (user.interceptor)
Aug 24 16:19:10 raspberrypi systemd[1]: weewx.service: Supervising process 1258 which is not our child. We'll most likely not notice when it exits.
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: MainThread: driver version is 0.30
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: MainThread: device type: observer
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: MainThread: sensor map: None
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: MainThread: mode is listen
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: MainThread: listen on 192.168.2.3:55
Aug 24 16:19:10 raspberrypi weewx[1258]: interceptor: ServerThread: start tcp server
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdTimeSynch
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdTimeSynch
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdConvert
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: StdConvert target unit is 0x10
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdConvert
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdCalibrate
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdCalibrate
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdQC
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdQC
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.wxservices.StdWXCalculate
Aug 24 16:19:10 raspberrypi weewx[1258]: 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
Aug 24 16:19:10 raspberrypi weewx[1258]: wxcalculate: The following algorithms will be used for calculations: altimeter=aaNOAA, maxSolarRad=RS
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.wxservices.StdWXCalculate
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdArchive
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Archive will use data binding wx_binding
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Record generation will be attempted in 'software'
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Using archive interval of 300 seconds (specified in weewx configuration)
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Use LOOP data in hi/low calculations: 1
Aug 24 16:19:10 raspberrypi weewx[1258]: manager: Daily summary version is 2.0
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Using binding 'wx_binding' to database 'weewx.sdb'
Aug 24 16:19:10 raspberrypi weewx[1258]: manager: Starting backfill of daily summaries
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdArchive
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdStationRegistry
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: StationRegistry: Registration not requested.
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdStationRegistry
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdWunderground
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: Wunderground-RF: Data for station IVICTORI1225 will be posted
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdWunderground
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdPWSweather
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: PWSweather: Posting not enabled.
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdPWSweather
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdCWOP
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: CWOP: Posting not enabled.
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdCWOP
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdWOW
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: WOW: Posting not enabled.
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdWOW
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.restx.StdAWEKAS
Aug 24 16:19:10 raspberrypi weewx[1258]: restx: AWEKAS: Posting not enabled.
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.restx.StdAWEKAS
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdPrint
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdPrint
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Loading service weewx.engine.StdReport
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Finished loading service weewx.engine.StdReport
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Starting up weewx version 3.7.1
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Station does not support reading the time
Aug 24 16:19:10 raspberrypi weewx[1258]: engine: Starting main packet loop.
Aug 24 16:19:10 raspberrypi weewx[1258]: manager: Daily summary version is 2.0
Andrew Milner
Aug 24, 2017, 2:58:50 AM8/24/17
to weewx-user
You have a permissions error at 16:15:29
David Porter
Aug 24, 2017, 3:04:30 AM8/24/17
to weewx-user
And the rest of the syslog file...
Aug 24 16:19:20 raspberrypi weewx[1258]: interceptor: MainThread: empty queue
Aug 24 16:19:25 raspberrypi weewx[1258]: interceptor: ServerThread: GET: ID=Stonycreek&PASSWORD=XXXX&tempf=55.6&humidity=67&dewptf=44.8&windchillf=55.6&winddir=13&windspeedmph=0.00&windgustmph=0.00&rainin=0.00&dailyrainin=0.00&weeklyrainin=0.24&monthlyrainin=1.59&yearlyrainin=1.59&solarradiation=22.94&UV=1&indoortempf=64.8&indoorhumidity=58&baromin=30.35&lowbatt=0&dateutc=2017-8-24%206:19:11&softwaretype=Weather%20logger%20V2.2.0&action=updateraw&realtime=1&rtfreq=5
Aug 24 16:19:25 raspberrypi weewx[1258]: interceptor: MainThread: raw data: ID=Stonycreek&PASSWORD=##########&tempf=55.6&humidity=67&dewptf=44.8&windchillf=55.6&winddir=13&windspeedmph=0.00&windgustmph=0.00&rainin=0.00&dailyrainin=0.00&weeklyrainin=0.24&monthlyrainin=1.59&yearlyrainin=1.59&solarradiation=22.94&UV=1&indoortempf=64.8&indoorhumidity=58&baromin=30.35&lowbatt=0&dateutc=2017-8-24%206:19:11&softwaretype=Weather%20logger%20V2.2.0&action=updateraw&realtime=1&rtfreq=5
Andrew Milner
Aug 24, 2017, 3:05:55 AM8/24/17
to weewx-user
I suspect it may be waiting for the network and/or NTP server to ensure the time is set correctly on the rpi before proceeding. I notice that the NTP server corrected time is some time (1 monute) after the attempt at starting weewx. By the time you give the manual command all is hunkey dorey and it starts just fine. It could also be related to the permissions error I noticed. When you give he manual command I see you use sudo - whilst the user and group are set to weewx in the script - don't know what the significance of the observation is though!! Maybe a red herring.
mwall
Aug 24, 2017, 8:21:03 AM8/24/17
to weewx-user
On Thursday, August 24, 2017 at 2:42:05 AM UTC-4, David Porter wrote:
There are no obvious error messages in the syslog (or at least, none I can see). "sudo systemctl start weewx" works fine when I manually type it into the terminal. But I'm still at a loss how to automate that command.
you can see the failure at 16:15:28
Aug 24 16:15:28 raspberrypi weewx[430]: interceptor: MainThread: listen on 192.168.2.3:55
Aug
24 16:15:28 raspberrypi weewx[430]: import of driver failed: [Errno 99]
Cannot assign requested address (<class 'socket.error'>)
Aug 24 16:15:28 raspberrypi weewx[430]: engine: Unable to load driver: [Errno 99] Cannot assign requested address
Aug 24 16:15:28 raspberrypi weewx[430]: **** Exiting...
Aug 24 16:15:28 raspberrypi systemd[1]: weewx.service: Main process exited, code=exited, status=4/NOPERMISSION
then after that the network actually comes up:
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: carrier acquired
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: adding address fe80::1f9d:7627:d979:865d
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: IAID eb:f0:4f:20
Aug 24 16:15:29 raspberrypi kernel: [ 8.732490] smsc95xx 1-1.1:1.0 enxb827ebf04f20: link up, 100Mbps, full-duplex, lpa 0xCDE1
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: rebinding lease of 192.168.2.3
Aug 24 16:15:29 raspberrypi dhcpcd[332]: enxb827ebf04f20: probing address 192.168.2.3/24
so the network has not been configured by the time that systemd starts weewx. since the interceptor driver requres a network connection, weewx quits.
anyone's guess as to why systemd reports it as 'NOPERMISSION'
you can tell systemd to not start weewx until the network is up: ask a systemd guru for the magic incantation
or you can tell weewx to cycle during startup despite any failures: use loop_on_init=true in your weewx configuration file.
m
Andrew Milner
Aug 24, 2017, 9:01:56 AM8/24/17
to weewx-user
Try and change the script to
Requires = time-sync.target network.target network-online.target
After = time-sync.target network.target network-online.target
See if that helps
On Wednesday, 23 August 2017 13:27:32 UTC+3, David Porter wrote:
Reply all
Reply to author
Forward
0 new messages