MiczFlor / RPi-Jukebox-RFID

A Raspberry Pi jukebox, playing local music, podcasts, web radio and streams triggered by RFID cards, web app or home automation. All plug and play via USB. GPIO scripts available.
http://phoniebox.de
MIT License
1.41k stars 398 forks source link

Neither onOff Shim nor shutdown -h 0 powers Raspi off #1194

Closed Barzille closed 1 year ago

Barzille commented 3 years ago

Bug

What I did

Powering down using onoff shim or using "sudo shutdown -h 0" or using ./scripts/playout_controls.sh -c=shutdown helps.

What happened

I expected this to happen

The Raspi is disconnected and shutdown completely so I can restart it using the shim

Further information that might help


pi@raspberrypi:~/RPi-Jukebox-RFID $ ./scripts/playout_controls.sh -c=shutdown
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
volume: n/a   repeat: off   random: off   single: off   consume: off
High Performance MPEG 1.0/2.0/2.5 Audio Player for Layers 1, 2 and 3
    version 1.25.10; written and copyright by Michael Hipp and others
    free software (LGPL) without any warranty but with best wishes

Directory: /home/pi/RPi-Jukebox-RFID/scripts/../shared/

Terminal control enabled, press 'h' for listing of keys and functions.

Playing MPEG stream 1 of 1: shutdownsound.mp3 ...

MPEG 1.0 L III cbr64 44100 mono

