search

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.38k stars 397 forks source link

Can't play anything / Spotify also not Working #783

Closed DarthChoco closed 4 years ago

DarthChoco commented 4 years ago

After a clean installation there is no way to play any file. When clicking on any button there is an error message like this "An error occorured: Execution failed Command: /home/pi/RPi-Jukebox-RFID/scripts/playout_controls.sh -c=volumeup Output: RC: .1"

A click on the spotify link opens a new site with the information "Unable to connect" while trying to connect to the host with port 6680 and subdir "iris".

Is there any way to install an older stable release while there a such errors?

s-martin commented 4 years ago

Are you using Stretch or Buster?

Did you install the regular stable installation from master or the one from develop?

s-martin commented 4 years ago

And what's the result of cat /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py?

s-martin commented 4 years ago

Please also press a button and post the result of tail -n 500 /var/log/syslog.

DarthChoco commented 4 years ago

The installation was done on buster.

Output for "cat /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py"

`def def_shutdown(): check_call("./scripts/playout_controls.sh -c=shutdown", shell=True)

def def_volU(): check_call("./scripts/playout_controls.sh -c=volumeup", shell=True)

def def_volD(): check_call("./scripts/playout_controls.sh -c=volumedown", shell=True)

def def_vol0(): check_call("./scripts/playout_controls.sh -c=mute", shell=True)

def def_next(): check_call("./scripts/playout_controls.sh -c=playernext", shell=True)

def def_prev(): check_call("./scripts/playout_controls.sh -c=playerprev", shell=True)

def def_halt(): check_call("./scripts/playout_controls.sh -c=playerpause", shell=True)

def def_recordstart(): check_call("./scripts/playout_controls.sh -c=recordstart", shell=True)

def def_recordstop(): check_call("./scripts/playout_controls.sh -c=recordstop", shell=True)

def def_recordplaylatest(): check_call("./scripts/playout_controls.sh -c=recordplaylatest", shell=True)

shut = Button(3, hold_time=2) vol0 = Button(13,pull_up=True) volU = Button(16,pull_up=True,hold_time=0.3,hold_repeat=True) volD = Button(19,pull_up=True,hold_time=0.3,hold_repeat=True) next = Button(26,pull_up=True) prev = Button(20,pull_up=True) halt = Button(21,pull_up=True)

reco = Button(6, pull_up=True) # Choose GPIO to fit your hardware

play = Button(12,pull_up=True) # Choose GPIO to fit your hardware

shut.when_held = def_shutdown vol0.when_pressed = def_vol0 volU.when_pressed = def_volU

When the Volume Up button was held for more than 0.3 seconds every 0.3 seconds he will call a ra$

volU.when_held = def_volU volD.when_pressed = def_volD

When the Volume Down button was held for more than 0.3 seconds every 0.3 second s he will lower t$

volD.when_held = def_volD next.when_pressed = def_next prev.when_pressed = def_prev halt.when_pressed = def_halt

reco.when_pressed = def_recordstart

reco.when_released = def_recordstop

play.when_pressed = def_recordplaylatest

pause()`

DarthChoco commented 4 years ago

Output for "tail -n 500 /var/log/syslog"

Feb  9 09:01:10 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Feb  9 09:01:10 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Feb  9 09:01:10 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Feb  9 09:01:10 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Feb  9 09:01:11 raspberrypi systemd[6029]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb  9 09:01:11 raspberrypi systemd[6029]: Reached target Paths.
Feb  9 09:01:11 raspberrypi systemd[6029]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb  9 09:01:11 raspberrypi systemd[6029]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb  9 09:01:11 raspberrypi systemd[6029]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Feb  9 09:01:11 raspberrypi systemd[6029]: Reached target Timers.
Feb  9 09:01:11 raspberrypi systemd[6029]: Listening on GnuPG network certificate management daemon.
Feb  9 09:01:11 raspberrypi systemd[6029]: Reached target Sockets.
Feb  9 09:01:11 raspberrypi systemd[6029]: Reached target Basic System.
Feb  9 09:01:11 raspberrypi systemd[6029]: Starting Music Player Daemon...
Feb  9 09:01:11 raspberrypi systemd[1]: Started User Manager for UID 1000.
Feb  9 09:01:11 raspberrypi systemd[1]: Started Session c3 of user pi.
Feb  9 09:01:12 raspberrypi mpd[6042]: exception: failed to open log file "/var/log/mpd/mpd.log" (config line 40): Permission denied
Feb  9 09:01:12 raspberrypi systemd[6029]: mpd.service: Main process exited, code=exited, status=1/FAILURE
Feb  9 09:01:12 raspberrypi systemd[6029]: mpd.service: Failed with result 'exit-code'.
Feb  9 09:01:12 raspberrypi systemd[6029]: Failed to start Music Player Daemon.
Feb  9 09:01:12 raspberrypi systemd[6029]: Reached target Default.
Feb  9 09:01:12 raspberrypi systemd[6029]: Startup finished in 1.252s.
Feb  9 09:04:14 raspberrypi lighttpd[820]: echo: write error: Broken pipe
Feb  9 09:04:18 raspberrypi lighttpd[820]: mpd error: Connection refused
Feb  9 09:04:18 raspberrypi lighttpd[820]: mpd error: Connection refused
Feb  9 09:04:19 raspberrypi lighttpd[820]: echo: write error: Broken pipe
bastiitsab commented 4 years ago

I have the exact same problem! I am trying to get phonibox running since last week. Can't play any songs in the web-site and can't connect to spotify (Connection refused)

During the installation I saw the following error: 

Collecting Mopidy-Iris
  Using cached https://files.pythonhosted.org/packages/85/74/52465ef66d859720b7797a117af6be10264901b11116b63a8abbb845916d/Mopidy-Iris-3.44.0.tar.gz
  Installing build dependencies ... done
Mopidy-Iris requires Python '>=3.7' but the running Python is 2.7.16
Cloning into 'RPi-Jukebox-RFID'...

I am using a RPi 4 b

btw: sound is working on rpi. I am playing mp3 files with vlc without problems!

hoodvisions commented 4 years ago

Same issue here. No sound playback via interface, no spotify (iris) after a clean install on buster. taillog after pressing play on a demo sound file after a clean reboot shows this https://pastebin.com/1wCVTGBY

bastiitsab commented 4 years ago

@s-martin this change makes no difference for me. Can't play anything or use spotify like before :(

I tried it with the Install of MPD during installation and without. Both not wirking.

s-martin commented 4 years ago

Spotify edition works only with mopidy.

I have created PR #789 which may fix this, but this needs to be reviewed before it can be merged.

bastiitsab commented 4 years ago

I have made the changes from the PR locally to test it

bastiitsab commented 4 years ago

@s-martin I've done a clean installation now with the developer version. I choosed to not install MPD during installation.

The Startup Sound is working (Using Hifiberry MiniAMP) but playing local sounds doesn't do anything. Spotify gets a 404: Not Found.

tail -n 500 /var/log/syslog

