search

owntone / owntone-server

Linux/FreeBSD DAAP (iTunes) and MPD audio server with support for AirPlay 1 and 2 speakers (multiroom), Apple Remote (and compatibles), Chromecast, Spotify and internet radio.
https://owntone.github.io/owntone-server
GNU General Public License v2.0
2.09k stars 235 forks source link

Service shutting down on Pi reboot #418

Closed 1liminal1 closed 7 years ago

1liminal1 commented 7 years ago

Getting a strange thing when I reboot;

pi@AirServer:~ $ tail -f /var/log/forked-daapd.log
[2017-09-13 16:19:42] [  LOG]     main: mDNS deinit
[2017-09-13 16:19:42] [  LOG]     main: Remote pairing deinit
[2017-09-13 16:19:42] [  LOG]     main: MPD deinit
[2017-09-13 16:19:42] [  LOG]     main: HTTPd deinit
[2017-09-13 16:19:42] [  LOG]     main: Player deinit
[2017-09-13 16:19:42] [  LOG]     main: Library scaner deinit
[2017-09-13 16:19:42] [  LOG]     main: Cache deinit
[2017-09-13 16:19:42] [  LOG]     main: Worker deinit
[2017-09-13 16:19:42] [  LOG]     main: Database deinit
[2017-09-13 16:19:42] [  LOG]     main: Exiting.

Running 

 sudo /etc/init.d/forked-daapd restart

Starts fine after that.

Anyone seen this before?

Thanks

ejurgensen commented 7 years ago

The part of the log that you included is just the shutdown sequence. The interesting part would be before, there is probably some sort of fatal error reported.

1liminal1 commented 7 years ago

Sorry, annoyingly it was just before that.

[2017-09-13 16:54:42] [  LOG]     main: Got SIGTERM or SIGINT
[2017-09-13 16:54:42] [  LOG]     main: Stopping gracefully
ejurgensen commented 7 years ago

That just means that the OS told forked-daapd to stop. Why it would do that during boot I cannot explain.

1liminal1 commented 7 years ago

Im sorry to keep bugging you, how can I tell the service to restart after that.

Os is there a place to look as to why?

Thanks

ejurgensen commented 7 years ago

Er, restart? Don't you just want it to start on boot?

What platform is this? And how did you install forked-daapd?

1liminal1 commented 7 years ago

Sorry mate,

Its a Pi Zero w with jessie lite. I just installed it the usual way as per your guide

https://www.raspberrypi.org/forums/viewtopic.php?f=66&t=49928

SO after boot of the Pi, it looks like the OS is telling daapd to shutdown for some strange reason, if I restart it manually, it works. So what I wanted was to set up the service to auto restart on shutdown of daapd.

Apparently there is an .sh file that describes this? But I cant find it

Thanks :)

ejurgensen commented 7 years ago

You can perhaps achieve restart by editing forked-daapd.service and setting Restart=always, see this: https://www.freedesktop.org/software/systemd/man/systemd.service.html

I wouldn't recommend it, though. I think you should check system logs to find out what is killing forked-daapd.

1liminal1 commented 7 years ago

Ok, ill see what I can find in the logs, which so far is not much

tail -200 /var/log/messages

Im not seeing anything about Got SIGTERM or SIGINT

I am getting this, but its over and over, so think its more to do with raspotify trying to restart the service (was getting this reboot issue since I installed daapd, nothing to do with raspotify)

Sep 20 11:33:16 AirServer rsyslogd-2007: action 'action 17' suspended, next retr                                   y is Wed Sep 20 11:33:46 2017 [try http://www.rsyslog.com/e/2007 ]

Everything before that is the kernel booting up drivers ect.

I guess im looking in the wrong log, is there an application log like Windows?

1liminal1 commented 7 years ago

Right, so was looking in the wrong logs... of course ;)

the syslog shows me all the services, but strangely does not mention daapd on start up. I can see information about raspotify starting and the config ect.

But nothing about daapd 