[0:02] Decoding of shutdownsound.mp3 finished.
Shutdown scheduled for Fri 2020-12-11 13:07:46 GMT, use 'shutdown -c' to cancel.
pi@raspberrypi:~ $ tail -n 500 /var/log/syslog
Dec 11 13:12:51 raspberrypi kernel: [    7.491154] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
Dec 11 13:12:51 raspberrypi kernel: [    7.492002] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd
Dec 11 13:12:51 raspberrypi kernel: [    8.716817] Under-voltage detected! (0x00050000)
Dec 11 13:12:51 raspberrypi systemd[1]: Started System Logging Service.
Dec 11 13:12:51 raspberrypi systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Dec 11 13:12:51 raspberrypi rngd[440]: rngd 2-unofficial-mt.14 starting up...
Dec 11 13:12:51 raspberrypi kernel: [    9.877558] uart-pl011 3f201000.serial: no DMA platform data
Dec 11 13:12:51 raspberrypi rng-tools[424]: Starting Hardware RNG entropy gatherer daemon: rngd.
Dec 11 13:12:51 raspberrypi systemd[1]: Started Deferred execution scheduler.
Dec 11 13:12:51 raspberrypi systemd[1]: Started rng-tools.service.
Dec 11 13:12:51 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Dec 11 13:12:51 raspberrypi thd[435]: Found socket passed from systemd
Dec 11 13:12:51 raspberrypi kernel: [    9.886786] 8021q: 802.1Q VLAN Support v1.8
Dec 11 13:12:51 raspberrypi rngd[440]: entropy feed to the kernel ready
Dec 11 13:12:51 raspberrypi dhcpcd[377]: `' is not a valid IP address
Dec 11 13:12:51 raspberrypi dhcpcd[377]: `' is not a valid IP address
Dec 11 13:12:51 raspberrypi systemd[1]: Started Check for v3d driver.
Dec 11 13:12:51 raspberrypi kernel: [    9.917324] random: crng init done
Dec 11 13:12:51 raspberrypi kernel: [    9.917343] random: 7 urandom warning(s) missed due to ratelimiting
Dec 11 13:12:51 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Dec 11 13:12:51 raspberrypi dhcpcd[377]: forked to background, child pid 445
Dec 11 13:12:51 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Dec 11 13:12:51 raspberrypi dphys-swapfile[395]: want /var/swap=100MByte, checking existing: keeping it
Dec 11 13:12:51 raspberrypi udisksd[431]: udisks daemon version 2.8.1 starting
Dec 11 13:12:51 raspberrypi systemd[1]: Reached target Sound Card.
Dec 11 13:12:51 raspberrypi dbus-daemon[409]: [system] Successfully activated service 'org.freedesktop.systemd1'
Dec 11 13:12:51 raspberrypi systemd[1]: Started Login Service.
Dec 11 13:12:51 raspberrypi wpa_supplicant[416]: Successfully initialized wpa_supplicant
Dec 11 13:12:51 raspberrypi avahi-daemon[392]: Successfully called chroot().
Dec 11 13:12:51 raspberrypi systemd[1]: Started WPA supplicant.
Dec 11 13:12:51 raspberrypi avahi-daemon[392]: Successfully dropped remaining capabilities.
Dec 11 13:12:51 raspberrypi cleanshutd[390]: Starting...
Dec 11 13:12:51 raspberrypi avahi-daemon[392]: No service file found in /etc/avahi/services.
Dec 11 13:12:51 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Dec 11 13:12:51 raspberrypi avahi-daemon[392]: Network interface enumeration completed.
Dec 11 13:12:51 raspberrypi systemd[1]: Reached target Network.
Dec 11 13:12:51 raspberrypi kernel: [   10.216870] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
Dec 11 13:12:51 raspberrypi avahi-daemon[392]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 2760753859.
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Permit User Sessions...
Dec 11 13:12:51 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Music Player Daemon...
Dec 11 13:12:51 raspberrypi dhcpcd-run-hooks[484]: wlan0: starting wpa_supplicant
Dec 11 13:12:51 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Dec 11 13:12:51 raspberrypi systemd[1]: Started Phoniebox GPIO Control Service.
Dec 11 13:12:51 raspberrypi systemd[1]: Reached target Network is Online.
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Samba NMB Daemon...
Dec 11 13:12:51 raspberrypi udisksd[431]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory
Dec 11 13:12:51 raspberrypi udisksd[431]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
Dec 11 13:12:51 raspberrypi systemd[1]: Starting LSB: exim Mail Transport Agent...
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Lighttpd Daemon...
Dec 11 13:12:51 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Dec 11 13:12:51 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Dec 11 13:12:51 raspberrypi udisksd[431]: Failed to load the 'mdraid' libblockdev plugin
Dec 11 13:12:51 raspberrypi udisksd[431]: Failed to load the 'crypto' libblockdev plugin
Dec 11 13:12:51 raspberrypi systemd[1]: Started Phoniebox Idle Watchdog Service.
Dec 11 13:12:51 raspberrypi dbus-daemon[409]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=431 comm="/usr/lib/udisks2/udisksd ")
Dec 11 13:12:51 raspberrypi systemd[1]: Started LSB: Monitoring GPIO shutdown trigger.
Dec 11 13:12:51 raspberrypi systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Dec 11 13:12:51 raspberrypi systemd[1]: Started Permit User Sessions.
Dec 11 13:12:51 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Dec 11 13:12:51 raspberrypi kernel: [   10.553152] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Authorization Manager...
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Dec 11 13:12:51 raspberrypi systemd[1]: Starting Light Display Manager...
Dec 11 13:12:51 raspberrypi kernel: [   10.797811] Voltage normalised (0x00000000)
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: connected to Access Point `'
Dec 11 13:12:52 raspberrypi raspi-config[399]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Dec 11 13:12:52 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Dec 11 13:12:52 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Dec 11 13:12:52 raspberrypi dhcpcd[445]: eth0: waiting for carrier
Dec 11 13:12:52 raspberrypi kernel: [   11.438786] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: waiting for carrier
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: carrier acquired
Dec 11 13:12:52 raspberrypi dhcpcd[445]: `' is not a valid IP address
Dec 11 13:12:52 raspberrypi dhcpcd[445]: DUID 00:01:00:01:26:d1:12:df:b8:27:eb:9f:fa:a5
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: IAID eb:9f:fa:a5
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: adding address fe80::ba27:ebff:fe9f:faa5
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: carrier lost
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe9f:faa5.
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: New relevant interface wlan0.IPv6 for mDNS.
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: Registering new address record for fe80::ba27:ebff:fe9f:faa5 on wlan0.*.
Dec 11 13:12:52 raspberrypi dhcpcd[445]: wlan0: deleting address fe80::ba27:ebff:fe9f:faa5
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: Withdrawing address record for fe80::ba27:ebff:fe9f:faa5 on wlan0.
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe9f:faa5.
Dec 11 13:12:52 raspberrypi avahi-daemon[392]: Interface wlan0.IPv6 no longer relevant for mDNS.
Dec 11 13:12:52 raspberrypi lightdm[517]: 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
Dec 11 13:12:52 raspberrypi polkitd[510]: started daemon version 0.105 using authority implementation `local' version `0.105'
Dec 11 13:12:52 raspberrypi dbus-daemon[409]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Dec 11 13:12:52 raspberrypi systemd[1]: Started Authorization Manager.
Dec 11 13:12:52 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 176 (plymouthd).
Dec 11 13:12:52 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 176 (plymouthd).
Dec 11 13:12:53 raspberrypi systemd[1]: plymouth-quit-wait.service: Succeeded.
Dec 11 13:12:53 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Dec 11 13:12:53 raspberrypi systemd[1]: Started Getty on tty1.
Dec 11 13:12:53 raspberrypi systemd[1]: Reached target Login Prompts.
Dec 11 13:12:53 raspberrypi systemd[1]: plymouth-start.service: Succeeded.
Dec 11 13:12:53 raspberrypi systemd[1]: Started Light Display Manager.
Dec 11 13:12:53 raspberrypi systemd[1]: Started Disk Manager.
Dec 11 13:12:53 raspberrypi udisksd[431]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Dec 11 13:12:53 raspberrypi systemd[1]: Started Lighttpd Daemon.
Dec 11 13:12:53 raspberrypi exim4[494]: Starting MTA: exim4.
Dec 11 13:12:53 raspberrypi systemd[1]: Started LSB: exim Mail Transport Agent.
Dec 11 13:12:53 raspberrypi kernel: [   12.484962] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: carrier acquired
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: connected to Access Point `Geheimes Netzwerk'
Dec 11 13:12:53 raspberrypi dhcpcd[445]: `' is not a valid IP address
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: IAID eb:9f:fa:a5
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: adding address fe80::ba27:ebff:fe9f:faa5
Dec 11 13:12:53 raspberrypi avahi-daemon[392]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe9f:faa5.
Dec 11 13:12:53 raspberrypi avahi-daemon[392]: New relevant interface wlan0.IPv6 for mDNS.
Dec 11 13:12:53 raspberrypi avahi-daemon[392]: Registering new address record for fe80::ba27:ebff:fe9f:faa5 on wlan0.*.
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:['VolumeControl', 'PrevNextControl', 'PlayPause', 'Shutdown', 'Volume0', 'VolumeUp', 'VolumeDown', 'NextSong', 'PrevSong', 'Halt']
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:adding GPIO-Device, VolumeControl
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:gpio_control:VolumeControl as TwoButtonControl
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.two_button_control:adding new action
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:{}: set when_pressed
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:add new action
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:{}: set when_pressed
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:add new action
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:adding GPIO-Device, PrevNextControl
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:adding TwoButtonControl
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: rebinding lease of 192.168.178.134
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.two_button_control:adding new action
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:{}: set when_pressed
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:add new action
Dec 11 13:12:53 raspberrypi dhcpcd[445]: wlan0: probing address 192.168.178.134/24
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:{}: set when_pressed
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:GPIODevices.simple_button:add new action
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:adding GPIO-Device, PlayPause
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device Shutdown not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device Volume0 not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device VolumeUp not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device VolumeDown not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device NextSong not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device PrevSong not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Device Halt not enabled
Dec 11 13:12:53 raspberrypi PhonieboxGPIOControl[491]: INFO:root:Ready for taking actions
Dec 11 13:12:54 raspberrypi daemon_rfid_reader.py[500]: 2020-12-11 13:12:54,181 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Dec 11 13:12:54 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Dec 11 13:12:54 raspberrypi dhcpcd[445]: wlan0: soliciting an IPv6 router
Dec 11 13:12:55 raspberrypi kernel: [   14.366163] Bluetooth: Core ver 2.22
Dec 11 13:12:55 raspberrypi kernel: [   14.366242] NET: Registered protocol family 31
Dec 11 13:12:55 raspberrypi kernel: [   14.366247] Bluetooth: HCI device and connection manager initialized
Dec 11 13:12:55 raspberrypi kernel: [   14.366268] Bluetooth: HCI socket layer initialized
Dec 11 13:12:55 raspberrypi kernel: [   14.366279] Bluetooth: L2CAP socket layer initialized
Dec 11 13:12:55 raspberrypi kernel: [   14.366299] Bluetooth: SCO socket layer initialized
Dec 11 13:12:55 raspberrypi btuart[381]: bcm43xx_init
Dec 11 13:12:55 raspberrypi btuart[381]: Flash firmware /lib/firmware/brcm/BCM43430A1.hcd
Dec 11 13:12:55 raspberrypi btuart[381]: Set BDADDR UART: b8:27:eb:60:05:5a
Dec 11 13:12:55 raspberrypi btuart[381]: Set Controller UART speed to 921600 bit/s
Dec 11 13:12:55 raspberrypi btuart[381]: Device setup complete
Dec 11 13:12:55 raspberrypi kernel: [   14.387639] Bluetooth: HCI UART driver ver 2.3
Dec 11 13:12:55 raspberrypi kernel: [   14.387652] Bluetooth: HCI UART protocol H4 registered
Dec 11 13:12:55 raspberrypi kernel: [   14.387700] Bluetooth: HCI UART protocol Three-wire (H5) registered
Dec 11 13:12:55 raspberrypi kernel: [   14.387861] Bluetooth: HCI UART protocol Broadcom registered
Dec 11 13:12:55 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Dec 11 13:12:55 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Dec 11 13:12:55 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Dec 11 13:12:55 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Dec 11 13:12:55 raspberrypi systemd[1]: Starting Bluetooth service...
Dec 11 13:12:55 raspberrypi bluetoothd[935]: Bluetooth daemon 5.50
Dec 11 13:12:55 raspberrypi systemd[1]: Started Bluetooth service.
Dec 11 13:12:55 raspberrypi bluetoothd[935]: Starting SDP server
Dec 11 13:12:55 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Dec 11 13:12:55 raspberrypi systemd[1]: Reached target Bluetooth.
Dec 11 13:12:55 raspberrypi systemd[1]: Started BluezALSA proxy.
Dec 11 13:12:55 raspberrypi kernel: [   14.767942] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Dec 11 13:12:55 raspberrypi kernel: [   14.767953] Bluetooth: BNEP filters: protocol multicast
Dec 11 13:12:55 raspberrypi kernel: [   14.767974] Bluetooth: BNEP socket layer initialized
Dec 11 13:12:55 raspberrypi bthelper[944]: Raspberry Pi BDADDR already set
Dec 11 13:12:55 raspberrypi bluetoothd[935]: Bluetooth management interface 1.14 initialized
Dec 11 13:12:55 raspberrypi dbus-daemon[409]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.9' (uid=0 pid=935 comm="/usr/lib/bluetooth/bluetoothd ")
Dec 11 13:12:55 raspberrypi bluetoothd[935]: Sap driver initialization failed.
Dec 11 13:12:55 raspberrypi bluetoothd[935]: sap-server: Operation not permitted (1)
Dec 11 13:12:56 raspberrypi systemd[1]: Starting Hostname Service...
Dec 11 13:12:56 raspberrypi bluetoothd[935]: Endpoint registered: sender=:1.10 path=/org/bluez/hci0/A2DP/SBC/Source/1
Dec 11 13:12:56 raspberrypi bluetoothd[935]: Endpoint registered: sender=:1.10 path=/org/bluez/hci0/A2DP/SBC/Source/2
Dec 11 13:12:56 raspberrypi kernel: [   14.849488] Bluetooth: RFCOMM TTY layer initialized
Dec 11 13:12:56 raspberrypi kernel: [   14.849510] Bluetooth: RFCOMM socket layer initialized
Dec 11 13:12:56 raspberrypi kernel: [   14.849534] Bluetooth: RFCOMM ver 1.11
Dec 11 13:12:56 raspberrypi bluetoothd[935]: Failed to set privacy: Rejected (0x0b)
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001112-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000111f-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A Alias: BlueZ 5.50
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A Pairable: yes
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A Class: 0x00080000
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001112-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000111f-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001112-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A UUIDs: 0000111f-0000-1000-8000-00805f9b34fb
Dec 11 13:12:56 raspberrypi bthelper[944]: Changing power off succeeded
Dec 11 13:12:56 raspberrypi dbus-daemon[409]: [system] Successfully activated service 'org.freedesktop.hostname1'
Dec 11 13:12:56 raspberrypi systemd[1]: Started Hostname Service.
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A Class: 0x00480000
Dec 11 13:12:56 raspberrypi bthelper[944]: Changing power on succeeded
Dec 11 13:12:56 raspberrypi bthelper[944]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:60:05:5A Powered: yes
Dec 11 13:12:56 raspberrypi systemd[1]: bthelper@hci0.service: Succeeded.
Dec 11 13:12:56 raspberrypi lightdm[973]: 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
Dec 11 13:12:56 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Dec 11 13:12:56 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Dec 11 13:12:56 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Dec 11 13:12:56 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Dec 11 13:12:57 raspberrypi mpd: zeroconf: No global port, disabling zeroconf
Dec 11 13:12:57 raspberrypi systemd[1]: Started Music Player Daemon.
Dec 11 13:12:57 raspberrypi systemd[1]: Starting Phoniebox Startup...
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOFOLDERSPATH="/home/pi/RPi-Jukebox-RFID/shared/audiofolders"
Dec 11 13:12:57 raspberrypi bash[993]: PLAYLISTSFOLDERPATH="/home/pi/RPi-Jukebox-RFID/playlists"
Dec 11 13:12:57 raspberrypi bash[993]: SECONDSWIPE="RESTART"
Dec 11 13:12:57 raspberrypi bash[993]: SECONDSWIPEPAUSE="2"
Dec 11 13:12:57 raspberrypi bash[993]: SECONDSWIPEPAUSECONTROLS="ON"
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOIFACENAME="Headphone"
Dec 11 13:12:57 raspberrypi bash[993]: VOLUMEMANAGER="amixer"
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOVOLCHANGESTEP="3"
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOVOLMAXLIMIT="100"
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOVOLMINLIMIT="1"
Dec 11 13:12:57 raspberrypi bash[993]: AUDIOVOLSTARTUP="40"
Dec 11 13:12:57 raspberrypi bash[993]: VOLCHANGEIDLE="TRUE"
Dec 11 13:12:57 raspberrypi bash[993]: IDLETIMESHUTDOWN="0"
Dec 11 13:12:57 raspberrypi bash[993]: POWEROFFCMD="sudo shutdown -h 0"
Dec 11 13:12:57 raspberrypi bash[993]: SHOWCOVER="ON"
Dec 11 13:12:57 raspberrypi bash[993]: READWLANIPYN="OFF"
Dec 11 13:12:57 raspberrypi bash[993]: EDITION="classic"
Dec 11 13:12:57 raspberrypi bash[993]: LANG="de-DE"
Dec 11 13:12:57 raspberrypi bash[993]: VERSION="2.2 - 305325d - master"
Dec 11 13:12:57 raspberrypi bash[993]: CMDVOLUP=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDVOLDOWN=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDNEXT=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDPREV=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDREWIND=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDSEEKFORW=""
Dec 11 13:12:57 raspberrypi bash[993]: CMDSEEKBACK=""
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on GnuPG network certificate management daemon.
Dec 11 13:12:57 raspberrypi systemd[978]: Reached target Paths.
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on GnuPG cryptographic agent and passphrase cache.
Dec 11 13:12:57 raspberrypi systemd[978]: Reached target Timers.
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Dec 11 13:12:57 raspberrypi systemd[978]: Starting D-Bus User Message Bus Socket.
Dec 11 13:12:57 raspberrypi bash[993]: 40 is the mpd startup volume
Dec 11 13:12:57 raspberrypi systemd[978]: Listening on D-Bus User Message Bus Socket.
Dec 11 13:12:57 raspberrypi systemd[978]: Reached target Sockets.
Dec 11 13:12:57 raspberrypi systemd[978]: Reached target Basic System.
Dec 11 13:12:57 raspberrypi systemd[1]: Started User Manager for UID 1000.
Dec 11 13:12:57 raspberrypi systemd[978]: Starting Music Player Daemon...
Dec 11 13:12:57 raspberrypi systemd[1]: Started Session 1 of user pi.
Dec 11 13:12:57 raspberrypi mpd: exception: Failed to read mixer for 'My ALSA Device': no such mixer control: Master
Dec 11 13:12:57 raspberrypi systemd[978]: Started D-Bus User Message Bus.
Dec 11 13:12:57 raspberrypi bash[993]: Simple mixer control 'Headphone',0
Dec 11 13:12:57 raspberrypi bash[993]:   Capabilities: pvolume pvolume-joined pswitch pswitch-joined
Dec 11 13:12:57 raspberrypi bash[993]:   Playback channels: Mono
Dec 11 13:12:57 raspberrypi bash[993]:   Limits: Playback -10239 - 400
Dec 11 13:12:57 raspberrypi bash[993]:   Mono: Playback -5983 [40%] [-59.83dB] [on]
Dec 11 13:12:57 raspberrypi bash[993]: 13107 is the mpg123 startup volume
Dec 11 13:12:57 raspberrypi bash[993]: High Performance MPEG 1.0/2.0/2.5 Audio Player for Layers 1, 2 and 3
Dec 11 13:12:57 raspberrypi bash[993]: #011version 1.25.10; written and copyright by Michael Hipp and others
Dec 11 13:12:57 raspberrypi bash[993]: #011free software (LGPL) without any warranty but with best wishes
Dec 11 13:12:57 raspberrypi bash[993]: Directory: /home/pi/RPi-Jukebox-RFID/shared/
Dec 11 13:12:57 raspberrypi bash[993]: Playing MPEG stream 1 of 1: startupsound.mp3 ...
Dec 11 13:12:57 raspberrypi bash[993]: MPEG 1.0 L III cbr64 44100 j-s
Dec 11 13:12:57 raspberrypi bash[993]: Artist:  Phoniebox
Dec 11 13:12:58 raspberrypi mpd: exception: Failed to bind to '[::1]:6600'
Dec 11 13:12:58 raspberrypi mpd: exception: nested: Failed to bind socket: Address already in use
Dec 11 13:12:58 raspberrypi systemd[1]: Started Session 3 of user pi.
Dec 11 13:12:58 raspberrypi systemd[978]: mpd.service: Main process exited, code=exited, status=1/FAILURE
Dec 11 13:12:58 raspberrypi systemd[978]: mpd.service: Failed with result 'exit-code'.
Dec 11 13:12:58 raspberrypi systemd[978]: Failed to start Music Player Daemon.
Dec 11 13:12:58 raspberrypi systemd[978]: Reached target Default.
Dec 11 13:12:58 raspberrypi systemd[978]: Startup finished in 1.745s.
Dec 11 13:12:58 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=1010 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ")
Dec 11 13:12:58 raspberrypi systemd[978]: Starting Virtual filesystem service...
Dec 11 13:12:58 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.Daemon'
Dec 11 13:12:58 raspberrypi systemd[978]: Started Virtual filesystem service.
Dec 11 13:12:58 raspberrypi kernel: [   17.469159] fuse: init (API version 7.31)
Dec 11 13:12:58 raspberrypi systemd[1]: Mounting FUSE Control File System...
Dec 11 13:12:58 raspberrypi systemd[1]: Mounted FUSE Control File System.
Dec 11 13:12:59 raspberrypi dhcpcd[445]: wlan0: leased 192.168.178.134 for 86400 seconds
Dec 11 13:12:59 raspberrypi avahi-daemon[392]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.134.
Dec 11 13:12:59 raspberrypi avahi-daemon[392]: New relevant interface wlan0.IPv4 for mDNS.
Dec 11 13:12:59 raspberrypi avahi-daemon[392]: Registering new address record for 192.168.178.134 on wlan0.IPv4.
Dec 11 13:12:59 raspberrypi dhcpcd[445]: wlan0: adding route to 192.168.178.0/24
Dec 11 13:12:59 raspberrypi dhcpcd[445]: wlan0: adding default route via 192.168.178.1
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1128 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 11 13:12:59 raspberrypi systemd[978]: Starting Virtual filesystem service - disk device monitor...
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Dec 11 13:12:59 raspberrypi systemd[978]: Started Virtual filesystem service - disk device monitor.
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1128 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 11 13:12:59 raspberrypi systemd[978]: Starting Virtual filesystem service - Apple File Conduit monitor...
Dec 11 13:12:59 raspberrypi gvfs-afc-volume-monitor[1220]: Volume monitor alive
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Dec 11 13:12:59 raspberrypi systemd[978]: Started Virtual filesystem service - Apple File Conduit monitor.
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1128 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 11 13:12:59 raspberrypi systemd[978]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Dec 11 13:12:59 raspberrypi systemd[978]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Dec 11 13:12:59 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1128 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 11 13:13:00 raspberrypi systemd[978]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Dec 11 13:13:00 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Dec 11 13:13:00 raspberrypi systemd[978]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Dec 11 13:13:00 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1128 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 11 13:13:00 raspberrypi systemd[978]: Starting Virtual filesystem service - digital camera monitor...
Dec 11 13:13:00 raspberrypi dbus-daemon[1022]: [session uid=1000 pid=1022] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Dec 11 13:13:00 raspberrypi systemd[978]: Started Virtual filesystem service - digital camera monitor.
Dec 11 13:13:00 raspberrypi mpd: exception: Failed to bind to '[::1]:6600'
Dec 11 13:13:00 raspberrypi mpd: exception: nested: Failed to bind socket: Address already in use
Dec 11 13:13:00 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Dec 11 13:13:01 raspberrypi bash[993]: [0:04] Decoding of startupsound.mp3 finished.
Dec 11 13:13:01 raspberrypi bash[993]: Updating DB (#1) ...
Dec 11 13:13:01 raspberrypi bash[993]: volume: n/a   repeat: off   random: off   single: off   consume: off
Dec 11 13:13:01 raspberrypi systemd[1]: Started Phoniebox Startup.
Dec 11 13:13:01 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-02 Beachball.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-16 Seven Days And One Week.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-14 Ayla - Ayla (Part 2).mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-19 Instant Moments.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-08 Together (Phase 1) (Edit).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-13 Galaktika '98.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-05 9PM (Till I Come).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-20 ALL Over THE World (Dream Dance MIX).mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-11 Follow Me (X-Ray).mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-03 Water Wave.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-04 The Age Of Love.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-20 Sonic Empire.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-16 Get Ready To Bounce.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-15 Café Del Mar.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-18 The Awakening.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-07 Love Stimulation.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-10 Pulverturm.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-05 The Circle (Radio Edit) (Vocal Version).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-13 Das Glockenspiel.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-14 Children.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-01 Insomnia.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-10 The Flow (Deep) (Extended Vocal Club Mix).mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-04 1999 (Kay Cee Rmx).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-01 Welcome To Planet Dream Dance (Intro).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-11 Universal Nation (The Real Anthem).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-12 Sunshine.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-15 Ayla.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-06 Planet Violet (Radio Edit).mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-07 Protect Your Mind (Braveheart) (Ayla Rmx).mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-02 The Final.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-06 Meet Her At The Loveparade.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:02 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-03 Offshore.mp3
Dec 11 13:13:02 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-19 Too Much Rain.mp3
Dec 11 13:13:02 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-17 Your Own Reality.mp3
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-09 Why Don't You Dance With Me.mp3
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-08 X Files.mp3
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/2-18 For An Angel.mp3
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-12 Try It (Original Club Mix).mp3
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:03 raspberrypi mpd: update: updating Best Of Dream Dance_ The Special Megamix Edition/1-17 Encore Une Fois (Future Breeze Rmx).mp3
Dec 11 13:13:03 raspberrypi mpd: mpg123: mpg123_getformat() failed: Message: I am done with this track.
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Format mp3 detected only with low score of 1, misdetection possible!
Dec 11 13:13:03 raspberrypi mpd: ffmpeg/mp3: Failed to read frame size: Could not seek to 5119.
Dec 11 13:13:04 raspberrypi systemd[1]: Started Samba NMB Daemon.
Dec 11 13:13:04 raspberrypi systemd[1]: Starting Samba SMB Daemon...
Dec 11 13:13:04 raspberrypi systemd[1]: Started Samba SMB Daemon.
Dec 11 13:13:04 raspberrypi systemd[1]: Reached target Multi-User System.
Dec 11 13:13:04 raspberrypi systemd[1]: Reached target Graphical Interface.
Dec 11 13:13:04 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Dec 11 13:13:04 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Dec 11 13:13:04 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Dec 11 13:13:04 raspberrypi systemd[1]: Startup finished in 3.229s (kernel) + 20.384s (userspace) = 23.613s.
Dec 11 13:13:07 raspberrypi dhcpcd[445]: wlan0: no IPv6 Routers available
Dec 11 13:13:19 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Dec 11 13:14:04 raspberrypi systemd-timesyncd[332]: Synchronized to time server for the first time 213.239.239.164:123 (2.debian.pool.ntp.org).
Dec 11 13:14:09 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Dec 11 13:14:14 raspberrypi systemd[1]: Started Session 4 of user pi.
Dec 11 13:14:36 raspberrypi systemd[1]: phoniebox-idle-watchdog.service: Succeeded.
Dec 11 13:17:01 raspberrypi CRON[4006]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)