pi@phoniebox:~ $ tail -n 500 /var/log/syslog Feb 14 21:33:00 phoniebox kernel: [ 0.333973] bcmgenet fd580000.genet: failed to get enet clock Feb 14 21:33:00 phoniebox systemd[1]: Started Daily apt download activities. Feb 14 21:33:00 phoniebox kernel: [ 0.334003] bcmgenet fd580000.genet: GENET 5.0 EPHY: 0x0000 Feb 14 21:33:00 phoniebox kernel: [ 0.334034] bcmgenet fd580000.genet: failed to get enet-wol clock Feb 14 21:33:00 phoniebox systemd[1]: Started Daily apt upgrade and clean activities. Feb 14 21:33:00 phoniebox kernel: [ 0.334063] bcmgenet fd580000.genet: failed to get enet-eee clock Feb 14 21:33:00 phoniebox kernel: [ 0.334098] bcmgenet: Skipping UMAC reset Feb 14 21:33:00 phoniebox kernel: [ 0.334341] unimac-mdio unimac-mdio.-19: DMA mask not set Feb 14 21:33:00 phoniebox kernel: [ 0.358142] libphy: bcmgenet MII bus: probed Feb 14 21:33:00 phoniebox systemd[1]: Reached target Timers. Feb 14 21:33:00 phoniebox kernel: [ 0.398655] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus at 0x(ptrval) Feb 14 21:33:00 phoniebox kernel: [ 0.399556] usbcore: registered new interface driver r8152 Feb 14 21:33:00 phoniebox kernel: [ 0.399636] usbcore: registered new interface driver lan78xx Feb 14 21:33:00 phoniebox kernel: [ 0.399703] usbcore: registered new interface driver smsc95xx Feb 14 21:33:00 phoniebox systemd[1]: Listening on D-Bus System Message Bus Socket. Feb 14 21:33:00 phoniebox kernel: [ 0.400008] xhci_hcd 0000:01:00.0: xHCI Host Controller Feb 14 21:33:00 phoniebox systemd[1]: Reached target Sockets. Feb 14 21:33:00 phoniebox kernel: [ 0.400052] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Feb 14 21:33:00 phoniebox kernel: [ 0.402229] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890 Feb 14 21:33:00 phoniebox kernel: [ 0.402563] genirq: irq_chip Brcm_MSI did not update eff. affinity mask of irq 55 Feb 14 21:33:00 phoniebox kernel: [ 0.403428] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19 Feb 14 21:33:00 phoniebox kernel: [ 0.403462] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 14 21:33:00 phoniebox kernel: [ 0.403491] usb usb1: Product: xHCI Host Controller Feb 14 21:33:00 phoniebox kernel: [ 0.403514] usb usb1: Manufacturer: Linux 4.19.97-v7l+ xhci-hcd Feb 14 21:33:00 phoniebox systemd[1]: Reached target Basic System. Feb 14 21:33:00 phoniebox kernel: [ 0.403538] usb usb1: SerialNumber: 0000:01:00.0 Feb 14 21:33:00 phoniebox systemd[1]: Starting Deferred execution scheduler... Feb 14 21:33:00 phoniebox kernel: [ 0.404051] hub 1-0:1.0: USB hub found Feb 14 21:33:00 phoniebox kernel: [ 0.404144] hub 1-0:1.0: 1 port detected Feb 14 21:33:00 phoniebox kernel: [ 0.404617] xhci_hcd 0000:01:00.0: xHCI Host Controller Feb 14 21:33:00 phoniebox kernel: [ 0.404654] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Feb 14 21:33:00 phoniebox kernel: [ 0.404690] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Feb 14 21:33:00 phoniebox systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)... Feb 14 21:33:00 phoniebox kernel: [ 0.405066] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19 Feb 14 21:33:00 phoniebox kernel: [ 0.405099] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 14 21:33:00 phoniebox systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Feb 14 21:33:00 phoniebox kernel: [ 0.405128] usb usb2: Product: xHCI Host Controller Feb 14 21:33:00 phoniebox kernel: [ 0.405151] usb usb2: Manufacturer: Linux 4.19.97-v7l+ xhci-hcd Feb 14 21:33:00 phoniebox systemd[1]: Starting Configure Bluetooth Modems connected by UART... Feb 14 21:33:00 phoniebox kernel: [ 0.405174] usb usb2: SerialNumber: 0000:01:00.0 Feb 14 21:33:00 phoniebox kernel: [ 0.405687] hub 2-0:1.0: USB hub found Feb 14 21:33:00 phoniebox kernel: [ 0.405767] hub 2-0:1.0: 4 ports detected Feb 14 21:33:00 phoniebox kernel: [ 0.406974] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Feb 14 21:33:00 phoniebox systemd[1]: Started Regular background program processing daemon. Feb 14 21:33:00 phoniebox kernel: [ 0.407193] dwc_otg: FIQ enabled Feb 14 21:33:00 phoniebox kernel: [ 0.407202] dwc_otg: NAK holdoff enabled Feb 14 21:33:00 phoniebox systemd[1]: Starting rng-tools.service... Feb 14 21:33:00 phoniebox kernel: [ 0.407211] dwc_otg: FIQ split-transaction FSM enabled Feb 14 21:33:00 phoniebox kernel: [ 0.407224] Module dwc_common_port init Feb 14 21:33:00 phoniebox cron[352]: (CRON) INFO (pidfile fd = 3) Feb 14 21:33:00 phoniebox kernel: [ 0.407421] usbcore: registered new interface driver uas Feb 14 21:33:00 phoniebox kernel: [ 0.407531] usbcore: registered new interface driver usb-storage Feb 14 21:33:00 phoniebox kernel: [ 0.407715] mousedev: PS/2 mouse device common for all mice Feb 14 21:33:00 phoniebox kernel: [ 0.408969] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Feb 14 21:33:00 phoniebox systemd[1]: Started Manage Sound Card State (restore and store). Feb 14 21:33:00 phoniebox kernel: [ 0.410441] sdhci: Secure Digital Host Controller Interface driver Feb 14 21:33:00 phoniebox kernel: [ 0.410466] sdhci: Copyright(c) Pierre Ossman Feb 14 21:33:00 phoniebox kernel: [ 0.410867] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Feb 14 21:33:00 phoniebox kernel: [ 0.411281] sdhci-pltfm: SDHCI platform and OF driver helper Feb 14 21:33:00 phoniebox kernel: [ 0.414276] ledtrig-cpu: registered to indicate activity on CPUs Feb 14 21:33:00 phoniebox kernel: [ 0.414447] hidraw: raw HID events driver (C) Jiri Kosina Feb 14 21:33:00 phoniebox kernel: [ 0.414580] usbcore: registered new interface driver usbhid Feb 14 21:33:00 phoniebox kernel: [ 0.414602] usbhid: USB HID core driver Feb 14 21:33:00 phoniebox kernel: [ 0.415325] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0 Feb 14 21:33:00 phoniebox kernel: [ 0.416615] [vc_sm_connected_init]: start Feb 14 21:33:00 phoniebox kernel: [ 0.422735] [vc_sm_connected_init]: end - returning 0 Feb 14 21:33:00 phoniebox kernel: [ 0.423894] Initializing XFRM netlink socket Feb 14 21:33:00 phoniebox kernel: [ 0.423942] NET: Registered protocol family 17 Feb 14 21:33:00 phoniebox kernel: [ 0.424037] Key type dns_resolver registered Feb 14 21:33:00 phoniebox kernel: [ 0.424302] Registering SWP/SWPB emulation handler Feb 14 21:33:00 phoniebox kernel: [ 0.424890] registered taskstats version 1 Feb 14 21:33:00 phoniebox kernel: [ 0.424918] Loading compiled-in X.509 certificates Feb 14 21:33:00 phoniebox kernel: [ 0.431881] uart-pl011 fe201000.serial: cts_event_workaround enabled Feb 14 21:33:00 phoniebox kernel: [ 0.431959] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2 Feb 14 21:33:00 phoniebox kernel: [ 0.437235] console [ttyS0] disabled Feb 14 21:33:00 phoniebox kernel: [ 0.437282] fe215040.serial: ttyS0 at MMIO 0x0 (irq = 36, base_baud = 62500000) is a 16550 Feb 14 21:33:00 phoniebox kernel: [ 1.603484] console [ttyS0] enabled Feb 14 21:33:00 phoniebox kernel: [ 1.607735] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Feb 14 21:33:00 phoniebox kernel: [ 1.615733] brcmstb_thermal fd5d2200.thermal: registered AVS TMON of-sensor driver Feb 14 21:33:00 phoniebox kernel: [ 1.624082] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Feb 14 21:33:00 phoniebox kernel: [ 1.630215] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Feb 14 21:33:00 phoniebox kernel: [ 1.662112] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.3 Feb 14 21:33:00 phoniebox kernel: [ 1.669295] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.4 Feb 14 21:33:00 phoniebox kernel: [ 1.693668] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Feb 14 21:33:00 phoniebox kernel: [ 1.700902] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 21:33:00 phoniebox kernel: [ 1.708096] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 21:33:00 phoniebox kernel: [ 1.713738] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA Feb 14 21:33:00 phoniebox kernel: [ 1.723639] of_cfs_init Feb 14 21:33:00 phoniebox kernel: [ 1.723950] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Feb 14 21:33:00 phoniebox kernel: [ 1.726218] of_cfs_init: OK Feb 14 21:33:00 phoniebox kernel: [ 1.733389] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 21:33:00 phoniebox kernel: [ 1.740534] Waiting for root device PARTUUID=56cd6262-02... Feb 14 21:33:00 phoniebox kernel: [ 1.789568] random: fast init done Feb 14 21:33:00 phoniebox kernel: [ 1.835738] mmc0: new ultra high speed DDR50 SDXC card at address 0001 Feb 14 21:33:00 phoniebox kernel: [ 1.845502] mmcblk0: mmc0:0001 ED4QT 119 GiB Feb 14 21:33:00 phoniebox kernel: [ 1.852186] mmcblk0: p1 p2 Feb 14 21:33:00 phoniebox kernel: [ 1.855968] mmc1: new high speed SDIO card at address 0001 Feb 14 21:33:00 phoniebox kernel: [ 1.898160] usb 1-1: new high-speed USB device number 2 using xhci_hcd Feb 14 21:33:00 phoniebox kernel: [ 1.902348] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Feb 14 21:33:00 phoniebox kernel: [ 1.913083] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. Feb 14 21:33:00 phoniebox kernel: [ 1.925165] devtmpfs: mounted Feb 14 21:33:00 phoniebox kernel: [ 1.935759] Freeing unused kernel memory: 2048K Feb 14 21:33:00 phoniebox kernel: [ 1.940655] Run /sbin/init as init process Feb 14 21:33:00 phoniebox kernel: [ 2.080806] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Feb 14 21:33:00 phoniebox kernel: [ 2.089161] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Feb 14 21:33:00 phoniebox kernel: [ 2.096421] usb 1-1: Product: USB2.0 Hub Feb 14 21:33:00 phoniebox kernel: [ 2.102118] hub 1-1:1.0: USB hub found Feb 14 21:33:00 phoniebox kernel: [ 2.106178] hub 1-1:1.0: 4 ports detected Feb 14 21:33:00 phoniebox kernel: [ 2.435047] NET: Registered protocol family 10 Feb 14 21:33:00 phoniebox kernel: [ 2.438191] usb 1-1.4: new low-speed USB device number 3 using xhci_hcd Feb 14 21:33:00 phoniebox kernel: [ 2.440802] Segment Routing with IPv6 Feb 14 21:33:00 phoniebox kernel: [ 2.575001] usb 1-1.4: New USB device found, idVendor=16c0, idProduct=27db, bcdDevice= 0.01 Feb 14 21:33:00 phoniebox kernel: [ 2.583559] usb 1-1.4: New USB device strings: Mfr=1, Product=0, SerialNumber=0 Feb 14 21:33:00 phoniebox kernel: [ 2.591043] usb 1-1.4: Manufacturer: HXGCoLtd Feb 14 21:33:00 phoniebox kernel: [ 2.618922] input: HXGCoLtd Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.0/0003:16C0:27DB.0001/input/input0 Feb 14 21:33:00 phoniebox kernel: [ 2.708586] hid-generic 0003:16C0:27DB.0001: input,hiddev96,hidraw0: USB HID v1.10 Keyboard [HXGCoLtd] on usb-0000:01:00.0-1.4/input0 Feb 14 21:33:00 phoniebox kernel: [ 3.277734] random: systemd: uninitialized urandom read (16 bytes read) Feb 14 21:33:00 phoniebox kernel: [ 3.293064] random: systemd: uninitialized urandom read (16 bytes read) Feb 14 21:33:00 phoniebox kernel: [ 3.308608] random: systemd: uninitialized urandom read (16 bytes read) Feb 14 21:33:00 phoniebox kernel: [ 4.095688] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) Feb 14 21:33:00 phoniebox kernel: [ 4.717533] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x0000ffff Feb 14 21:33:00 phoniebox kernel: [ 4.726088] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00000fff Feb 14 21:33:00 phoniebox kernel: [ 4.727000] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x0000ffff Feb 14 21:33:00 phoniebox kernel: [ 4.727487] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x0000ffff Feb 14 21:33:00 phoniebox kernel: [ 4.802814] snd-rpi-simple soc:sound: pcm5102a-hifi <-> fe203000.i2s mapping ok Feb 14 21:33:00 phoniebox kernel: [ 4.841328] input: soc:shutdown_button as /devices/platform/soc/soc:shutdown_button/input/input1 Feb 14 21:33:00 phoniebox kernel: [ 4.886698] media: Linux media interface: v0.10 Feb 14 21:33:00 phoniebox kernel: [ 4.887287] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Feb 14 21:33:00 phoniebox kernel: [ 4.889358] bcm2835_vc_sm_cma_probe: Videocore shared memory driver Feb 14 21:33:00 phoniebox kernel: [ 4.889374] [vc_sm_connected_init]: start Feb 14 21:33:00 phoniebox kernel: [ 4.893579] [vc_sm_connected_init]: installed successfully Feb 14 21:33:00 phoniebox kernel: [ 4.943324] videodev: Linux video capture interface: v2.00 Feb 14 21:33:00 phoniebox kernel: [ 5.030197] cfg80211: Loading compiled-in X.509 certificates for regulatory database Feb 14 21:33:00 phoniebox kernel: [ 5.046088] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Feb 14 21:33:00 phoniebox kernel: [ 5.048679] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Feb 14 21:33:00 phoniebox kernel: [ 5.066462] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Feb 14 21:33:00 phoniebox kernel: [ 5.075636] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Feb 14 21:33:00 phoniebox kernel: [ 5.078982] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Feb 14 21:33:00 phoniebox kernel: [ 5.079019] bcm2835-codec bcm2835-codec: Loaded V4L2 decode Feb 14 21:33:00 phoniebox kernel: [ 5.088294] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Feb 14 21:33:00 phoniebox kernel: [ 5.088341] bcm2835-codec bcm2835-codec: Loaded V4L2 encode Feb 14 21:33:00 phoniebox kernel: [ 5.089013] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0 Feb 14 21:33:00 phoniebox kernel: [ 5.096369] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Feb 14 21:33:00 phoniebox kernel: [ 5.096400] bcm2835-codec bcm2835-codec: Loaded V4L2 isp Feb 14 21:33:00 phoniebox kernel: [ 5.135747] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Feb 14 21:33:00 phoniebox kernel: [ 5.144602] [drm] No displays found. Consider forcing hotplug if HDMI is attached Feb 14 21:33:00 phoniebox kernel: [ 5.144706] vc4-drm soc:gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4]) Feb 14 21:33:00 phoniebox kernel: [ 5.147169] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 1 Feb 14 21:33:00 phoniebox kernel: [ 5.147181] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013). Feb 14 21:33:00 phoniebox kernel: [ 5.147191] [drm] No driver support for vblank timestamp query. Feb 14 21:33:00 phoniebox kernel: [ 5.147200] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL Feb 14 21:33:00 phoniebox kernel: [ 5.188786] brcmfmac: F1 signature read @0x18000000=0x15264345 Feb 14 21:33:00 phoniebox kernel: [ 5.198848] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Feb 14 21:33:00 phoniebox kernel: [ 5.199444] usbcore: registered new interface driver brcmfmac Feb 14 21:33:00 phoniebox kernel: [ 5.425814] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Feb 14 21:33:00 phoniebox kernel: [ 5.438723] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Feb 27 2018 03:15:32 version 7.45.154 (r684107 CY) FWID 01-4fbe0b04 Feb 14 21:33:00 phoniebox kernel: [ 7.118766] uart-pl011 fe201000.serial: no DMA platform data Feb 14 21:33:00 phoniebox kernel: [ 7.157371] random: crng init done Feb 14 21:33:00 phoniebox kernel: [ 7.157386] random: 7 urandom warning(s) missed due to ratelimiting Feb 14 21:33:00 phoniebox systemd[1]: Starting Phoniebox Startup Sound... Feb 14 21:33:00 phoniebox cron[352]: (CRON) INFO (Running @reboot jobs) Feb 14 21:33:00 phoniebox systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Feb 14 21:33:00 phoniebox systemd[1]: Starting Check for Raspberry Pi EEPROM updates... Feb 14 21:33:00 phoniebox systemd[1]: Starting Save/Restore Sound Card State... Feb 14 21:33:00 phoniebox alsactl[359]: alsactl 1.1.8 daemon started Feb 14 21:33:00 phoniebox rngd[369]: rngd 2-unofficial-mt.14 starting up... Feb 14 21:33:00 phoniebox rng-tools[353]: Starting Hardware RNG entropy gatherer daemon: rngd. Feb 14 21:33:00 phoniebox systemd[1]: Starting System Logging Service... Feb 14 21:33:00 phoniebox systemd[1]: Starting dhcpcd on all interfaces... Feb 14 21:33:00 phoniebox systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Feb 14 21:33:00 phoniebox systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Feb 14 21:33:00 phoniebox systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped. Feb 14 21:33:00 phoniebox systemd[1]: Started D-Bus System Message Bus. Feb 14 21:33:00 phoniebox rpi-eeprom-update[364]: BCM2711 detected Feb 14 21:33:00 phoniebox mpg123[361]: High Performance MPEG 1.0/2.0/2.5 Audio Player for Layers 1, 2 and 3 Feb 14 21:33:00 phoniebox mpg123[361]: #011version 1.25.10; written and copyright by Michael Hipp and others Feb 14 21:33:00 phoniebox mpg123[361]: #011free software (LGPL) without any warranty but with best wishes Feb 14 21:33:00 phoniebox rngd[369]: entropy feed to the kernel ready Feb 14 21:33:00 phoniebox systemd[1]: Starting triggerhappy global hotkey daemon... Feb 14 21:33:00 phoniebox systemd[1]: Starting Login Service... Feb 14 21:33:00 phoniebox systemd[1]: Starting WPA supplicant... Feb 14 21:33:00 phoniebox dhcpcd[378]: dev: loaded udev Feb 14 21:33:00 phoniebox systemd[1]: Started Deferred execution scheduler. Feb 14 21:33:00 phoniebox systemd[1]: Started rng-tools.service. Feb 14 21:33:00 phoniebox systemd[1]: Started Save/Restore Sound Card State. Feb 14 21:33:00 phoniebox thd[387]: Found socket passed from systemd Feb 14 21:33:00 phoniebox rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.1901.0] Feb 14 21:33:00 phoniebox rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="374" x-info="https://www.rsyslog.com"] start Feb 14 21:33:00 phoniebox systemd[1]: Started triggerhappy global hotkey daemon. Feb 14 21:33:00 phoniebox systemd[1]: Started System Logging Service. Feb 14 21:33:00 phoniebox systemd[1]: Reached target Sound Card. Feb 14 21:33:00 phoniebox avahi-daemon[381]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113). Feb 14 21:33:00 phoniebox avahi-daemon[381]: Successfully dropped root privileges. Feb 14 21:33:00 phoniebox kernel: [ 7.313259] 8021q: 802.1Q VLAN Support v1.8 Feb 14 21:33:00 phoniebox avahi-daemon[381]: avahi-daemon 0.7 starting up. Feb 14 21:33:00 phoniebox dphys-swapfile[349]: want /var/swap=100MByte, checking existing: keeping it Feb 14 21:33:00 phoniebox avahi-daemon[381]: Successfully called chroot(). Feb 14 21:33:00 phoniebox avahi-daemon[381]: Successfully dropped remaining capabilities. Feb 14 21:33:00 phoniebox avahi-daemon[381]: No service file found in /etc/avahi/services. Feb 14 21:33:00 phoniebox avahi-daemon[381]: Network interface enumeration completed. Feb 14 21:33:00 phoniebox avahi-daemon[381]: Server startup complete. Host name is phoniebox.local. Local service cookie is 74946712. Feb 14 21:33:00 phoniebox wpa_supplicant[392]: Successfully initialized wpa_supplicant Feb 14 21:33:01 phoniebox systemd[1]: Started Login Service. Feb 14 21:33:01 phoniebox systemd[1]: Started Avahi mDNS/DNS-SD Stack. Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: starting wpa_supplicant Feb 14 21:33:01 phoniebox dhcpcd-run-hooks[450]: wlan0: starting wpa_supplicant Feb 14 21:33:01 phoniebox systemd[1]: Started WPA supplicant. Feb 14 21:33:01 phoniebox mpg123[361]: Directory: /home/pi/RPi-Jukebox-RFID/shared/ Feb 14 21:33:01 phoniebox mpg123[361]: Playing MPEG stream 1 of 1: startupsound.mp3 ... Feb 14 21:33:01 phoniebox kernel: [ 7.588463] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS Feb 14 21:33:01 phoniebox systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file. Feb 14 21:33:01 phoniebox kernel: [ 7.619974] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready Feb 14 21:33:01 phoniebox kernel: [ 7.619990] brcmfmac: power management disabled Feb 14 21:33:01 phoniebox mpg123[361]: MPEG 1.0 L III vbr 44100 j-s Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: BOOTLOADER: up-to-date Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: CURRENT: Tue 10 Sep 10:41:50 UTC 2019 (1568112110) Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: LATEST: Tue 10 Sep 10:41:50 UTC 2019 (1568112110) Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: VL805: up-to-date Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: CURRENT: 000137ad Feb 14 21:33:01 phoniebox rpi-eeprom-update[364]: LATEST: 000137ad Feb 14 21:33:01 phoniebox systemd[1]: Started Check for Raspberry Pi EEPROM updates. Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: connected to Access Point ' Feb 14 21:33:01 phoniebox kernel: [ 7.903200] bcmgenet: Skipping UMAC reset Feb 14 21:33:01 phoniebox dhcpcd[378]: eth0: waiting for carrier Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: waiting for carrier Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: carrier acquired Feb 14 21:33:01 phoniebox kernel: [ 7.998806] bcmgenet fd580000.genet: configuring instance for external RGMII (no delay) Feb 14 21:33:01 phoniebox kernel: [ 7.999212] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready Feb 14 21:33:01 phoniebox dhcpcd[378]: DUID 00:01:00:01:25:cd:a3:7f:dc:a6:32:42:a8:aa Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: IAID 32:42:a8:aa Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: adding address fe80::b910:1f2f:985e:75a0 Feb 14 21:33:01 phoniebox avahi-daemon[381]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::b910:1f2f:985e:75a0. Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: carrier lost Feb 14 21:33:01 phoniebox avahi-daemon[381]: New relevant interface wlan0.IPv6 for mDNS. Feb 14 21:33:01 phoniebox avahi-daemon[381]: Registering new address record for fe80::b910:1f2f:985e:75a0 on wlan0.*. Feb 14 21:33:01 phoniebox dhcpcd[378]: wlan0: deleting address fe80::b910:1f2f:985e:75a0 Feb 14 21:33:01 phoniebox avahi-daemon[381]: Withdrawing address record for fe80::b910:1f2f:985e:75a0 on wlan0. Feb 14 21:33:01 phoniebox avahi-daemon[381]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::b910:1f2f:985e:75a0. Feb 14 21:33:01 phoniebox avahi-daemon[381]: Interface wlan0.IPv6 no longer relevant for mDNS. Feb 14 21:33:02 phoniebox raspi-config[348]: Checking if shift key is held down: No. Switching to ondemand scaling governor. Feb 14 21:33:02 phoniebox systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed). Feb 14 21:33:02 phoniebox kernel: [ 9.048227] bcmgenet fd580000.genet eth0: Link is Down Feb 14 21:33:03 phoniebox mpg123[361]: [0:02] Decoding of startupsound.mp3 finished. Feb 14 21:33:03 phoniebox systemd[1]: Started Phoniebox Startup Sound. Feb 14 21:33:04 phoniebox systemd[1]: systemd-rfkill.service: Succeeded. Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: carrier acquired Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: connected to Access Pointwuuusaaa' Feb 14 21:33:06 phoniebox kernel: [ 13.056009] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: IAID 32:42:a8:aa Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: adding address fe80::838d:23e:ab27:4776 Feb 14 21:33:06 phoniebox avahi-daemon[381]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::838d:23e:ab27:4776. Feb 14 21:33:06 phoniebox avahi-daemon[381]: New relevant interface wlan0.IPv6 for mDNS. Feb 14 21:33:06 phoniebox avahi-daemon[381]: Registering new address record for fe80::838d:23e:ab27:4776 on wlan0.*. Feb 14 21:33:06 phoniebox systemd-udevd[489]: Process '/sbin/crda' failed with exit code 255. Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: rebinding lease of 192.168.1.149 Feb 14 21:33:06 phoniebox dhcpcd[378]: wlan0: probing address 192.168.1.149/24 Feb 14 21:33:07 phoniebox dhcpcd[378]: wlan0: soliciting an IPv6 router Feb 14 21:33:07 phoniebox kernel: [ 13.912862] Bluetooth: Core ver 2.22 Feb 14 21:33:07 phoniebox kernel: [ 13.912925] NET: Registered protocol family 31 Feb 14 21:33:07 phoniebox kernel: [ 13.912933] Bluetooth: HCI device and connection manager initialized Feb 14 21:33:07 phoniebox kernel: [ 13.912951] Bluetooth: HCI socket layer initialized Feb 14 21:33:07 phoniebox kernel: [ 13.912964] Bluetooth: L2CAP socket layer initialized Feb 14 21:33:07 phoniebox kernel: [ 13.913000] Bluetooth: SCO socket layer initialized Feb 14 21:33:07 phoniebox kernel: [ 13.925556] Bluetooth: HCI UART driver ver 2.3 Feb 14 21:33:07 phoniebox kernel: [ 13.925567] Bluetooth: HCI UART protocol H4 registered Feb 14 21:33:07 phoniebox kernel: [ 13.925631] Bluetooth: HCI UART protocol Three-wire (H5) registered Feb 14 21:33:07 phoniebox kernel: [ 13.925824] Bluetooth: HCI UART protocol Broadcom registered Feb 14 21:33:07 phoniebox btuart[350]: bcm43xx_init Feb 14 21:33:07 phoniebox btuart[350]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Feb 14 21:33:07 phoniebox btuart[350]: Set Controller UART speed to 3000000 bit/s Feb 14 21:33:07 phoniebox btuart[350]: Device setup complete Feb 14 21:33:07 phoniebox systemd[1]: Starting Load/Save RF Kill Switch Status... Feb 14 21:33:07 phoniebox systemd[1]: Started Configure Bluetooth Modems connected by UART. Feb 14 21:33:07 phoniebox systemd[1]: Started Load/Save RF Kill Switch Status. Feb 14 21:33:07 phoniebox systemd[1]: Created slice system-bthelper.slice. Feb 14 21:33:07 phoniebox systemd[1]: Starting Bluetooth service... Feb 14 21:33:07 phoniebox bluetoothd[501]: Bluetooth daemon 5.50 Feb 14 21:33:07 phoniebox systemd[1]: Started Bluetooth service. Feb 14 21:33:07 phoniebox bluetoothd[501]: Starting SDP server Feb 14 21:33:07 phoniebox systemd[1]: Started Raspberry Pi bluetooth helper. Feb 14 21:33:07 phoniebox systemd[1]: Reached target Bluetooth. Feb 14 21:33:07 phoniebox bluetoothd[501]: Bluetooth management interface 1.14 initialized Feb 14 21:33:07 phoniebox dbus-daemon[383]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=501 comm="/usr/lib/bluetooth/bluetoothd ") Feb 14 21:33:07 phoniebox kernel: [ 14.120227] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Feb 14 21:33:07 phoniebox kernel: [ 14.120234] Bluetooth: BNEP filters: protocol multicast Feb 14 21:33:07 phoniebox kernel: [ 14.120245] Bluetooth: BNEP socket layer initialized Feb 14 21:33:07 phoniebox bluetoothd[501]: Sap driver initialization failed. Feb 14 21:33:07 phoniebox bluetoothd[501]: sap-server: Operation not permitted (1) Feb 14 21:33:07 phoniebox systemd[1]: bthelper@hci0.service: Succeeded. Feb 14 21:33:07 phoniebox systemd[1]: Starting Hostname Service... Feb 14 21:33:07 phoniebox bluetoothd[501]: Failed to set privacy: Rejected (0x0b) Feb 14 21:33:08 phoniebox dbus-daemon[383]: [system] Successfully activated service 'org.freedesktop.hostname1' Feb 14 21:33:08 phoniebox systemd[1]: Started Hostname Service. Feb 14 21:33:11 phoniebox dhcpcd[378]: wlan0: leased 192.168.1.149 for 86400 seconds Feb 14 21:33:11 phoniebox avahi-daemon[381]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.149. Feb 14 21:33:11 phoniebox avahi-daemon[381]: New relevant interface wlan0.IPv4 for mDNS. Feb 14 21:33:11 phoniebox avahi-daemon[381]: Registering new address record for 192.168.1.149 on wlan0.IPv4. Feb 14 21:33:11 phoniebox dhcpcd[378]: wlan0: adding route to 192.168.1.0/24 Feb 14 21:33:11 phoniebox dhcpcd[378]: wlan0: adding default route via 192.168.1.1 Feb 14 21:33:12 phoniebox dhcpcd[378]: forked to background, child pid 551 Feb 14 21:33:12 phoniebox systemd[1]: Started dhcpcd on all interfaces. Feb 14 21:33:12 phoniebox systemd[1]: Reached target Network. Feb 14 21:33:12 phoniebox systemd[1]: Reached target Network is Online. Feb 14 21:33:12 phoniebox systemd[1]: Starting LSB: exim Mail Transport Agent... Feb 14 21:33:12 phoniebox systemd[1]: Starting Lighttpd Daemon... Feb 14 21:33:12 phoniebox systemd[1]: Starting /etc/rc.local Compatibility... Feb 14 21:33:12 phoniebox systemd[1]: Starting The PHP 7.3 FastCGI Process Manager... Feb 14 21:33:12 phoniebox systemd[1]: Starting OpenBSD Secure Shell server... Feb 14 21:33:12 phoniebox systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Feb 14 21:33:12 phoniebox systemd[1]: Starting Samba NMB Daemon... Feb 14 21:33:12 phoniebox systemd[1]: Started Phoniebox Rotary Encoder Service. Feb 14 21:33:12 phoniebox systemd[1]: Started Phoniebox GPIO Buttons Service. Feb 14 21:33:12 phoniebox systemd[1]: Started Phoniebox RFID-Reader Service. Feb 14 21:33:12 phoniebox systemd[1]: Starting Mopidy music server... Feb 14 21:33:12 phoniebox systemd[1]: Started Phoniebox Idle Watchdog Service. Feb 14 21:33:12 phoniebox systemd[1]: Starting Permit User Sessions... Feb 14 21:33:12 phoniebox systemd[1]: systemd-rfkill.service: Succeeded. Feb 14 21:33:12 phoniebox systemd[1]: Started /etc/rc.local Compatibility. Feb 14 21:33:12 phoniebox systemd[1]: Started Mopidy music server. Feb 14 21:33:12 phoniebox systemd[1]: Started Permit User Sessions. Feb 14 21:33:12 phoniebox systemd[1]: Started Getty on tty1. Feb 14 21:33:12 phoniebox systemd[1]: Started Serial Getty on ttyS0. Feb 14 21:33:12 phoniebox systemd[1]: Reached target Login Prompts. Feb 14 21:33:12 phoniebox systemd[1]: Started OpenBSD Secure Shell server. Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:123: RuntimeWarning: A physical pull up resistor is fitted on this channel! Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: GPIO.setup(btn_shut , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:126: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: GPIO.setup(btn_volD , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:128: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: GPIO.setup(btn_prev , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:129: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: GPIO.setup(btn_halt , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: Traceback (most recent call last): Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: File "/home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py", line 135, in Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime) Feb 14 21:33:13 phoniebox gpio-buttons.py[562]: RuntimeError: Failed to add edge detection Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:13 phoniebox systemd[1]: Started Lighttpd Daemon. Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Service RestartSec=100ms expired, scheduling restart. Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Scheduled restart job, restart counter is at 1. Feb 14 21:33:13 phoniebox systemd[1]: Stopped Phoniebox GPIO Buttons Service. Feb 14 21:33:13 phoniebox systemd[1]: Started Phoniebox GPIO Buttons Service. Feb 14 21:33:13 phoniebox systemd[1]: Started The PHP 7.3 FastCGI Process Manager. Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:123: RuntimeWarning: A physical pull up resistor is fitted on this channel! Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: GPIO.setup(btn_shut , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:131: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: GPIO.setup(led_power , GPIO.OUT) Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: Traceback (most recent call last): Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: File "/home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py", line 135, in Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime) Feb 14 21:33:13 phoniebox gpio-buttons.py[853]: RuntimeError: Failed to add edge detection Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:13 phoniebox exim4[552]: Starting MTA: exim4. Feb 14 21:33:13 phoniebox systemd[1]: Started LSB: exim Mail Transport Agent. Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Service RestartSec=100ms expired, scheduling restart. Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Scheduled restart job, restart counter is at 2. Feb 14 21:33:13 phoniebox systemd[1]: Stopped Phoniebox GPIO Buttons Service. Feb 14 21:33:13 phoniebox systemd[1]: Started Phoniebox GPIO Buttons Service. Feb 14 21:33:13 phoniebox systemd[1]: Started Samba NMB Daemon. Feb 14 21:33:13 phoniebox systemd[1]: Starting Samba SMB Daemon... Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:123: RuntimeWarning: A physical pull up resistor is fitted on this channel! Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: GPIO.setup(btn_shut , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:131: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: GPIO.setup(led_power , GPIO.OUT) Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: Traceback (most recent call last): Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: File "/home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py", line 135, in Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime) Feb 14 21:33:13 phoniebox gpio-buttons.py[870]: RuntimeError: Failed to add edge detection Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:33:13 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:13 phoniebox python3[563]: 2020-02-14 21:33:13,929 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Service RestartSec=100ms expired, scheduling restart. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Scheduled restart job, restart counter is at 3. Feb 14 21:33:14 phoniebox systemd[1]: Stopped Phoniebox GPIO Buttons Service. Feb 14 21:33:14 phoniebox systemd[1]: Started Phoniebox GPIO Buttons Service. Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:123: RuntimeWarning: A physical pull up resistor is fitted on this channel! Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: GPIO.setup(btn_shut , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:131: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: GPIO.setup(led_power , GPIO.OUT) Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: Traceback (most recent call last): Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: File "/home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py", line 135, in Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime) Feb 14 21:33:14 phoniebox gpio-buttons.py[877]: RuntimeError: Failed to add edge detection Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Service RestartSec=100ms expired, scheduling restart. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Scheduled restart job, restart counter is at 4. Feb 14 21:33:14 phoniebox systemd[1]: Stopped Phoniebox GPIO Buttons Service. Feb 14 21:33:14 phoniebox systemd[1]: Started Phoniebox GPIO Buttons Service. Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:123: RuntimeWarning: A physical pull up resistor is fitted on this channel! Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: GPIO.setup(btn_shut , GPIO.IN, pull_up_down=GPIO.PUD_UP) Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: /home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py:131: RuntimeWarning: This channel is already in use, continuing anyway. Use GPIO.setwarnings(False) to disable warnings. Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: GPIO.setup(led_power , GPIO.OUT) Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: Traceback (most recent call last): Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: File "/home/pi/RPi-Jukebox-RFID/scripts/gpio-buttons.py", line 135, in Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime) Feb 14 21:33:14 phoniebox gpio-buttons.py[881]: RuntimeError: Failed to add edge detection Feb 14 21:33:14 phoniebox systemd[1]: Started Samba SMB Daemon. Feb 14 21:33:14 phoniebox systemd[1]: Reached target Multi-User System. Feb 14 21:33:14 phoniebox systemd[1]: Reached target Graphical Interface. Feb 14 21:33:14 phoniebox systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:14 phoniebox systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 14 21:33:14 phoniebox systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 14 21:33:14 phoniebox systemd[1]: Startup finished in 2.304s (kernel) + 18.595s (userspace) = 20.899s. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Service RestartSec=100ms expired, scheduling restart. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Scheduled restart job, restart counter is at 5. Feb 14 21:33:14 phoniebox systemd[1]: Stopped Phoniebox GPIO Buttons Service. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Start request repeated too quickly. Feb 14 21:33:14 phoniebox systemd[1]: phoniebox-gpio-buttons.service: Failed with result 'exit-code'. Feb 14 21:33:14 phoniebox systemd[1]: Failed to start Phoniebox GPIO Buttons Service. Feb 14 21:33:16 phoniebox mopidy[573]: /usr/lib/python2.7/dist-packages/mopidy/ext.py:202: PkgResourcesDeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately. Feb 14 21:33:16 phoniebox mopidy[573]: extension_class = entry_point.load(require=False) Feb 14 21:33:16 phoniebox mopidy[573]: INFO Starting Mopidy 2.2.2 Feb 14 21:33:16 phoniebox mopidy[573]: INFO Loading config from builtin defaults Feb 14 21:33:16 phoniebox mopidy[573]: INFO Loading config from /etc/mopidy/mopidy.conf Feb 14 21:33:16 phoniebox mopidy[573]: INFO Loading config from command line options Feb 14 21:33:16 phoniebox mopidy[573]: INFO Enabled extensions: spotify, mpd, http, stream, m3u, softwaremixer, file, local Feb 14 21:33:16 phoniebox mopidy[573]: INFO Disabled extensions: none Feb 14 21:33:16 phoniebox lighttpd[828]: chmod: changing permissions of '/home/pi/RPi-Jukebox-RFID/scripts/../settings/edition': Operation not permitted Feb 14 21:33:16 phoniebox lighttpd[828]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/scripts/../settings/global.conf': No such file or directory Feb 14 21:33:16 phoniebox lighttpd[828]: chmod: changing permissions of '/home/pi/RPi-Jukebox-RFID/settings/global.conf': Operation not permitted Feb 14 21:33:17 phoniebox mopidy[573]: INFO Starting Mopidy mixer: SoftwareMixer Feb 14 21:33:17 phoniebox mopidy[573]: INFO Mixer volume set to 30 Feb 14 21:33:17 phoniebox mopidy[573]: INFO Starting Mopidy audio Feb 14 21:33:17 phoniebox mopidy[573]: INFO Starting Mopidy backends: SpotifyBackend, StreamBackend, M3UBackend, FileBackend, LocalBackend Feb 14 21:33:17 phoniebox mopidy[573]: INFO Creating dir /var/cache/mopidy/spotify Feb 14 21:33:17 phoniebox mopidy[573]: INFO Creating dir /var/lib/mopidy/spotify Feb 14 21:33:17 phoniebox mopidy[573]: INFO Audio output set to "alsasink" Feb 14 21:33:17 phoniebox mopidy[573]: INFO No local library metadata cache found at /var/lib/mopidy/local/library.json.gz. Please run mopidy local scan to index your local music library. If you do not have a local music collection, you can disable the local backend to hide this message. Feb 14 21:33:17 phoniebox mopidy[573]: INFO Loaded 0 local tracks using json Feb 14 21:33:17 phoniebox lighttpd[828]: echo: write error: Broken pipe Feb 14 21:33:17 phoniebox mopidy[573]: INFO Logged in to Spotify in online mode Feb 14 21:33:18 phoniebox mopidy[573]: INFO Logged into Spotify Web API as bastiitsab2501 Feb 14 21:33:18 phoniebox mopidy[573]: INFO Started spotify backend Feb 14 21:33:18 phoniebox mopidy[573]: INFO Starting Mopidy core Feb 14 21:33:18 phoniebox mopidy[573]: INFO Starting Mopidy frontends: MpdFrontend, HttpFrontend Feb 14 21:33:18 phoniebox mopidy[573]: INFO MPD server running at [::ffff:0.0.0.0]:6600 Feb 14 21:33:18 phoniebox mopidy[573]: INFO HTTP server running at [::ffff:0.0.0.0]:6680 Feb 14 21:33:18 phoniebox mopidy[573]: INFO Starting GLib mainloop Feb 14 21:33:19 phoniebox dhcpcd[551]: wlan0: no IPv6 Routers available Feb 14 21:33:22 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:33:22 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:33:25 phoniebox mopidy[573]: INFO Loaded 24 playlists Feb 14 21:33:27 phoniebox mopidy[573]: INFO Refresh Playlists took 8863ms Feb 14 21:33:28 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:33:29 phoniebox systemd[1]: systemd-fsckd.service: Succeeded. Feb 14 21:33:44 phoniebox systemd-timesyncd[311]: Synchronized to time server for the first time 195.50.171.101:123 (2.debian.pool.ntp.org). Feb 14 21:33:48 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:33:52 phoniebox systemd[1]: systemd-hostnamed.service: Succeeded. Feb 14 21:33:54 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:00 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:02 phoniebox systemd[1]: Created slice User Slice of UID 1000. Feb 14 21:34:02 phoniebox systemd[1]: Starting User Runtime Directory /run/user/1000... Feb 14 21:34:02 phoniebox systemd[1]: Started User Runtime Directory /run/user/1000. Feb 14 21:34:02 phoniebox systemd[1]: Starting User Manager for UID 1000... Feb 14 21:34:03 phoniebox systemd[1051]: Reached target Paths. Feb 14 21:34:03 phoniebox systemd[1051]: Starting D-Bus User Message Bus Socket. Feb 14 21:34:03 phoniebox systemd[1051]: Listening on GnuPG network certificate management daemon. Feb 14 21:34:03 phoniebox systemd[1051]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Feb 14 21:34:03 phoniebox systemd[1051]: Reached target Timers. Feb 14 21:34:03 phoniebox systemd[1051]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Feb 14 21:34:03 phoniebox systemd[1051]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Feb 14 21:34:03 phoniebox systemd[1051]: Listening on GnuPG cryptographic agent and passphrase cache. Feb 14 21:34:03 phoniebox systemd[1051]: Listening on D-Bus User Message Bus Socket. Feb 14 21:34:03 phoniebox systemd[1051]: Reached target Sockets. Feb 14 21:34:03 phoniebox systemd[1051]: Reached target Basic System. Feb 14 21:34:03 phoniebox systemd[1]: Started User Manager for UID 1000. Feb 14 21:34:03 phoniebox systemd[1051]: Starting Music Player Daemon... Feb 14 21:34:03 phoniebox systemd[1]: Started Session c1 of user pi. Feb 14 21:34:03 phoniebox mpd[1064]: exception: failed to open log file "/var/log/mpd/mpd.log" (config line 39): Permission denied Feb 14 21:34:04 phoniebox systemd[1051]: mpd.service: Main process exited, code=exited, status=1/FAILURE Feb 14 21:34:04 phoniebox systemd[1051]: mpd.service: Failed with result 'exit-code'. Feb 14 21:34:04 phoniebox systemd[1051]: Failed to start Music Player Daemon. Feb 14 21:34:04 phoniebox systemd[1051]: Reached target Default. Feb 14 21:34:04 phoniebox systemd[1051]: Startup finished in 1.175s. Feb 14 21:34:06 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:12 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:14 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:14 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:17 phoniebox lighttpd[828]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders/ZZZ/ABC/folder.conf: No such file or directory Feb 14 21:34:17 phoniebox lighttpd[828]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/shared/audiofolders/ZZZ/ABC/folder.conf': No such file or directory Feb 14 21:34:18 phoniebox lighttpd[828]: cat: /home/pi/RPi-Jukebox-RFID/scripts/../settings/Latest_Folder_Played: No such file or directory Feb 14 21:34:18 phoniebox lighttpd[828]: cat: /home/pi/RPi-Jukebox-RFID/scripts/../settings/Latest_Playlist_Played: No such file or directory Feb 14 21:34:18 phoniebox lighttpd[828]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders//folder.conf: No such file or directory Feb 14 21:34:18 phoniebox lighttpd[828]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/shared/audiofolders//folder.conf': No such file or directory Feb 14 21:34:18 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:18 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:19 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:19 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:24 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:25 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:25 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:25 phoniebox mopidy[573]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 14 21:34:26 phoniebox lighttpd[828]: No LSB modules are available. Feb 14 21:34:26 phoniebox lighttpd[828]: tail: cannot open '../logs/debug.log' for reading: No such file or directory Feb 14 21:34:27 phoniebox systemd[1]: phoniebox-idle-watchdog.service: Succeeded. pi@phoniebox:~ $