Sep 22 13:33:52 AirServer kernel: [    0.957124] Init: Port Power? op_state=1
Sep 22 13:33:52 AirServer kernel: [    0.959753] Init: Power Port (0)
Sep 22 13:33:52 AirServer kernel: [    0.962600] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Sep 22 13:33:52 AirServer kernel: [    0.965194] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sep 22 13:33:52 AirServer kernel: [    0.967782] usb usb1: Product: DWC OTG Controller
Sep 22 13:33:52 AirServer kernel: [    0.970394] usb usb1: Manufacturer: Linux 4.9.35+ dwc_otg_hcd
Sep 22 13:33:52 AirServer kernel: [    0.972972] usb usb1: SerialNumber: 20980000.usb
Sep 22 13:33:52 AirServer kernel: [    0.976684] hub 1-0:1.0: USB hub found
Sep 22 13:33:52 AirServer kernel: [    0.979395] hub 1-0:1.0: 1 port detected
Sep 22 13:33:52 AirServer kernel: [    0.982630] dwc_otg: FIQ enabled
Sep 22 13:33:52 AirServer kernel: [    0.982640] dwc_otg: NAK holdoff enabled
Sep 22 13:33:52 AirServer kernel: [    0.982646] dwc_otg: FIQ split-transaction FSM enabled
Sep 22 13:33:52 AirServer kernel: [    0.982667] Module dwc_common_port init
Sep 22 13:33:52 AirServer kernel: [    0.983187] usbcore: registered new interface driver usb-storage
Sep 22 13:33:52 AirServer kernel: [    0.986200] mousedev: PS/2 mouse device common for all mice
Sep 22 13:33:52 AirServer kernel: [    0.990495] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
Sep 22 13:33:52 AirServer kernel: [    0.993681] bcm2835-cpufreq: min=700000 max=1000000
Sep 22 13:33:52 AirServer kernel: [    0.996905] sdhci: Secure Digital Host Controller Interface driver
Sep 22 13:33:52 AirServer kernel: [    0.999617] sdhci: Copyright(c) Pierre Ossman
Sep 22 13:33:52 AirServer kernel: [    1.002685] sdhost-bcm2835 20202000.sdhost: could not get clk, deferring probe
Sep 22 13:33:52 AirServer kernel: [    1.007938] mmc-bcm2835 20300000.mmc: could not get clk, deferring probe
Sep 22 13:33:52 AirServer kernel: [    1.011190] sdhci-pltfm: SDHCI platform and OF driver helper
Sep 22 13:33:52 AirServer kernel: [    1.014490] ledtrig-cpu: registered to indicate activity on CPUs
Sep 22 13:33:52 AirServer kernel: [    1.017446] hidraw: raw HID events driver (C) Jiri Kosina
Sep 22 13:33:52 AirServer kernel: [    1.020604] usbcore: registered new interface driver usbhid
Sep 22 13:33:52 AirServer kernel: [    1.023414] usbhid: USB HID core driver
Sep 22 13:33:52 AirServer kernel: [    1.027442] vchiq: vchiq_init_state: slot_zero = 0xdb580000, is_master = 0
Sep 22 13:33:52 AirServer kernel: [    1.032799] Initializing XFRM netlink socket
Sep 22 13:33:52 AirServer kernel: [    1.036145] NET: Registered protocol family 17
Sep 22 13:33:52 AirServer kernel: [    1.039566] Key type dns_resolver registered
Sep 22 13:33:52 AirServer kernel: [    1.044738] registered taskstats version 1
Sep 22 13:33:52 AirServer kernel: [    1.048029] vc-sm: Videocore shared memory driver
Sep 22 13:33:52 AirServer kernel: [    1.050937] [vc_sm_connected_init]: start
Sep 22 13:33:52 AirServer kernel: [    1.054850] [vc_sm_connected_init]: end - returning 0
Sep 22 13:33:52 AirServer kernel: [    1.066596] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
Sep 22 13:33:52 AirServer kernel: [    1.074863] sdhost: log_buf @ db513000 (5b513000)
Sep 22 13:33:52 AirServer kernel: [    1.149182] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Sep 22 13:33:52 AirServer kernel: [    1.154656] mmc-bcm2835 20300000.mmc: mmc_debug:0 mmc_debug2:0
Sep 22 13:33:52 AirServer kernel: [    1.157555] mmc-bcm2835 20300000.mmc: DMA channel allocated
Sep 22 13:33:52 AirServer kernel: [    1.190013] random: fast init done
Sep 22 13:33:52 AirServer kernel: [    1.239356] of_cfs_init
Sep 22 13:33:52 AirServer kernel: [    1.243330] of_cfs_init: OK
Sep 22 13:33:52 AirServer kernel: [    1.252225] Waiting for root device PARTUUID=d743c44a-02...
Sep 22 13:33:52 AirServer kernel: [    1.265201] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
Sep 22 13:33:52 AirServer kernel: [    1.269439] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Sep 22 13:33:52 AirServer kernel: [    1.273639] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Sep 22 13:33:52 AirServer kernel: [    1.279017] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Sep 22 13:33:52 AirServer kernel: [    1.298440] mmc0: host does not support reading read-only switch, assuming write-enable
Sep 22 13:33:52 AirServer kernel: [    1.306528] mmc0: new high speed SDHC card at address aaaa
Sep 22 13:33:52 AirServer kernel: [    1.310583] mmcblk0: mmc0:aaaa SL08G 7.40 GiB
Sep 22 13:33:52 AirServer kernel: [    1.315776]  mmcblk0: p1 p2
Sep 22 13:33:52 AirServer kernel: [    1.382641] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Sep 22 13:33:52 AirServer kernel: [    1.387657] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Sep 22 13:33:52 AirServer kernel: [    1.400108] devtmpfs: mounted
Sep 22 13:33:52 AirServer kernel: [    1.404073] Freeing unused kernel memory: 400K (c0840000 - c08a4000)
Sep 22 13:33:52 AirServer kernel: [    1.406650] This architecture does not have kernel memory protection.
Sep 22 13:33:52 AirServer kernel: [    1.417358] mmc1: new high speed SDIO card at address 0001
Sep 22 13:33:52 AirServer kernel: [    1.880646] NET: Registered protocol family 10
Sep 22 13:33:52 AirServer kernel: [    5.489312] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
Sep 22 13:33:52 AirServer kernel: [    6.432497] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Sep 22 13:33:52 AirServer kernel: [    7.289557] usbcore: registered new interface driver brcmfmac
Sep 22 13:33:52 AirServer kernel: [    7.465770] brcmfmac: Firmware version = wl0: Aug  7 2017 00:46:29 version 7.45.41.46 (r666254 CY) FWID 01-f8a78378
Sep 22 13:33:52 AirServer kernel: [   10.353337] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Sep 22 13:33:52 AirServer kernel: [   10.353429] brcmfmac: power management disabled
Sep 22 13:33:52 AirServer systemd[1]: Mounted Configuration File System.
Sep 22 13:33:52 AirServer systemd[1]: Started Apply Kernel Variables.
Sep 22 13:33:52 AirServer systemd[1]: Started Create Static Device Nodes in /dev.
Sep 22 13:33:52 AirServer systemd[1]: Starting udev Kernel Device Manager...
Sep 22 13:33:52 AirServer systemd[1]: Started udev Kernel Device Manager.
Sep 22 13:33:52 AirServer systemd[1]: Starting Copy rules generated while the root was ro...
Sep 22 13:33:52 AirServer systemd[1]: Starting LSB: Set preliminary keymap...
Sep 22 13:33:52 AirServer systemd-fsck[84]: e2fsck 1.43.3 (04-Sep-2016)
Sep 22 13:33:52 AirServer systemd-fsck[84]: /dev/mmcblk0p2: clean, 53982/451232 files, 540561/1928960 blocks
Sep 22 13:33:52 AirServer systemd[1]: Started Copy rules generated while the root was ro.
Sep 22 13:33:52 AirServer fake-hwclock[87]: Friday 22 September  03:33:45 UTC 2017
Sep 22 13:33:52 AirServer keyboard-setup[120]: Setting preliminary keymap...done.
Sep 22 13:33:52 AirServer systemd[1]: Started LSB: Set preliminary keymap.
Sep 22 13:33:52 AirServer systemd[1]: Starting Show Plymouth Boot Screen...
Sep 22 13:33:52 AirServer systemd[1]: Starting Remount Root and Kernel File Systems...
Sep 22 13:33:52 AirServer systemd[1]: Received SIGRTMIN+20 from PID 170 (plymouthd).
Sep 22 13:33:52 AirServer systemd[1]: Started Show Plymouth Boot Screen.
Sep 22 13:33:52 AirServer systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
Sep 22 13:33:52 AirServer systemd[1]: Starting Paths.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Paths.
Sep 22 13:33:52 AirServer systemd[1]: Starting Forward Password Requests to Plymouth Directory Watch.
Sep 22 13:33:52 AirServer systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
Sep 22 13:33:52 AirServer systemd[1]: Started Remount Root and Kernel File Systems.
Sep 22 13:33:52 AirServer systemd[1]: Started Various fixups to make systemd work better on Debian.
Sep 22 13:33:52 AirServer systemd[1]: Starting Load/Save Random Seed...
Sep 22 13:33:52 AirServer systemd[1]: Starting Local File Systems (Pre).
Sep 22 13:33:52 AirServer systemd[1]: Reached target Local File Systems (Pre).
Sep 22 13:33:52 AirServer systemd[1]: Started Load/Save Random Seed.
Sep 22 13:33:52 AirServer systemd[1]: Found device /dev/disk/by-partuuid/d743c44a-01.
Sep 22 13:33:52 AirServer systemd[1]: Starting File System Check on /dev/disk/by-partuuid/d743c44a-01...
Sep 22 13:33:52 AirServer systemd-fsck[182]: fsck.fat 3.0.27 (2014-11-12)
Sep 22 13:33:52 AirServer systemd-fsck[182]: /dev/mmcblk0p1: 147 files, 42846/82644 clusters
Sep 22 13:33:52 AirServer systemd[1]: Started File System Check on /dev/disk/by-partuuid/d743c44a-01.
Sep 22 13:33:52 AirServer systemd[1]: Mounting /boot...
Sep 22 13:33:52 AirServer systemd[1]: Mounted /boot.
Sep 22 13:33:52 AirServer systemd[1]: Starting Local File Systems.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Local File Systems.
Sep 22 13:33:52 AirServer systemd[1]: Starting Create Volatile Files and Directories...
Sep 22 13:33:52 AirServer systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...
Sep 22 13:33:52 AirServer systemd[1]: Starting Remote File Systems.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Remote File Systems.
Sep 22 13:33:52 AirServer systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
Sep 22 13:33:52 AirServer systemd[1]: Starting LSB: Prepare console...
Sep 22 13:33:52 AirServer systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Sep 22 13:33:52 AirServer systemd[1]: Starting LSB: Raise network interfaces....
Sep 22 13:33:52 AirServer systemd[1]: Started Tell Plymouth To Write Out Runtime Data.
Sep 22 13:33:52 AirServer systemd[1]: Started Create Volatile Files and Directories.
Sep 22 13:33:52 AirServer raspi-config[202]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Sep 22 13:33:52 AirServer systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
Sep 22 13:33:52 AirServer raspi-config[202]: No. Switching to ondemand scaling governor.
Sep 22 13:33:52 AirServer kbd[201]: Setting console screen modes.
Sep 22 13:33:52 AirServer systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Sep 22 13:33:52 AirServer systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Sep 22 13:33:52 AirServer systemd[1]: Started Update UTMP about System Boot/Shutdown.
Sep 22 13:33:52 AirServer systemd[1]: Starting Sound Card.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Sound Card.
Sep 22 13:33:52 AirServer kbd[201]: setterm: $TERM is not defined.
Sep 22 13:33:52 AirServer systemd[1]: Started LSB: Prepare console.
Sep 22 13:33:52 AirServer systemd[1]: Starting LSB: Set console font and keymap...
Sep 22 13:33:52 AirServer systemd[1]: Starting system-systemd\x2drfkill.slice.
Sep 22 13:33:52 AirServer systemd[1]: Created slice system-systemd\x2drfkill.slice.
Sep 22 13:33:52 AirServer systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill0...
Sep 22 13:33:52 AirServer systemd[1]: Started Load/Save RF Kill Switch Status of rfkill0.
Sep 22 13:33:52 AirServer systemd[1]: Starting system-ifup.slice.
Sep 22 13:33:52 AirServer systemd[1]: Created slice system-ifup.slice.
Sep 22 13:33:52 AirServer console-setup[253]: Setting up console font and keymap...done.
Sep 22 13:33:52 AirServer systemd[1]: Started LSB: Set console font and keymap.
Sep 22 13:33:52 AirServer networking[205]: Configuring network interfaces...done.
Sep 22 13:33:52 AirServer systemd[1]: Started LSB: Raise network interfaces..
Sep 22 13:33:52 AirServer systemd[1]: Starting ifup for wlan0...
Sep 22 13:33:52 AirServer systemd[1]: Started ifup for wlan0.
Sep 22 13:33:52 AirServer systemd[1]: Starting System Initialization.
Sep 22 13:33:52 AirServer systemd[1]: Reached target System Initialization.
Sep 22 13:33:52 AirServer systemd[1]: Starting Avahi mDNS/DNS-SD Stack Activation Socket.
Sep 22 13:33:52 AirServer systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Sep 22 13:33:52 AirServer systemd[1]: Starting D-Bus System Message Bus Socket.
Sep 22 13:33:52 AirServer systemd[1]: Listening on D-Bus System Message Bus Socket.
Sep 22 13:33:52 AirServer systemd[1]: Starting Sockets.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Sockets.
Sep 22 13:33:52 AirServer systemd[1]: Starting Daily Cleanup of Temporary Directories.
Sep 22 13:33:52 AirServer systemd[1]: Started Daily Cleanup of Temporary Directories.
Sep 22 13:33:52 AirServer systemd[1]: Starting Timers.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Timers.
Sep 22 13:33:52 AirServer systemd[1]: Started Manage Sound Card State (restore and store).
Sep 22 13:33:52 AirServer systemd[1]: Starting Restore Sound Card State...
Sep 22 13:33:52 AirServer systemd[1]: Starting Basic System.
Sep 22 13:33:52 AirServer systemd[1]: Reached target Basic System.
Sep 22 13:33:52 AirServer systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Sep 22 13:33:52 AirServer systemd[1]: Starting Regular background program processing daemon...
Sep 22 13:33:52 AirServer systemd[1]: Started Regular background program processing daemon.
Sep 22 13:33:52 AirServer systemd[1]: Starting Configure Bluetooth Modems connected by UART...
Sep 22 13:33:52 AirServer systemd[1]: Started Turn on SSH if /boot/ssh is present.
Sep 22 13:33:52 AirServer systemd[1]: Starting System Logging Service...
Sep 22 13:33:52 AirServer systemd[1]: Starting dhcpcd on all interfaces...
Sep 22 13:33:52 AirServer cron[354]: (CRON) INFO (pidfile fd = 3)
Sep 22 13:33:52 AirServer avahi-daemon[352]: Found user 'avahi' (UID 105) and group 'avahi' (GID 110).
Sep 22 13:33:52 AirServer avahi-daemon[352]: Successfully dropped root privileges.
Sep 22 13:33:52 AirServer avahi-daemon[352]: avahi-daemon 0.6.31 starting up.
Sep 22 13:33:52 AirServer cron[354]: (CRON) INFO (Running @reboot jobs)
Sep 22 13:33:52 AirServer systemd[1]: Starting D-Bus System Message Bus...
Sep 22 13:33:52 AirServer systemd[1]: Started D-Bus System Message Bus.
Sep 22 13:33:52 AirServer dhcpcd[364]: unknown option: See
Sep 22 13:33:52 AirServer dhcpcd[364]: version 6.7.1 starting
Sep 22 13:33:52 AirServer dhcpcd[364]: dev: loaded udev
Sep 22 13:33:52 AirServer dhcpcd[364]: dhcpcd[364]: unknown option: See
Sep 22 13:33:52 AirServer dhcpcd[364]: unknown option: See
Sep 22 13:33:52 AirServer dhcpcd[364]: wlan0: adding address fe80::f32f:9e13:2105:7e6a
Sep 22 13:33:53 AirServer wpa_supplicant[379]: Successfully initialized wpa_supplicant
Sep 22 13:33:53 AirServer kernel: [   11.176761] uart-pl011 20201000.serial: no DMA platform data
Sep 22 13:33:53 AirServer avahi-daemon[352]: Successfully called chroot().
Sep 22 13:33:53 AirServer avahi-daemon[352]: Successfully dropped remaining capabilities.
Sep 22 13:33:53 AirServer avahi-daemon[352]: No service file found in /etc/avahi/services.
Sep 22 13:33:53 AirServer avahi-daemon[352]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::f32f:9e13:2105:7e6a.
Sep 22 13:33:53 AirServer avahi-daemon[352]: New relevant interface wlan0.IPv6 for mDNS.
Sep 22 13:33:53 AirServer avahi-daemon[352]: Network interface enumeration completed.
Sep 22 13:33:53 AirServer avahi-daemon[352]: Registering new address record for fe80::f32f:9e13:2105:7e6a on wlan0.*.
Sep 22 13:33:53 AirServer avahi-daemon[352]: Registering HINFO record with values 'ARMV6L'/'LINUX'.
Sep 22 13:33:53 AirServer systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Sep 22 13:33:53 AirServer systemd[1]: Starting Login Service...
Sep 22 13:33:53 AirServer systemd[1]: Started getty on tty2-tty6 if dbus and logind are not available.
Sep 22 13:33:53 AirServer systemd[1]: Starting LSB: Autogenerate and use a swap file...
Sep 22 13:33:53 AirServer systemd[1]: Starting LSB: triggerhappy hotkey daemon...
Sep 22 13:33:53 AirServer systemd[1]: Started System Logging Service.
Sep 22 13:33:53 AirServer systemd[1]: Started Restore Sound Card State.
Sep 22 13:33:53 AirServer systemd[1]: Started Login Service.
Sep 22 13:33:53 AirServer avahi-daemon[352]: Server startup complete. Host name is AirServer.local. Local service cookie is 2467535316.
Sep 22 13:33:54 AirServer dphys-swapfile[407]: Starting dphys-swapfile swapfile setup ...
Sep 22 13:33:54 AirServer wpa_supplicant[436]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=AU
Sep 22 13:33:54 AirServer triggerhappy[411]: Error opening '/dev/input/event*': No such file or directory
Sep 22 13:33:54 AirServer systemd[1]: Started LSB: triggerhappy hotkey daemon.
Sep 22 13:33:54 AirServer dphys-swapfile[407]: want /var/swap=100MByte, checking existing: keeping it
Sep 22 13:33:54 AirServer kernel: [   13.021210] Adding 102396k swap on /var/swap.  Priority:-1 extents:5 across:200700k SSFS
Sep 22 13:33:54 AirServer dphys-swapfile[407]: done.
Sep 22 13:33:54 AirServer systemd[1]: Started LSB: Autogenerate and use a swap file.
Sep 22 13:33:55 AirServer wpa_supplicant[436]: wlan0: Trying to associate with e4:f4:c6:00:b1:ee (SSID='WLAN' freq=2462 MHz)
Sep 22 13:33:55 AirServer wpa_supplicant[436]: wlan0: Associated with e4:f4:c6:00:b1:ee
Sep 22 13:33:55 AirServer kernel: [   13.313108] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Sep 22 13:33:55 AirServer wpa_supplicant[436]: wlan0: WPA: Key negotiation completed with e4:f4:c6:00:b1:ee [PTK=CCMP GTK=CCMP]
Sep 22 13:33:55 AirServer wpa_supplicant[436]: wlan0: CTRL-EVENT-CONNECTED - Connection to e4:f4:c6:00:b1:ee completed [id=0 id_str=]
Sep 22 13:33:55 AirServer dhcpcd[364]: wlan0: waiting for carrier
Sep 22 13:33:55 AirServer dhcpcd[364]: wlan0: carrier acquired
Sep 22 13:33:55 AirServer dhcpcd[364]: unknown option: See
Sep 22 13:33:55 AirServer dhcpcd[364]: DUID 00:01:00:01:20:7e:16:33:b8:27:eb:04:e7:c1
Sep 22 13:33:55 AirServer dhcpcd[364]: wlan0: IAID eb:04:e7:c1
Sep 22 13:33:55 AirServer dhcpcd[364]: wlan0: soliciting an IPv6 router
Sep 22 13:33:56 AirServer dhcpcd[364]: wlan0: using static address 192.168.190.18/24
Sep 22 13:33:56 AirServer avahi-daemon[352]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.190.18.
Sep 22 13:33:56 AirServer dhcpcd[364]: wlan0: adding route to 192.168.190.0/24
Sep 22 13:33:56 AirServer dhcpcd[364]: wlan0: adding default route via 192.168.190.1
Sep 22 13:33:56 AirServer avahi-daemon[352]: New relevant interface wlan0.IPv4 for mDNS.
Sep 22 13:33:56 AirServer avahi-daemon[352]: Registering new address record for 192.168.190.18 on wlan0.IPv4.
Sep 22 13:33:56 AirServer dhcpcd[364]: forked to background, child pid 599
Sep 22 13:33:56 AirServer systemd[1]: Started dhcpcd on all interfaces.
Sep 22 13:33:56 AirServer systemd[1]: Starting Network.
Sep 22 13:33:56 AirServer systemd[1]: Reached target Network.
Sep 22 13:33:56 AirServer systemd[1]: Starting OpenBSD Secure Shell server...
Sep 22 13:33:56 AirServer systemd[1]: Started OpenBSD Secure Shell server.
Sep 22 13:33:56 AirServer systemd[1]: Starting Raspotify...
Sep 22 13:33:56 AirServer systemd[1]: Starting /etc/rc.local Compatibility...
Sep 22 13:33:56 AirServer systemd[1]: Starting Permit User Sessions...
Sep 22 13:33:56 AirServer systemd[1]: Starting Network is Online.
Sep 22 13:33:56 AirServer systemd[1]: Reached target Network is Online.
Sep 22 13:33:56 AirServer systemd[1]: Starting LSB: Start NTP daemon...
Sep 22 13:33:57 AirServer systemd[1]: Started /etc/rc.local Compatibility.
Sep 22 13:33:57 AirServer systemd[1]: Started Permit User Sessions.
Sep 22 13:33:57 AirServer systemd[1]: Started Raspotify.
Sep 22 13:33:57 AirServer ntpd[621]: ntpd 4.2.6p5@1.2349-o Mon Jul 25 22:35:28 UTC 2016 (1)
Sep 22 13:33:57 AirServer librespot[618]: INFO:librespot: librespot ddfc28f (2017-08-04). Built on 2017-08-07. Build ID: N5RcEuis
Sep 22 13:33:57 AirServer ntp[605]: Starting NTP server: ntpd.
Sep 22 13:33:57 AirServer ntpd[622]: proto: precision = 1.000 usec
Sep 22 13:33:57 AirServer ntpd[622]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Sep 22 13:33:57 AirServer systemd[1]: Started LSB: Start NTP daemon.
Sep 22 13:33:57 AirServer ntpd[622]: Listen and drop on 1 v6wildcard :: UDP 123
Sep 22 13:33:57 AirServer ntpd[622]: Listen normally on 2 lo 127.0.0.1 UDP 123
Sep 22 13:33:57 AirServer ntpd[622]: Listen normally on 3 wlan0 192.168.190.18 UDP 123
Sep 22 13:33:57 AirServer ntpd[622]: Listen normally on 4 wlan0 fe80::f32f:9e13:2105:7e6a UDP 123
Sep 22 13:33:57 AirServer ntpd[622]: Listen normally on 5 lo ::1 UDP 123
Sep 22 13:33:57 AirServer ntpd[622]: peers refreshed
Sep 22 13:33:57 AirServer ntpd[622]: Listening on routing socket on fd #22 for interface updates
Sep 22 13:33:57 AirServer systemd[1]: Starting Terminate Plymouth Boot Screen...
Sep 22 13:33:57 AirServer systemd[1]: Starting Hold until boot process finishes up...
Sep 22 13:33:57 AirServer kernel: [   15.680534] Bluetooth: Core ver 2.22
Sep 22 13:33:57 AirServer kernel: [   15.680635] NET: Registered protocol family 31
Sep 22 13:33:57 AirServer kernel: [   15.680641] Bluetooth: HCI device and connection manager initialized
Sep 22 13:33:57 AirServer kernel: [   15.680665] Bluetooth: HCI socket layer initialized
Sep 22 13:33:57 AirServer kernel: [   15.680679] Bluetooth: L2CAP socket layer initialized
Sep 22 13:33:57 AirServer kernel: [   15.680723] Bluetooth: SCO socket layer initialized
Sep 22 13:33:57 AirServer kernel: [   15.714018] Bluetooth: HCI UART driver ver 2.3
Sep 22 13:33:57 AirServer kernel: [   15.714033] Bluetooth: HCI UART protocol H4 registered
Sep 22 13:33:57 AirServer kernel: [   15.714037] Bluetooth: HCI UART protocol Three-wire (H5) registered
Sep 22 13:33:57 AirServer kernel: [   15.714179] Bluetooth: HCI UART protocol Broadcom registered
Sep 22 13:33:57 AirServer btuart[356]: bcm43xx_init
Sep 22 13:33:57 AirServer btuart[356]: Flash firmware /lib/firmware/BCM43430A1.hcd
Sep 22 13:33:57 AirServer btuart[356]: Set BDADDR UART: b8:27:eb:fb:18:3e
Sep 22 13:33:57 AirServer btuart[356]: Set Controller UART speed to 3000000 bit/s
Sep 22 13:33:57 AirServer btuart[356]: Device setup complete
Sep 22 13:33:57 AirServer systemd[1]: Started Configure Bluetooth Modems connected by UART.
Sep 22 13:33:57 AirServer systemd[1]: Started Terminate Plymouth Boot Screen.
Sep 22 13:33:57 AirServer systemd[1]: Started Hold until boot process finishes up.
Sep 22 13:33:57 AirServer librespot[618]: INFO:librespot_core::session: Connecting to AP "gae2-accesspoint-b-t78w.ap.spotify.com:4070"
Sep 22 13:33:57 AirServer systemd[1]: Received SIGRTMIN+21 from PID 170 (n/a).
Sep 22 13:33:57 AirServer systemd[1]: Starting Load/Save RF Kill Switch Status of rfkill1...
Sep 22 13:33:57 AirServer systemd[1]: Starting Bluetooth service...
Sep 22 13:33:57 AirServer systemd[1]: Starting Getty on tty1...
Sep 22 13:33:57 AirServer systemd[1]: Started Getty on tty1.
Sep 22 13:33:57 AirServer systemd[1]: Starting Login Prompts.
Sep 22 13:33:57 AirServer systemd[1]: Reached target Login Prompts.
Sep 22 13:33:57 AirServer systemd[1]: Starting Multi-User System.
Sep 22 13:33:57 AirServer systemd[1]: Reached target Multi-User System.
Sep 22 13:33:57 AirServer systemd[1]: Starting Graphical Interface.
Sep 22 13:33:57 AirServer systemd[1]: Reached target Graphical Interface.
Sep 22 13:33:57 AirServer systemd[1]: Starting Update UTMP about System Runlevel Changes...
Sep 22 13:33:58 AirServer bluetoothd[646]: Bluetooth daemon 5.23
Sep 22 13:33:58 AirServer systemd[1]: Started Load/Save RF Kill Switch Status of rfkill1.
Sep 22 13:33:58 AirServer bluetoothd[646]: Starting SDP server
Sep 22 13:33:58 AirServer kernel: [   16.214854] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Sep 22 13:33:58 AirServer kernel: [   16.214866] Bluetooth: BNEP filters: protocol multicast
Sep 22 13:33:58 AirServer kernel: [   16.214894] Bluetooth: BNEP socket layer initialized
Sep 22 13:33:58 AirServer systemd[1]: Started Bluetooth service.
Sep 22 13:33:58 AirServer bluetoothd[646]: Bluetooth management interface 1.14 initialized
Sep 22 13:33:58 AirServer dbus[367]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
Sep 22 13:33:58 AirServer bluetoothd[646]: Sap driver initialization failed.
Sep 22 13:33:58 AirServer bluetoothd[646]: sap-server: Operation not permitted (1)
Sep 22 13:33:58 AirServer systemd[1]: Started Update UTMP about System Runlevel Changes.
Sep 22 13:33:58 AirServer systemd[1]: Starting Hostname Service...
Sep 22 13:33:58 AirServer systemd[1]: Starting Bluetooth.
Sep 22 13:33:58 AirServer systemd[1]: Reached target Bluetooth.
Sep 22 13:33:58 AirServer systemd-hostnamed[653]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname!
Sep 22 13:33:58 AirServer dbus[367]: [system] Successfully activated service 'org.freedesktop.hostname1'
Sep 22 13:33:58 AirServer systemd[1]: Started Hostname Service.
Sep 22 13:33:58 AirServer systemd[1]: Startup finished in 1.610s (kernel) + 15.243s (userspace) = 16.854s.
Sep 22 13:34:00 AirServer librespot[618]: INFO:librespot_core::session: Authenticated as "NAME" !
Sep 22 13:34:00 AirServer librespot[618]: INFO:librespot_core::session: Country: "AU"
Sep 22 13:34:13 AirServer systemd[1]: Time has been changed
Sep 22 13:34:18 AirServer dhcpcd[599]: wlan0: no IPv6 Routers available
Sep 22 13:39:56 AirServer kernel: [  365.782236] random: crng init done
hkuehl commented 7 years ago

I encounter the exact same problem: after a reboot of my Pi3B with Raspbian Stretch, the service won't come up again. Starting it manually always works. I can't find any errors during startup. It seems the service is not even started...strange...

ejurgensen commented 7 years ago

That issue sounds more like this one https://github.com/ejurgensen/forked-daapd/issues/430. It is fixed here on github, but I have yet to make a new RPi release with the fix.

The issue above is different - it is not that it is not starting, it is that something is killing it after it starts.

hkuehl commented 7 years ago

Thanks for the quick reply. #430 does seem to be my case. Waiting for the new release! :-)

Thanks for the great work!

ejurgensen commented 7 years ago

I don't think I will be able to figure out what is killing your forked-daapd, OP, so I am closing this issue.

1liminal1 commented 6 years ago

Ok thanks :)