Software

Base image and version

pi@raspberrypi:~ $ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

Branch / Release

master

Installscript

Hardware

RaspberryPi version

Raspberry Pi 3 Model B Rev 1.2

Other notable hardware

s-martin commented 3 years ago

Did you test, if the RPi can be started again with the on off shim after you shut down?

Barzille commented 3 years ago

Yes. That’s not working as it is still somehow powered

s-martin commented 3 years ago

Do you use a gpio button for shutdown command or the button on the onoff shim?

Barzille commented 3 years ago

At first the onoff shim button. Now I connected a push button to the shim -> same behaviour

But this is only the trigger as I mentioned above the shutdown command itself results in the same outcome

Barzille commented 3 years ago

When I power the RPi via direct current connection and not via the onOff Shim it has the same behavior (red light stays on), so it seems to me that the shim is not cutting the power connection, maybe it's defect. I have ordered a new one and will let you know once I checked that.

Barzille commented 3 years ago

And btw is this my clean shutdown config for the shim:

# Config for cleanshutd
# Commented out values will be reverted to defaults,
# and may not work on any given board.

# OnOff SHIM uses trigger 17 and poweroff 4
# Zero Lipo uses trigger 4 and poweroff off
# pHAT BEAT uses trigger 12 and powerof off
# Default values are trigger 4 and poweroff off