s-martin commented 4 years ago

We have merged PR #789 into master.

Could you check, if you do a new installation, if this fixes your issue?

ATTENTION: Removing the directory /home/pi/RPi-jukebox-RFID deletes all your settings and also your music files!

s-martin commented 4 years ago

@s-martin I've done a clean installation now with the developer version. I choosed to not install MPD during installation.

The Startup Sound is working (Using Hifiberry MiniAMP) but playing local sounds doesn't do anything. Spotify gets a 404: Not Found.

develop is still heavily work in progress, so I don't expect that this works at the moment.

But we have merged PR #789 to master yesterday, which should fix at least some Spotify issues.

So you could try master again, see also https://github.com/MiczFlor/RPi-Jukebox-RFID/issues/783#issuecomment-586860974

cd; rm buster-install-*; wget https://raw.githubusercontent.com/MiczFlor/RPi-Jukebox-RFID/master/scripts/installscripts/buster-install-default.sh; chmod +x buster-install-default.sh; ./buster-install-default.sh

bastiitsab commented 4 years ago

thanks @s-martin will try this today! Should I select to install MPD or not during Installation?

edit Was faster than I thought. Have installed with the MPD installation. Spotifiy is not working: 404: Not Found. Local does not work anyway.

s-martin commented 4 years ago