daemon_active=1
trigger_pin=17
led_pin=17
poweroff_pin=4
hold_time=2
shutdown_delay=0
polling_rate=1
s-martin commented 3 years ago

Unfortunately my Phoniebox w OnOffShim has a hardware defect, so I can’t check. Will get back to you as soon as I tested it.

s-martin commented 3 years ago

Does this work now?

Barzille commented 3 years ago

I haven’t received the new one yet

Barzille commented 3 years ago

I just tried with a new shim, same behavior. Is there anything I could check or look for in special?

Barzille commented 3 years ago

btw this is my gpio_setting.ini

[DEFAULT]
enabled: True
[VolumeControl]
enabled: True
Type: TwoButtonControl ;or RotaryEncoder
PinUp: 5
PinDown: 6
pull_up: True
hold_time: 0.3
hold_repeat: True
timeBase: 0.1 ;only for RotaryEncoder
functionCallDown: functionCallVolD
functionCallUp: functionCallVolU
functionCallTwoButtons: functionCallVol0 ;only for TwoButtonControl

[PrevNextControl]
enabled: False
Type: TwoButtonControl
Pin1: 22
Pin2: 23
functionCall1: functionCallPlayerPrev
functionCall2: functionCallPlayerNext
functionCallTwoButtons: None
pull_up: True
hold_time: 0.3
hold_repeat: False

[PlayPause]
enabled: True
Type: Button
Pin: 27
pull_up: True
hold_time: 0.3
functionCall: functionCallPlayerPause

[Shutdown]
enabled: False
Type:  Button
Pin: 3
pull_up: True
hold_time: 2
functionCall: functionCallShutdown

[Volume0]
enabled: False
Type:  Button
Pin: 17
pull_up: True
hold_time: 0.3
functionCall: functionCallVol0

[VolumeUp]
enabled: True
Type:  Button
Pin: 24
pull_up: True
hold_time: 0.3
hold_repeat: True
functionCall: functionCallVolU

[VolumeDown]
enabled: True
Type:  Button
Pin: 16
pull_up: True
hold_time: 0.3
hold_repeat: True
functionCall: functionCallVolD

[NextSong]
enabled: True
Type:  Button
Pin: 23
pull_up: True
hold_time: 0.3
functionCall: functionCallPlayerNext

[PrevSong]
enabled: True
Type:  Button
Pin: 13
pull_up: True
hold_time: 0.3
functionCall: functionCallPlayerPrev

[Halt]
enabled: False
Type:  Button
Pin: 21
pull_up: True
hold_time: 0.3
functionCall: functionCallPlayerPauseForce
Barzille commented 3 years ago

And this is the syslog after pushing the onOff Shim Button:

pi@raspberrypi:~/RPi-Jukebox-RFID/settings $ sudo tail -f /var/log/syslog
Dec 20 17:23:05 raspberrypi systemd[1]: man-db.service: Succeeded.
Dec 20 17:23:05 raspberrypi systemd[1]: Started Daily man-db regeneration.
Dec 20 17:23:06 raspberrypi systemd[1]: apt-daily.service: Succeeded.
Dec 20 17:23:06 raspberrypi systemd[1]: Started Daily apt download activities.
Dec 20 17:23:06 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
Dec 20 17:23:07 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Dec 20 17:23:08 raspberrypi systemd[1]: apt-daily-upgrade.service: Succeeded.
Dec 20 17:23:08 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Dec 20 17:23:19 raspberrypi systemd[1]: Started Session 4 of user pi.
Dec 20 17:23:33 raspberrypi systemd[1]: phoniebox-idle-watchdog.service: Succeeded.

Broadcast message from root@raspberrypi (somewhere) (Sun Dec 20 17:29:37 2020):

BCM 17 held low, system shutdown in 0 minutes

Dec 20 17:29:37 raspberrypi systemd[1]: systemd-rfkill.socket: Succeeded.
Dec 20 17:29:37 raspberrypi systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopped target Timers.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopped target Graphical Interface.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Session 3 of user pi.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopped target Multi-User System.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Samba SMB Daemon...
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Lighttpd Daemon...
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping LSB: exim Mail Transport Agent...
Dec 20 17:29:37 raspberrypi systemd[1]: gldriver-test.service: Succeeded.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopped Check for v3d driver.
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Regular background program processing daemon...
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Configure Bluetooth Modems connected by UART...
Dec 20 17:29:37 raspberrypi systemd[1]: Stopping Authorization Manager...
Dec 20 17:29:37 raspberrypi systemd[1]: Removed slice system-bthelper.slice.
Connection to raspberrypi closed by remote host.
Connection to raspberrypi closed.
chaskitb commented 3 years ago