That's too bad :-(

What's the result of sudo systemctl status mopidy and tail -n 500 /var/log/syslog?

s-martin commented 4 years ago

It seems that mopidy-iris dropped support for python 2 and mopidy2 after version 3.43.0. PR #793 should fix this.

s-martin commented 4 years ago

PR #793 was merged to master and should fix this issue.

Please test.

bastiitsab commented 4 years ago

PR #793 was merged to master and should fix this issue.

Please test.

Can confirm, Spotify is working with this fix! Big thanks for this!

But local files can't be played anyways. Do you know where the problem is with local files playing? I could try to help or at least provide log-files!

I found this problem in the syslog:

Feb 19 09:19:08 phoniebox mopidy[568]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 09:19:27 phoniebox lighttpd[823]: chown: changing ownership of '/home/pi/RPi-Jukebox-RFID/shared/audiofolders/test1': Operation not permitted Feb 19 09:19:27 phoniebox lighttpd[823]: chown: changing ownership of '/home/pi/RPi-Jukebox-RFID/shared/audiofolders/test1/goat.mp3': Operation not permitted Feb 19 09:19:31 phoniebox mopidy[568]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 09:19:31 phoniebox mopidy[568]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 09:19:33 phoniebox lighttpd[823]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders/test1/folder.conf: No such file or directory Feb 19 09:19:33 phoniebox lighttpd[823]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/shared/audiofolders/test1/folder.conf': No such file or directory Feb 19 09:19:34 phoniebox lighttpd[823]: cat: /home/pi/RPi-Jukebox-RFID/scripts/../settings/Latest_Folder_Played: No such file or directory Feb 19 09:19:34 phoniebox lighttpd[823]: cat: /home/pi/RPi-Jukebox-RFID/scripts/../settings/Latest_Playlist_Played: No such file or directory Feb 19 09:19:34 phoniebox lighttpd[823]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders//folder.conf: No such file or directory Feb 19 09:19:34 phoniebox lighttpd[823]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/shared/audiofolders//folder.conf': No such file or directory

s-martin commented 4 years ago

PR #793 was merged to master and should fix this issue. Please test.

Can confirm, Spotify is working with this fix!

Great to hear!

But local files can't be played anyways. Do you know where the problem is with local files playing? I could try to help or at least provide log-files!

You could try to play a local file and then post the results of tail -n 500 /var/log/syslog

bastiitsab commented 4 years ago

PR #793 was merged to master and should fix this issue. Please test.

Can confirm, Spotify is working with this fix!

Great to hear!

But local files can't be played anyways. Do you know where the problem is with local files playing? I could try to help or at least provide log-files!

You could try to play a local file and then post the results of tail -n 500 /var/log/syslog

see my previous post.

Here I tried one of the test sample files:

Feb 19 10:32:06 phoniebox mopidy[567]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 10:32:10 phoniebox lighttpd[824]: No LSB modules are available. Feb 19 10:32:10 phoniebox lighttpd[824]: tail: cannot open '../logs/debug.log' for reading: No such file or directory Feb 19 10:33:13 phoniebox mopidy[567]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 10:33:13 phoniebox mopidy[567]: INFO New MPD connection from [::ffff:127.0.0.1]:6600 Feb 19 10:33:17 phoniebox lighttpd[824]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders/ZZZ/ABC/folder.conf: No such file or directory Feb 19 10:33:17 phoniebox lighttpd[824]: rm: cannot remove '/home/pi/RPi-Jukebox-RFID/shared/audiofolders/ZZZ/ABC/folder.conf': No such file or directory Feb 19 10:33:18 phoniebox mopidy[567]: INFO New MPD connection from [::ffff:127.0.0.1]:6600