I have a similar issue. With the update to 2.2 the shutdown over GPIO does not work. As soon as the part in the gpio-settings.ini the section [shutdown] is enabled with "enabled : True" the other buttons don't work anymore, and most interestingly, the sound does not work anymore as well.

s-martin commented 3 years ago

I have a similar issue. With the update to 2.2 the shutdown over GPIO does not work. As soon as the part in the gpio-settings.ini the section [shutdown] is enabled with "enabled : True" the other buttons don't work anymore, and most interestingly, the sound does not work anymore as well.

Could you please show your gpio_settings.ini?

chaskitb commented 3 years ago

[VolumeControl] enabled: True Type: TwoButtonControl PinUp: 6 PinDown: 5 pull_up: False hold_time: 0.3 hold_repeat: True timeBase: 0.1 functionCallDown: functionCallVolD functionCallUp: functionCallVolU functionCallTwoButtons: None

[PrevNextControl] enabled: True Type: TwoButtonControl Pin1: 26 Pin2: 13 functionCall1: functionCallPlayerPrev functionCall2: functionCallPlayerNext functionCallTwoButtons: None pull_up: False hold_time: 0.3 hold_repeat: False

[PlayPause] enabled: True Type: Button Pin: 12 pull_up: False hold_time: 0.3 functionCall: functionCallPlayerPause