Update: Livestreams (like from the samples) are working too!

Update2: I just tried to "Scan Music Library". Afterwards I was able to play local files!? Have to test frther

hoodvisions commented 4 years ago

Now that Spotify (iris) is working audio is still not. I have posted my taillog here after a clean install + reboot, after pressing the play button once for an uploaded test-mp3: https://pastebin.com/Qd3cgmbQ Hope this helps in any way.

s-martin commented 4 years ago

Update2: I just tried to "Scan Music Library". Afterwards I was able to play local files!? Have to test frther

That would make sense as you got the error

Feb 19 10:33:17 phoniebox lighttpd[824]: /home/pi/RPi-Jukebox-RFID/scripts/inc.writeFolderConfig.sh: line 106: /home/pi/RPi-Jukebox-RFID/shared/audiofolders/ZZZ/ABC/folder.conf: No such file or directory

before.

Not sure, why the files weren’t indexed in the first place, though. @MiczFlor, do you have any ideas?

s-martin commented 4 years ago

Now that Spotify (iris) is working audio is still not. I have posted my taillog here after a clean install + reboot, after pressing the play button once for an uploaded test-mp3: https://pastebin.com/Qd3cgmbQ Hope this helps in any way.

I have seen a „warning“ that your local files aren’t indexed

Feb 19 14:45:00 raspberrypi mopidy[457]: INFO No local library metadata cache found at /var/lib/mopidy/local/library.json.gz. Please run mopidy local scan to index your local music library. If you do not have a local music collection, you can disable the local backend to hide this message