[Shutdown] enabled: False Type: Button Pin: 3 pull_up: False hold_time: 2 functionCall: functionCallShutdown

[Volume0] enabled: False Type: Button Pin: 17 pull_up: True hold_time: 0.3 functionCall: functionCallVol0

[VolumeUp] enabled: False Type: Button Pin: 5 pull_up: True hold_time: 0.3 hold_repeat: True functionCall: functionCallVolU

[VolumeDown] enabled: False Type: Button Pin: 6 pull_up: True hold_time: 0.3 hold_repeat: True functionCall: functionCallVolD

[NextSong] enabled: False Type: Button Pin: 26 pull_up: True hold_time: 0.3 functionCall: functionCallPlayerNext

[PrevSong] enabled: False Type: Button Pin: 13 pull_up: True hold_time: 0.3 functionCall: functionCallPlayerPrev

[Halt] enabled: False Type: Button Pin: 21 pull_up: True hold_time: 0.3 functionCall: functionCallPlayerPauseForce

Barzille commented 3 years ago

Is the „Halt“ or „Shutdown“ section in any way related to the onOff Shim? Meaning: should I enable any of it to have the shim working?

matthias-pelger commented 3 years ago

If you are using the button or button connector on the shim itself, the GPIO settings are irrelevant.

If you experience a "restart" with your onoffshim, it could also be, that you have a capacitor attached to +5v or +3,3 pins and GND. It is normally suggested to use this capacitor to enable a short powersupply if your powerbank switches from or to charging and would normally loose power. Other areas are you are a fool like myself and use this capacitor for your selfmade amplifier and don't see this problem :)

Barzille commented 3 years ago

I see a power cut off when I attach powercord to the powerbank, but that's ok for me. And as mentioned before my main problem is that the shim as well as the system shutdown command powers down the raspi, but is not dropping the power supply so the raspi keeps on with a red light. But it's not possible to start up the device again without removing the power connection from the powerbank to the raspi.

What do you mean with the last sentence? German is fine too ;) @matthias-pelger

matthias-pelger commented 3 years ago

Sorry for bad english, still in holiday mode :)

Also auf Deutsch: Ich hatte das gleiche Problem, als ich einen Verstärker selber gelötet habe und zur spannungsstabilisierung des Verstärkers einen größeren Elko zwischen +5V und GND gehängt habe. Dieser verursachte genau das Phänomen: Raspi ging aus und sofort wieder an. Das liegt wohl irgendwie daran, dass der OnOffShim es nicht mag wenn er nach dem Ausschalten noch mit Spannnung "von hinten" versorgt wird. Bei mir hat eine einfache Diode, die verhindert das Strom vom Elko zurück zu Raspi fließt gelöst.

Daher der Vorschlag: prüfe mal alles was da an +5V und +3.3V an den Pins vom OnOffShim hängt ob da irgendwo noch ein Stromimpuls kommen könnte der den Shim wieder einschaltet.

Barzille commented 3 years ago

Danke 👍 Das hatte ich auch vermutet und alle anderen Pins, ich nutze das Extension Bord, auf andere gesteckt, so dass jetzt nur noch der shim und der hifiberry miniamp sich Pins teilen. meine Button LEDs werden zwar auch über 5V Dauerstrom versorgt, aber über andere Pins :(

matthias-pelger commented 3 years ago

Hmm, wäre es nicht möglich, dass der Shim auf alle 5V Pins gleich reagiert? Würde vermuten, dass die geteilt ist und nicht getrennt wird.

Barzille commented 3 years ago

Hm, du meinst ich sollte mal alle 5V Pins abkoppeln?

matthias-pelger commented 3 years ago

genau, also testweise und dann einzeln wieder dran bis der fehler wieder auftritt.

Barzille commented 3 years ago

Ich habe jetzt auch mal das Extension Board abgenommen und den OnOff Shim direkt auf den Pi gestöpselt, aber leider immer noch das gleiche Problem. Es sind auch keine weiteren anderen PINs angeschlossen/belegt.

Barzille commented 3 years ago

Ich habe hier eine ähnliche Beschreibung gefunden, das werde ich mal überprüfen: https://forum-raspberrypi.de/forum/thread/44762-phoniebox-onoffshim-schaltet-den-rpi-nicht-aus/

Barzille commented 3 years ago

Hat leider auch nicht geholfen, ich habe jetzt mal einen RPI4 bestellt, mal gucken ob das da besser läuft und ggf. checke ich noch mal die Lötstellen.

s-martin commented 1 year ago

Closing for now as there was no activity for a long time. Feel free to reopen a new issue, if the issue persists with current version 2.4 (or beta 3.2).