Did you try mopidy local scan?

In addition I didn’t see anywhere that you would play a mp3 file.

hoodvisions commented 4 years ago

You are right!! I have run the scan and now the file apparently plays, but I have no audio. So this might be an issue I have to solve on my own. Will test and come back asap!

bastiitsab commented 4 years ago

It seems that the local files sometimes are not correct indexed. After manual indexing over the website the local files are working.

Spotify is working like charm! Thanks again @s-martin !

But with spotify Playlists I have one Bug. The given name is not displayed on the home Screen. I've made a Screenshot from this. The Top Spotify List is marked with the yellow box from me. The second spotify is without that mark. image

s-martin commented 4 years ago

Good to hear that it is now working.

Could you open a new issue for the display problem as it's not really related to this issue? Thanks.

hoodvisions commented 4 years ago

I have run a fresh install and for some reason I have no sound neither in spotify (iris) nor the phoniebox. The Startup sound plays fine. Should I open a separate issue on this or is it likely it's the same issue?

s-martin commented 4 years ago

Could you show the log output?

hoodvisions commented 4 years ago

UPDATE: solved my issue with not having sound at all. It was simply setting the external USB sound card as default by editing /usr/share/alsa/alsa.conf

Yes, here it is on pastebin :) Used tail -n 500 /var/log/syslog

What is weird is...I can see the file being played. ( https://imgur.com/a/LDT0FVB ) The Interface shows me the duration and on Spotify it is even showing a playing now etc. But in the log there is NO indication whatsoever of me Playing König der Löwen.........is this maybe the wrong log?

UPDATE: Okay, my god, I switched the cables from external USB Audio to the regular Pi Audio output and it works!! So it is only something about the soundcard configuration which I cannot find in the Jukebox settings. WIll keep searching.

s-martin commented 4 years ago

Good to hear, it was fixed for you.

I would close the ticket, if there are new problems, please open a new ticket.