Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

RFID is working only sometimes #1083

Closed
Barzille opened this issue Oct 12, 2020 · 4 comments
Closed

RFID is working only sometimes #1083

Barzille opened this issue Oct 12, 2020 · 4 comments
Labels
bug need more info

Comments

@Barzille
Copy link

Barzille commented Oct 12, 2020 •
edited by s-martin
Loading

Bug

This is a strange behaviour I could not track down.
When we start or restart the raspberry it seems as if everything is initialized correctly. The rfid is beeping, the leds are blinking and also the jukebox startup sound is playing.

But every now and then the rfid reader is not recognizing any cards. It's not beeping when holding a card to it while the other time when we switched the raspi on it worked flawlessly.

None of the logs show any errors or warnings which we could connect to the rfid reader.

What I did

  • I installed the raspberry pi with above mentioned buster image and ran the installer script
  • Installed a on/off shim
  • working with a power bank or wired current
  • sed -i -e 's/sudo poweroff/sudo shutdown -h 0/g' /home/pi/RPi-Jukebox-RFID/scripts/playout_controls.sh

What happened

unknown but even another RFID reader (same product type) is producing the same outcome

I expected this to happen

RFID Reader is working every time correctly

Further information that might help

tail -n 500 /var/log/syslog
Oct 12 20:35:12 raspberrypi kernel: [    2.596711] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Oct 12 20:35:12 raspberrypi kernel: [    2.600572] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Oct 12 20:35:12 raspberrypi kernel: [    2.605152] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Oct 12 20:35:12 raspberrypi kernel: [    2.609883] of_cfs_init
Oct 12 20:35:12 raspberrypi kernel: [    2.612255] of_cfs_init: OK
Oct 12 20:35:12 raspberrypi kernel: [    2.627939] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Oct 12 20:35:12 raspberrypi kernel: [    2.628068] Waiting for root device PARTUUID=50d7c220-02...
Oct 12 20:35:12 raspberrypi kernel: [    2.636460] Indeed it is in host mode hprt0 = 00021501
Oct 12 20:35:12 raspberrypi kernel: [    2.676188] random: fast init done
Oct 12 20:35:12 raspberrypi kernel: [    2.697251] mmc0: host does not support reading read-only switch, assuming write-enable
Oct 12 20:35:12 raspberrypi kernel: [    2.705805] mmc0: new high speed SDHC card at address aaaa
Oct 12 20:35:12 raspberrypi kernel: [    2.709563] mmcblk0: mmc0:aaaa SC32G 29.7 GiB
Oct 12 20:35:12 raspberrypi kernel: [    2.715919]  mmcblk0: p1 p2
Oct 12 20:35:12 raspberrypi kernel: [    2.742023] mmc1: new high speed SDIO card at address 0001
Oct 12 20:35:12 raspberrypi kernel: [    2.761546] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Oct 12 20:35:12 raspberrypi kernel: [    2.766016] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Oct 12 20:35:12 raspberrypi kernel: [    2.778504] devtmpfs: mounted
Oct 12 20:35:12 raspberrypi kernel: [    2.788804] Freeing unused kernel memory: 1024K
Oct 12 20:35:12 raspberrypi kernel: [    2.796725] Run /sbin/init as init process
Oct 12 20:35:12 raspberrypi kernel: [    2.846336] usb 1-1: new high-speed USB device number 2 using dwc_otg
Oct 12 20:35:12 raspberrypi kernel: [    2.849067] Indeed it is in host mode hprt0 = 00001101
Oct 12 20:35:12 raspberrypi kernel: [    3.086698] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
Oct 12 20:35:12 raspberrypi kernel: [    3.092002] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 12 20:35:12 raspberrypi kernel: [    3.095633] hub 1-1:1.0: USB hub found
Oct 12 20:35:12 raspberrypi kernel: [    3.098576] hub 1-1:1.0: 5 ports detected
Oct 12 20:35:12 raspberrypi kernel: [    3.416330] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Oct 12 20:35:12 raspberrypi kernel: [    3.546704] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
Oct 12 20:35:12 raspberrypi kernel: [    3.552173] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 12 20:35:12 raspberrypi kernel: [    3.557854] smsc95xx v1.0.6
Oct 12 20:35:12 raspberrypi kernel: [    3.594586] NET: Registered protocol family 10
Oct 12 20:35:12 raspberrypi kernel: [    3.598834] Segment Routing with IPv6
Oct 12 20:35:12 raspberrypi kernel: [    3.653814] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:39:a5:84
Oct 12 20:35:12 raspberrypi kernel: [    3.660125] usb 1-1-port2: over-current change #1
Oct 12 20:35:12 raspberrypi kernel: [    4.216342] usb 1-1.3: new full-speed USB device number 4 using dwc_otg
Oct 12 20:35:12 raspberrypi kernel: [    4.238387] random: lvmconfig: uninitialized urandom read (4 bytes read)
Oct 12 20:35:12 raspberrypi kernel: [    4.354200] usb 1-1.3: New USB device found, idVendor=8086, idProduct=0808, bcdDevice= 1.00
Oct 12 20:35:12 raspberrypi kernel: [    4.360093] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Oct 12 20:35:12 raspberrypi kernel: [    4.363094] usb 1-1.3: Product: USB PnP Sound Device
Oct 12 20:35:12 raspberrypi kernel: [    4.365989] usb 1-1.3: Manufacturer: C-Media Electronics Inc.      
Oct 12 20:35:12 raspberrypi kernel: [    4.374653] input: C-Media Electronics Inc.       USB PnP Sound Device as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.3/0003:8086:0808.0001/input/input0
Oct 12 20:35:12 raspberrypi kernel: [    4.446613] hid-generic 0003:8086:0808.0001: input,hidraw0: USB HID v1.00 Device [C-Media Electronics Inc.       USB PnP Sound Device] on usb-3f980000.usb-1.3/input3
Oct 12 20:35:12 raspberrypi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Oct 12 20:35:12 raspberrypi rngd[446]: entropy feed to the kernel ready
Oct 12 20:35:12 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Oct 12 20:35:12 raspberrypi systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Oct 12 20:35:12 raspberrypi kernel: [    4.756342] usb 1-1.2: new full-speed USB device number 5 using dwc_otg
Oct 12 20:35:12 raspberrypi kernel: [    4.889705] usb 1-1.2: New USB device found, idVendor=413d, idProduct=2107, bcdDevice= 0.00
Oct 12 20:35:12 raspberrypi kernel: [    4.896448] usb 1-1.2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 12 20:35:12 raspberrypi kernel: [    4.904431] input: HID 413d:2107 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2:1.0/0003:413D:2107.0002/input/input1
Oct 12 20:35:12 raspberrypi kernel: [    4.904882] random: systemd: uninitialized urandom read (16 bytes read)
Oct 12 20:35:12 raspberrypi kernel: [    4.932679] random: systemd: uninitialized urandom read (16 bytes read)
Oct 12 20:35:12 raspberrypi kernel: [    4.977001] hid-generic 0003:413D:2107.0002: input,hidraw1: USB HID v1.11 Keyboard [HID 413d:2107] on usb-3f980000.usb-1.2/input0
Oct 12 20:35:12 raspberrypi kernel: [    6.096909] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Oct 12 20:35:12 raspberrypi kernel: [    6.920670] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    6.924106] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
Oct 12 20:35:12 raspberrypi kernel: [    6.924135] [vc_sm_connected_init]: start
Oct 12 20:35:12 raspberrypi kernel: [    6.926668] [vc_sm_connected_init]: installed successfully
Oct 12 20:35:12 raspberrypi kernel: [    6.955747] mc: Linux media interface: v0.10
Oct 12 20:35:12 raspberrypi kernel: [    7.001075] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.005760] videodev: Linux video capture interface: v2.00
Oct 12 20:35:12 raspberrypi kernel: [    7.008949] bcm2835_audio bcm2835_audio: card created with 8 channels
Oct 12 20:35:12 raspberrypi kernel: [    7.056781] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.059875] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.073987] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.093366] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.117467] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.133015] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
Oct 12 20:35:12 raspberrypi kernel: [    7.145553] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
Oct 12 20:35:12 raspberrypi kernel: [    7.156193] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
Oct 12 20:35:12 raspberrypi kernel: [    7.157559] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
Oct 12 20:35:12 raspberrypi kernel: [    7.158052] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
Oct 12 20:35:12 raspberrypi kernel: [    7.158087] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
Oct 12 20:35:12 raspberrypi kernel: [    7.158118] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
Oct 12 20:35:12 raspberrypi kernel: [    7.158137] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
Oct 12 20:35:12 raspberrypi kernel: [    7.158154] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
Oct 12 20:35:12 raspberrypi kernel: [    7.158359] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
Oct 12 20:35:12 raspberrypi kernel: [    7.256513] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
Oct 12 20:35:12 raspberrypi kernel: [    7.256567] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
Oct 12 20:35:12 raspberrypi kernel: [    7.297612] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
Oct 12 20:35:12 raspberrypi kernel: [    7.297681] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
Oct 12 20:35:12 raspberrypi kernel: [    7.348067] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
Oct 12 20:35:12 raspberrypi kernel: [    7.348117] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
Oct 12 20:35:12 raspberrypi kernel: [    7.388867] cfg80211: Loading compiled-in X.509 certificates for regulatory database
Oct 12 20:35:12 raspberrypi kernel: [    7.582555] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
Oct 12 20:35:12 raspberrypi kernel: [    7.703275] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
Oct 12 20:35:12 raspberrypi kernel: [    7.715468] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
Oct 12 20:35:12 raspberrypi kernel: [    7.715776] usbcore: registered new interface driver brcmfmac
Oct 12 20:35:12 raspberrypi kernel: [    7.737020] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,3-model-b.txt failed with error -2
Oct 12 20:35:12 raspberrypi kernel: [    7.882524] usbcore: registered new interface driver snd-usb-audio
Oct 12 20:35:12 raspberrypi kernel: [    7.985413] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
Oct 12 20:35:12 raspberrypi kernel: [    7.985513] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
Oct 12 20:35:12 raspberrypi kernel: [    7.986447] 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
Oct 12 20:35:12 raspberrypi kernel: [    8.363996] random: crng init done
Oct 12 20:35:12 raspberrypi kernel: [    8.364009] random: 7 urandom warning(s) missed due to ratelimiting
Oct 12 20:35:12 raspberrypi systemd[1]: Starting Login Service...
Oct 12 20:35:12 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Oct 12 20:35:13 raspberrypi systemd[1]: Starting WPA supplicant...
Oct 12 20:35:13 raspberrypi kernel: [   10.510928] uart-pl011 3f201000.serial: no DMA platform data
Oct 12 20:35:13 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Oct 12 20:35:13 raspberrypi systemd[1]: Started Daily Cleanup of Temporary Directories.
Oct 12 20:35:13 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Oct 12 20:35:13 raspberrypi systemd[1]: Reached target Timers.
Oct 12 20:35:13 raspberrypi systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Oct 12 20:35:13 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Oct 12 20:35:13 raspberrypi systemd[1]: Started System Logging Service.
Oct 12 20:35:13 raspberrypi systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Oct 12 20:35:13 raspberrypi systemd[1]: Started rng-tools.service.
Oct 12 20:35:13 raspberrypi dhcpcd[475]: dev: loaded udev
Oct 12 20:35:13 raspberrypi systemd[1]: Started Deferred execution scheduler.
Oct 12 20:35:13 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Oct 12 20:35:13 raspberrypi dphys-swapfile[442]: want /var/swap=100MByte, checking existing: keeping it
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Successfully dropped root privileges.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: avahi-daemon 0.7 starting up.
Oct 12 20:35:13 raspberrypi systemd[1]: Reached target Sound Card.
Oct 12 20:35:13 raspberrypi kernel: [   10.701375] 8021q: 802.1Q VLAN Support v1.8
Oct 12 20:35:13 raspberrypi cleanshutd[448]: Starting...
Oct 12 20:35:13 raspberrypi kernel: [   10.776431] Adding 102396k swap on /var/swap.  Priority:-2 extents:2 across:307200k SSFS
Oct 12 20:35:13 raspberrypi dbus-daemon[485]: [system] Successfully activated service 'org.freedesktop.systemd1'
Oct 12 20:35:13 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Successfully called chroot().
Oct 12 20:35:13 raspberrypi systemd[1]: Started Login Service.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Successfully dropped remaining capabilities.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: No service file found in /etc/avahi/services.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Network interface enumeration completed.
Oct 12 20:35:13 raspberrypi avahi-daemon[506]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 2467196832.
Oct 12 20:35:13 raspberrypi systemd[1]: Started LSB: Monitoring GPIO shutdown trigger.
Oct 12 20:35:13 raspberrypi systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Oct 12 20:35:13 raspberrypi wpa_supplicant[501]: Successfully initialized wpa_supplicant
Oct 12 20:35:13 raspberrypi systemd[1]: Started WPA supplicant.
Oct 12 20:35:13 raspberrypi dhcpcd[475]: wlan0: starting wpa_supplicant
Oct 12 20:35:13 raspberrypi dhcpcd-run-hooks[547]: wlan0: starting wpa_supplicant
Oct 12 20:35:13 raspberrypi kernel: [   11.108382] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: connected to Access Point `'
Oct 12 20:35:14 raspberrypi dhcpcd[475]: eth0: waiting for carrier
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: waiting for carrier
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: carrier acquired
Oct 12 20:35:14 raspberrypi kernel: [   11.599175] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Oct 12 20:35:14 raspberrypi dhcpcd[475]: DUID 00:01:00:01:26:d1:11:69:b8:27:eb:39:a5:84
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: IAID eb:6c:f0:d1
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: adding address fe80::ba27:ebff:fe6c:f0d1
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe6c:f0d1.
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: New relevant interface wlan0.IPv6 for mDNS.
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: probing address 192.168.0.18/24
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: Registering new address record for fe80::ba27:ebff:fe6c:f0d1 on wlan0.*.
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: carrier lost
Oct 12 20:35:14 raspberrypi dhcpcd[475]: wlan0: deleting address fe80::ba27:ebff:fe6c:f0d1
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: Withdrawing address record for fe80::ba27:ebff:fe6c:f0d1 on wlan0.
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe6c:f0d1.
Oct 12 20:35:14 raspberrypi avahi-daemon[506]: Interface wlan0.IPv6 no longer relevant for mDNS.
Oct 12 20:35:14 raspberrypi raspi-config[473]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Oct 12 20:35:14 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: carrier acquired
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: connected to Access Point `KabelBox-F289'
Oct 12 20:35:15 raspberrypi kernel: [   12.863046] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: IAID eb:6c:f0:d1
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: adding address fe80::ba27:ebff:fe6c:f0d1
Oct 12 20:35:15 raspberrypi avahi-daemon[506]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe6c:f0d1.
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: probing address 192.168.0.18/24
Oct 12 20:35:15 raspberrypi avahi-daemon[506]: New relevant interface wlan0.IPv6 for mDNS.
Oct 12 20:35:15 raspberrypi avahi-daemon[506]: Registering new address record for fe80::ba27:ebff:fe6c:f0d1 on wlan0.*.
Oct 12 20:35:15 raspberrypi dhcpcd[475]: wlan0: soliciting an IPv6 router
Oct 12 20:35:16 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: adding address 2a02:8108:1680:1803:ba27:ebff:fe6c:f0d1/64
Oct 12 20:35:16 raspberrypi avahi-daemon[506]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::ba27:ebff:fe6c:f0d1.
Oct 12 20:35:16 raspberrypi avahi-daemon[506]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2a02:8108:1680:1803:ba27:ebff:fe6c:f0d1.
Oct 12 20:35:16 raspberrypi avahi-daemon[506]: Registering new address record for 2a02:8108:1680:1803:ba27:ebff:fe6c:f0d1 on wlan0.*.
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: adding route to 2a02:8108:1680:1803::/64
Oct 12 20:35:16 raspberrypi avahi-daemon[506]: Withdrawing address record for fe80::ba27:ebff:fe6c:f0d1 on wlan0.
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: requesting DHCPv6 information
Oct 12 20:35:16 raspberrypi kernel: [   14.182028] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.wlan0.retrans_time - use net.ipv6.neigh.wlan0.retrans_time_ms instead
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: fe80::de53:7cff:fef4:c9ae is reachable again
Oct 12 20:35:16 raspberrypi dhcpcd[475]: wlan0: adding default route via fe80::de53:7cff:fef4:c9ae
Oct 12 20:35:17 raspberrypi kernel: [   14.728514] Bluetooth: Core ver 2.22
Oct 12 20:35:17 raspberrypi kernel: [   14.728595] NET: Registered protocol family 31
Oct 12 20:35:17 raspberrypi kernel: [   14.728603] Bluetooth: HCI device and connection manager initialized
Oct 12 20:35:17 raspberrypi kernel: [   14.728629] Bluetooth: HCI socket layer initialized
Oct 12 20:35:17 raspberrypi kernel: [   14.728643] Bluetooth: L2CAP socket layer initialized
Oct 12 20:35:17 raspberrypi kernel: [   14.728666] Bluetooth: SCO socket layer initialized
Oct 12 20:35:17 raspberrypi kernel: [   14.740749] Bluetooth: HCI UART driver ver 2.3
Oct 12 20:35:17 raspberrypi kernel: [   14.740766] Bluetooth: HCI UART protocol H4 registered
Oct 12 20:35:17 raspberrypi kernel: [   14.740832] Bluetooth: HCI UART protocol Three-wire (H5) registered
Oct 12 20:35:17 raspberrypi kernel: [   14.741052] Bluetooth: HCI UART protocol Broadcom registered
Oct 12 20:35:17 raspberrypi btuart[428]: bcm43xx_init
Oct 12 20:35:17 raspberrypi btuart[428]: Flash firmware /lib/firmware/brcm/BCM43430A1.hcd
Oct 12 20:35:17 raspberrypi btuart[428]: Set BDADDR UART: b8:27:eb:93:0f:2e
Oct 12 20:35:17 raspberrypi btuart[428]: Set Controller UART speed to 921600 bit/s
Oct 12 20:35:17 raspberrypi btuart[428]: Device setup complete
Oct 12 20:35:17 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Oct 12 20:35:17 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Oct 12 20:35:17 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Oct 12 20:35:17 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Oct 12 20:35:17 raspberrypi systemd[1]: Starting Bluetooth service...
Oct 12 20:35:17 raspberrypi bluetoothd[630]: Bluetooth daemon 5.50
Oct 12 20:35:17 raspberrypi systemd[1]: Started Bluetooth service.
Oct 12 20:35:17 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Oct 12 20:35:17 raspberrypi systemd[1]: Reached target Bluetooth.
Oct 12 20:35:17 raspberrypi bluetoothd[630]: Starting SDP server
Oct 12 20:35:17 raspberrypi kernel: [   15.024915] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Oct 12 20:35:17 raspberrypi kernel: [   15.024929] Bluetooth: BNEP filters: protocol multicast
Oct 12 20:35:17 raspberrypi kernel: [   15.024946] Bluetooth: BNEP socket layer initialized
Oct 12 20:35:17 raspberrypi dbus-daemon[485]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=630 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 20:35:17 raspberrypi bluetoothd[630]: Bluetooth management interface 1.14 initialized
Oct 12 20:35:17 raspberrypi bluetoothd[630]: Sap driver initialization failed.
Oct 12 20:35:17 raspberrypi bluetoothd[630]: sap-server: Operation not permitted (1)
Oct 12 20:35:17 raspberrypi bthelper[634]: Raspberry Pi BDADDR already set
Oct 12 20:35:17 raspberrypi systemd[1]: Starting Hostname Service...
Oct 12 20:35:17 raspberrypi bluetoothd[630]: Failed to set privacy: Rejected (0x0b)
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E Alias: BlueZ 5.50
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E Pairable: yes
Oct 12 20:35:17 raspberrypi bthelper[634]: Changing power off succeeded
Oct 12 20:35:17 raspberrypi dbus-daemon[485]: [system] Successfully activated service 'org.freedesktop.hostname1'
Oct 12 20:35:17 raspberrypi systemd[1]: Started Hostname Service.
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E Name: raspberrypi
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E Alias: BlueZ 5.50
Oct 12 20:35:17 raspberrypi bthelper[634]: Changing power on succeeded
Oct 12 20:35:17 raspberrypi bthelper[634]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:93:0F:2E Powered: yes
Oct 12 20:35:17 raspberrypi systemd[1]: bthelper@hci0.service: Succeeded.
Oct 12 20:35:20 raspberrypi dhcpcd[475]: wlan0: using static address 192.168.0.18/24
Oct 12 20:35:20 raspberrypi avahi-daemon[506]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.18.
Oct 12 20:35:20 raspberrypi avahi-daemon[506]: New relevant interface wlan0.IPv4 for mDNS.
Oct 12 20:35:20 raspberrypi dhcpcd[475]: wlan0: adding route to 192.168.0.0/24
Oct 12 20:35:20 raspberrypi avahi-daemon[506]: Registering new address record for 192.168.0.18 on wlan0.IPv4.
Oct 12 20:35:20 raspberrypi dhcpcd[475]: wlan0: adding default route via 192.168.0.1
Oct 12 20:35:21 raspberrypi dhcpcd[475]: forked to background, child pid 748
Oct 12 20:35:21 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Oct 12 20:35:21 raspberrypi systemd[1]: Reached target Network.
Oct 12 20:35:21 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox Idle Watchdog Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox Rotary Encoder Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Reached target Network is Online.
Oct 12 20:35:21 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Oct 12 20:35:21 raspberrypi systemd[752]: phoniebox-rotary-encoder.service: Failed to execute command: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[752]: phoniebox-rotary-encoder.service: Failed at step EXEC spawning /home/pi/RPi-Jukebox-RFID/scripts/rotary-encoder.py: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Lighttpd Daemon...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting LSB: Fetch LDAP SSL public key from the server...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting LSB: Enabling NAT for clients behind eth1...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting LSB: initscript for cfengine3...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Samba NMB Daemon...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Music Player Daemon...
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox GPIO Buttons Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Permit User Sessions...
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Main process exited, code=exited, status=203/EXEC
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:21 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Permit User Sessions.
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Scheduled restart job, restart counter is at 1.
Oct 12 20:35:21 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Oct 12 20:35:21 raspberrypi systemd[1]: Stopped Phoniebox Rotary Encoder Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox Rotary Encoder Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Oct 12 20:35:21 raspberrypi systemd[1]: Starting Terminate Plymouth Boot Screen...
Oct 12 20:35:21 raspberrypi systemd[782]: phoniebox-rotary-encoder.service: Failed to execute command: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[782]: phoniebox-rotary-encoder.service: Failed at step EXEC spawning /home/pi/RPi-Jukebox-RFID/scripts/rotary-encoder.py: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[1]: Started LSB: Enabling NAT for clients behind eth1.
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Main process exited, code=exited, status=203/EXEC
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:21 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 190 (plymouthd).
Oct 12 20:35:21 raspberrypi systemd[1]: Started LSB: initscript for cfengine3.
Oct 12 20:35:21 raspberrypi systemd[1]: plymouth-start.service: Succeeded.
Oct 12 20:35:21 raspberrypi systemd[1]: plymouth-quit-wait.service: Succeeded.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Oct 12 20:35:21 raspberrypi systemd[1]: plymouth-quit.service: Succeeded.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Terminate Plymouth Boot Screen.
Oct 12 20:35:21 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 190 (n/a).
Oct 12 20:35:21 raspberrypi systemd[1]: Started Getty on tty1.
Oct 12 20:35:21 raspberrypi systemd[1]: Reached target Login Prompts.
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Scheduled restart job, restart counter is at 2.
Oct 12 20:35:21 raspberrypi systemd[1]: Stopped Phoniebox Rotary Encoder Service.
Oct 12 20:35:21 raspberrypi systemd[1]: Started Phoniebox Rotary Encoder Service.
Oct 12 20:35:21 raspberrypi systemd[872]: phoniebox-rotary-encoder.service: Failed to execute command: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[872]: phoniebox-rotary-encoder.service: Failed at step EXEC spawning /home/pi/RPi-Jukebox-RFID/scripts/rotary-encoder.py: No such file or directory
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Main process exited, code=exited, status=203/EXEC
Oct 12 20:35:21 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Scheduled restart job, restart counter is at 3.
Oct 12 20:35:22 raspberrypi systemd[1]: Started Lighttpd Daemon.
Oct 12 20:35:22 raspberrypi systemd[1]: Stopped Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[1]: Started Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[874]: phoniebox-rotary-encoder.service: Failed to execute command: No such file or directory
Oct 12 20:35:22 raspberrypi systemd[874]: phoniebox-rotary-encoder.service: Failed at step EXEC spawning /home/pi/RPi-Jukebox-RFID/scripts/rotary-encoder.py: No such file or directory
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Main process exited, code=exited, status=203/EXEC
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:22 raspberrypi daemon_rfid_reader.py[750]: 2020-10-12 20:35:22,327 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Scheduled restart job, restart counter is at 4.
Oct 12 20:35:22 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Oct 12 20:35:22 raspberrypi systemd[1]: Stopped Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[1]: Started Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[879]: phoniebox-rotary-encoder.service: Failed to execute command: No such file or directory
Oct 12 20:35:22 raspberrypi systemd[879]: phoniebox-rotary-encoder.service: Failed at step EXEC spawning /home/pi/RPi-Jukebox-RFID/scripts/rotary-encoder.py: No such file or directory
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Main process exited, code=exited, status=203/EXEC
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Scheduled restart job, restart counter is at 5.
Oct 12 20:35:22 raspberrypi systemd[1]: Stopped Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Start request repeated too quickly.
Oct 12 20:35:22 raspberrypi systemd[1]: phoniebox-rotary-encoder.service: Failed with result 'exit-code'.
Oct 12 20:35:22 raspberrypi systemd[1]: Failed to start Phoniebox Rotary Encoder Service.
Oct 12 20:35:22 raspberrypi systemd[1]: Started Samba NMB Daemon.
Oct 12 20:35:22 raspberrypi systemd[1]: Starting Samba SMB Daemon...
Oct 12 20:35:23 raspberrypi debian-edu-ldapserver: The function 'find_ldap_server' did not provide a ldap host and fallback 'ldap' does not work.
Oct 12 20:35:23 raspberrypi systemd[1]: Started LSB: Fetch LDAP SSL public key from the server.
Oct 12 20:35:23 raspberrypi systemd[1]: Starting LSB: Update chromium configuration from LDAP...
Oct 12 20:35:23 raspberrypi systemd[1]: Starting LSB: Update firefox configuration from LDAP...
Oct 12 20:35:23 raspberrypi systemd[1]: Started LSB: Update chromium configuration from LDAP.
Oct 12 20:35:23 raspberrypi systemd[1]: Started LSB: Update firefox configuration from LDAP.
Oct 12 20:35:24 raspberrypi systemd[1]: Started Samba SMB Daemon.
Oct 12 20:35:25 raspberrypi systemd[1]: Started Music Player Daemon.
Oct 12 20:35:25 raspberrypi systemd[1]: Starting Phoniebox Startup...
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOFOLDERSPATH="/home/pi/RPi-Jukebox-RFID/shared/audiofolders"
Oct 12 20:35:25 raspberrypi bash[936]: PLAYLISTSFOLDERPATH="/home/pi/RPi-Jukebox-RFID/playlists"
Oct 12 20:35:25 raspberrypi bash[936]: SECONDSWIPE="PAUSE"
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOIFACENAME="PCM"
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOVOLCHANGESTEP="3"
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOVOLMAXLIMIT="100"
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOVOLMINLIMIT="1"
Oct 12 20:35:25 raspberrypi bash[936]: AUDIOVOLSTARTUP="10"
Oct 12 20:35:25 raspberrypi bash[936]: VOLCHANGEIDLE="TRUE"
Oct 12 20:35:25 raspberrypi bash[936]: IDLETIMESHUTDOWN="30"
Oct 12 20:35:25 raspberrypi bash[936]: SHOWCOVER="ON"
Oct 12 20:35:25 raspberrypi bash[936]: READWLANIPYN="OFF"
Oct 12 20:35:25 raspberrypi bash[936]: EDITION="classic"
Oct 12 20:35:25 raspberrypi bash[936]: LANG="de-DE"
Oct 12 20:35:25 raspberrypi bash[936]: VERSION="2.0 - ed888da - master"
Oct 12 20:35:25 raspberrypi bash[936]: 10
Oct 12 20:35:25 raspberrypi bash[936]: OK MPD 0.21.4
Oct 12 20:35:25 raspberrypi bash[936]: OK
Oct 12 20:35:26 raspberrypi dhcpcd[748]: wlan0: failed to request information
Oct 12 20:35:26 raspberrypi dhcpcd[748]: wlan0: fe80::de53:7cff:fef4:c9ae is reachable again
Oct 12 20:35:26 raspberrypi dhcpcd[748]: wlan0: fe80::de53:7cff:fef4:c9ae is reachable again
Oct 12 20:35:27 raspberrypi bash[936]: High Performance MPEG 1.0/2.0/2.5 Audio Player for Layers 1, 2 and 3
Oct 12 20:35:27 raspberrypi bash[936]: #011version 1.25.10; written and copyright by Michael Hipp and others
Oct 12 20:35:27 raspberrypi bash[936]: #011free software (LGPL) without any warranty but with best wishes
Oct 12 20:35:27 raspberrypi bash[936]: Directory: /home/pi/RPi-Jukebox-RFID/shared/
Oct 12 20:35:27 raspberrypi bash[936]: Playing MPEG stream 1 of 1: startupsound.mp3 ...
Oct 12 20:35:27 raspberrypi bash[936]: MPEG 1.0 L III cbr64 44100 j-s
Oct 12 20:35:27 raspberrypi bash[936]: Artist:  Phoniebox
Oct 12 20:35:31 raspberrypi bash[936]: [0:04] Decoding of startupsound.mp3 finished.
Oct 12 20:35:31 raspberrypi systemd[1]: Started Phoniebox Startup.
Oct 12 20:35:31 raspberrypi systemd[1]: Reached target Multi-User System.
Oct 12 20:35:31 raspberrypi systemd[1]: Reached target Graphical Interface.
Oct 12 20:35:32 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Oct 12 20:35:32 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Oct 12 20:35:32 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Oct 12 20:35:32 raspberrypi systemd[1]: Startup finished in 3.371s (kernel) + 26.160s (userspace) = 29.531s.
Oct 12 20:35:39 raspberrypi systemd[1]: Stopping Phoniebox RFID-Reader Service...
Oct 12 20:35:39 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=killed, status=15/TERM
Oct 12 20:35:39 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Succeeded.
Oct 12 20:35:39 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:35:41 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Oct 12 20:36:40 raspberrypi systemd-timesyncd[381]: Synchronized to time server for the first time [2a01:4f8:150:1287::2]:123 (2.debian.pool.ntp.org).
Oct 12 20:36:44 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:36:45 raspberrypi daemon_rfid_reader.py[1282]: 2020-10-12 20:36:45,158 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Oct 12 20:36:45 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Oct 12 20:38:29 raspberrypi kernel: [  149.126913] usb 1-1.2: USB disconnect, device number 5
Oct 12 20:38:29 raspberrypi thd[440]: Error reading device '/dev/input/event1'
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]: Traceback (most recent call last):
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/home/pi/RPi-Jukebox-RFID/scripts/daemon_rfid_reader.py", line 38, in <module>
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     cardid = reader.reader.readCard()
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/home/pi/RPi-Jukebox-RFID/scripts/Reader.py", line 58, in readCard
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     for event in self.dev.read():
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/usr/local/lib/python3.7/dist-packages/evdev/eventio.py", line 67, in read
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     events = _input.device_read_many(self.fd)
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]: OSError: [Errno 19] No such device
Oct 12 20:38:29 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:29 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:29 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:29 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 1.
Oct 12 20:38:29 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:29 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:38:30 raspberrypi daemon_rfid_reader.py[1927]: Could not find the device HID 413d:2107
Oct 12 20:38:30 raspberrypi daemon_rfid_reader.py[1927]: . Make sure is connected
Oct 12 20:38:30 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:30 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:30 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:30 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 2.
Oct 12 20:38:30 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:30 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:38:30 raspberrypi daemon_rfid_reader.py[1931]: Could not find the device HID 413d:2107
Oct 12 20:38:30 raspberrypi daemon_rfid_reader.py[1931]: . Make sure is connected
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 3.
Oct 12 20:38:31 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:31 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:38:31 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:38:31 raspberrypi daemon_rfid_reader.py[1946]: Could not find the device HID 413d:2107
Oct 12 20:38:31 raspberrypi daemon_rfid_reader.py[1946]: . Make sure is connected
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:31 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 4.
Oct 12 20:38:31 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:31 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:38:32 raspberrypi daemon_rfid_reader.py[1957]: Could not find the device HID 413d:2107
Oct 12 20:38:32 raspberrypi daemon_rfid_reader.py[1957]: . Make sure is connected
Oct 12 20:38:32 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:32 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:32 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:32 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 5.
Oct 12 20:38:32 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:32 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:38:33 raspberrypi daemon_rfid_reader.py[1961]: Could not find the device HID 413d:2107
Oct 12 20:38:33 raspberrypi daemon_rfid_reader.py[1961]: . Make sure is connected
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Service RestartSec=100ms expired, scheduling restart.
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Scheduled restart job, restart counter is at 6.
Oct 12 20:38:33 raspberrypi systemd[1]: Stopped Phoniebox RFID-Reader Service.
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Start request repeated too quickly.
Oct 12 20:38:33 raspberrypi systemd[1]: phoniebox-rfid-reader.service: Failed with result 'exit-code'.
Oct 12 20:38:33 raspberrypi systemd[1]: Failed to start Phoniebox RFID-Reader Service.
Oct 12 20:38:42 raspberrypi kernel: [  162.846314] usb 1-1.2: new full-speed USB device number 6 using dwc_otg
Oct 12 20:38:43 raspberrypi kernel: [  162.978460] usb 1-1.2: New USB device found, idVendor=413d, idProduct=2107, bcdDevice= 0.00
Oct 12 20:38:43 raspberrypi kernel: [  162.978480] usb 1-1.2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 12 20:38:43 raspberrypi kernel: [  162.988479] input: HID 413d:2107 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2:1.0/0003:413D:2107.0003/input/input2
Oct 12 20:38:43 raspberrypi mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Oct 12 20:38:43 raspberrypi mtp-probe: bus: 1, device: 6 was not an MTP device
Oct 12 20:38:43 raspberrypi kernel: [  163.057410] hid-generic 0003:413D:2107.0003: input,hidraw1: USB HID v1.11 Keyboard [HID 413d:2107] on usb-3f980000.usb-1.2/input0
Oct 12 20:38:43 raspberrypi systemd-udevd[2019]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Oct 12 20:38:43 raspberrypi mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Oct 12 20:38:43 raspberrypi mtp-probe: bus: 1, device: 6 was not an MTP device
Oct 12 20:38:59 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Oct 12 20:39:00 raspberrypi systemd[1]: Starting Clean php session files...
Oct 12 20:39:00 raspberrypi daemon_rfid_reader.py[2182]: 2020-10-12 20:39:00,288 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Oct 12 20:39:00 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
Oct 12 20:39:00 raspberrypi systemd[1]: Started Clean php session files.
Oct 12 20:39:01 raspberrypi CRON[2303]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Oct 12 20:39:03 raspberrypi daemon_rfid_reader.py[2182]: 2020-10-12 20:39:03,023 - root - INFO - Trigger Play Cardid=3fca2b
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: volume: 10%   repeat: off   random: off   single: off   consume: off
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: volume: 10%   repeat: off   random: off   single: off   consume: off
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: loading: Die Eule findet den Beat - Europatour
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: volume: 10%   repeat: off   random: off   single: off   consume: off
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: volume: 10%   repeat: off   random: off   single: off   consume: off
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: OK MPD 0.21.4
Oct 12 20:39:04 raspberrypi daemon_rfid_reader.py[2182]: OK
Oct 12 20:39:50 raspberrypi systemd[1]: getty@tty1.service: Succeeded.
Oct 12 20:39:50 raspberrypi systemd[1]: getty@tty1.service: Service has no hold-off time (RestartSec=0), scheduling restart.
Oct 12 20:39:50 raspberrypi systemd[1]: getty@tty1.service: Scheduled restart job, restart counter is at 1.
Oct 12 20:39:50 raspberrypi systemd[1]: Stopped Getty on tty1.
Oct 12 20:39:50 raspberrypi systemd[1]: Started Getty on tty1.
Oct 12 20:40:01 raspberrypi CRON[2926]: (root) CMD (if [ -x /usr/sbin/debian-edu-update-netblock ]; then /usr/sbin/debian-edu-update-netblock auto > /dev/null; fi)
Oct 12 20:40:01 raspberrypi debian-edu-update-netblock: making sure netblock is disabled
Oct 12 20:40:35 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:42:10 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:42:11 raspberrypi systemd-timesyncd[381]: Timed out waiting for reply from [2a01:4f8:150:1287::2]:123 (2.debian.pool.ntp.org).
Oct 12 20:42:12 raspberrypi systemd-timesyncd[381]: Synchronized to time server for the first time [2001:43f8:1f4:100::57]:123 (2.debian.pool.ntp.org).
Oct 12 20:43:48 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:45:01 raspberrypi CRON[5083]: (root) CMD (if [ -x /usr/sbin/debian-edu-update-netblock ]; then /usr/sbin/debian-edu-update-netblock auto > /dev/null; fi)
Oct 12 20:45:01 raspberrypi debian-edu-update-netblock: making sure netblock is disabled
Oct 12 20:45:06 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:45:33 raspberrypi gpio-buttons.py[771]: Die Eule findet den Beat - Europatour/20 Eule und das Erdweibchen - Teil 1-qXVK1GwU3S0.mp3
Oct 12 20:45:33 raspberrypi gpio-buttons.py[771]: [paused]  #20/26   2:23/4:47 (49%)
Oct 12 20:45:33 raspberrypi gpio-buttons.py[771]: volume:  4%   repeat: off   random: off   single: off   consume: off
Oct 12 20:46:32 raspberrypi idle-watchdog.sh[751]: warning: commands will be executed using /bin/sh
Oct 12 20:46:32 raspberrypi idle-watchdog.sh[751]: job 20 at Mon Oct 12 21:16:00 2020
Oct 12 20:48:02 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:49:28 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:50:02 raspberrypi CRON[6752]: (root) CMD (if [ -x /usr/sbin/debian-edu-update-netblock ]; then /usr/sbin/debian-edu-update-netblock auto > /dev/null; fi)
Oct 12 20:50:02 raspberrypi debian-edu-update-netblock: making sure netblock is disabled
Oct 12 20:50:55 raspberrypi dhcpcd[748]: wlan0: Router Advertisement from fe80::de53:7cff:fef4:c9ae
Oct 12 20:50:59 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Oct 12 20:50:59 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Oct 12 20:51:00 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Oct 12 20:51:00 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on GnuPG network certificate management daemon.
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Oct 12 20:51:00 raspberrypi systemd[7091]: Starting D-Bus User Message Bus Socket.
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on GnuPG cryptographic agent and passphrase cache.
Oct 12 20:51:00 raspberrypi systemd[7091]: Reached target Timers.
Oct 12 20:51:00 raspberrypi systemd[7091]: Reached target Paths.
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Oct 12 20:51:00 raspberrypi systemd[1]: Starting Cleanup of Temporary Directories...
Oct 12 20:51:00 raspberrypi systemd[7091]: Listening on D-Bus User Message Bus Socket.
Oct 12 20:51:00 raspberrypi systemd[7091]: Reached target Sockets.
Oct 12 20:51:00 raspberrypi systemd[7091]: Reached target Basic System.
Oct 12 20:51:00 raspberrypi systemd[1]: Started User Manager for UID 1000.
Oct 12 20:51:00 raspberrypi systemd[7091]: Starting Music Player Daemon...
Oct 12 20:51:00 raspberrypi systemd[1]: Started Session c1 of user pi.
Oct 12 20:51:00 raspberrypi systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Oct 12 20:51:00 raspberrypi systemd[1]: Started Cleanup of Temporary Directories.
Oct 12 20:51:01 raspberrypi mpd[7105]: exception: failed to open log file "/var/log/mpd/mpd.log" (config line 40): Permission denied
Oct 12 20:51:01 raspberrypi systemd[7091]: mpd.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 20:51:01 raspberrypi systemd[7091]: mpd.service: Failed with result 'exit-code'.
Oct 12 20:51:01 raspberrypi systemd[7091]: Failed to start Music Player Daemon.
Oct 12 20:51:01 raspberrypi systemd[7091]: Reached target Default.
Oct 12 20:51:01 raspberrypi systemd[7091]: Startup finished in 1.518s.

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

pi@raspberrypi:~ $ cd /home/pi/RPi-Jukebox-RFID/ && git status | head -2
Auf Branch master
Ihr Branch ist auf demselben Stand wie 'origin/master'.

Installscript

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

Hardware

RaspberryPi version

Raspberry Pi 3 Model B Rev 1.2

RFID Reader

Bus 001 Device 006: ID 413d:2107
idVendor 0x413d
idProduct 0x2107

Mitfahre card Reader M301

Soundcard

Bus 001 Device 004: ID 8086:0808 Intel Corp.
iManufacturer 1 C-Media Electronics Inc.
iProduct 2 USB PnP Sound Device

Other notable hardware

#!/usr/bin/env python3
import RPi.GPIO as GPIO
from signal import pause
from subprocess import check_call
import time
from time import sleep

# This script will block any I2S DAC e.g. from Hifiberry, Justboom, ES9023, PCM5102A
# due to the assignment of GPIO 19 and 21 to a buttons
#
# 2019-12-17
# Added support to detect RFID tag removal. Requires an appropriate switch
# makes no difference which hardware implementation you choose, could be a simple switch,
# or hidden magnetic switch or hacking the rfid reader as suggested here:
# https://github.com/MiczFlor/RPi-Jukebox-RFID/issues/62
#
# 2019-05-14
# * Rewrite using RPi.GPIO for Raspberry pi zero compatibility.
# * Added power LED functionality
#
# 2018-10-31
# Added the function on holding volume + - buttons to change the volume in 0.3s interval
#
# 2018-10-15
# this script has the `pull_up=True` for all pins. See the following link for additional info:
# https://github.com/MiczFlor/RPi-Jukebox-RFID/issues/259#issuecomment-430007446
#
# 2017-12-12
# This script was copied from the following RPi forum post:
# https://forum-raspberrypi.de/forum/thread/13144-projekt-jukebox4kids-jukebox-fuer-kinder/?postID=312257#post312257
# I have not yet had the time to test is, so I placed it in the misc folder.
# If anybody has ideas or tests or experience regarding this solution, please create pull requests or contact me.


# This function takes a holding time (fractional seconds), a channel, a GPIO state and an action reference (function).
# It checks if the GPIO is in the state since the function was called. If the state
# changes it return False. If the time is over the function returns True.
def checkGpioStaysInState(holdingTime, gpioChannel, gpioHoldingState):
    # Get a reference start time (https://docs.python.org/3/library/time.html#time.perf_counter)
    startTime = time.perf_counter()
    # Continously check if time is not over
    while(holdingTime >= (time.perf_counter() - startTime)):
        # Return if state does not match holding state
        if(gpioHoldingState != GPIO.input(gpioChannel)):
            return False
        # Else: Wait
    return True


# Actions that call other processes of the phoniebox (Channel Parameter needed by RPi.GPIO)
def shutdown_action(channel):
    check_call("./scripts/playout_controls.sh -c=shutdown", shell=True)


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


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


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


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


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


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


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


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


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


def rfidoff_action(channel):
    check_call("./scripts/playout_controls.sh -c=playerpauseforce -v=0.5", shell=True)


# Handlers that handle special behavior of the push of a button
# When the shutdown button was held for more than 2 seconds LED flashed and afterwards
def shutdown_handler(channel):
    # Detect holding of button
    if checkGpioStaysInState(shutdownHoldTime, btn_shut, GPIO.LOW) is True:
        # Blink LED
        for x in range(0, 10):
            GPIO.output(led_power, x & 1)
            sleep(PledBlinkTime)
        # Keep LED on until power off
        GPIO.output(led_power, GPIO.HIGH)
        # Shutdown afterwards
        shutdown_action(channel)


# When the Volume Down button was held for more than 0.3 seconds every 0.3 seconds he will lower t$
def volU_handler(channel):
    # Rise volume as requested
    volU_action(channel)
    # Detect holding of button
    while checkGpioStaysInState(volumeHoldTime, btn_volU, GPIO.LOW):
        volU_action(channel)


# When the Volume Up button was held for more than 0.3 seconds every 0.3 seconds he will call a ra$
def volD_handler(channel):
    # Rise volume as requested
    volD_action(channel)
    # Detect holding of button
    while checkGpioStaysInState(volumeHoldTime, btn_volD, GPIO.LOW):
        volD_action(channel)


# Define the used pins of the raspberry board
btn_shut = 3
btn_vol0 = 13
btn_volU = 16
btn_volD = 19
btn_next = 26
btn_prev = 20
btn_halt = 21
led_power = 12
# btn_rfidoff =
# reco =
# play =

# Set GPIO numbering to BCM instead of board numbering
GPIO.setmode(GPIO.BCM)
# Bounce tolerance time for buttons
bouncetime = 500
volumeHoldTime = 0.3  # Seconds
shutdownHoldTime = 2  # Seconds
PledBlinkTime = 0.3  # Seconds

# Set up GPIO pins and the power led
GPIO.setup(btn_shut, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_vol0, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_volU, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_volD, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_next, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_prev, GPIO.IN, pull_up_down=GPIO.PUD_UP)
GPIO.setup(btn_halt, GPIO.IN, pull_up_down=GPIO.PUD_UP)
# GPIO.setup(btn_rfidoff, GPIO.IN, pull_up_down=GPIO.PUD_DOWN)
GPIO.setup(led_power, GPIO.OUT)


# Set standard events for the buttons. Callback functions define the actions of the events (THey are defined above)
GPIO.add_event_detect(btn_shut, GPIO.FALLING, callback=shutdown_handler, bouncetime=bouncetime)
GPIO.add_event_detect(btn_vol0, GPIO.FALLING, callback=vol0_action, bouncetime=bouncetime)
GPIO.add_event_detect(btn_volU, GPIO.FALLING, callback=volU_handler, bouncetime=bouncetime)
GPIO.add_event_detect(btn_volD, GPIO.FALLING, callback=volD_handler, bouncetime=bouncetime)
GPIO.add_event_detect(btn_next, GPIO.FALLING, callback=next_action, bouncetime=bouncetime)
GPIO.add_event_detect(btn_prev, GPIO.FALLING, callback=prev_action, bouncetime=bouncetime)
GPIO.add_event_detect(btn_halt, GPIO.FALLING, callback=halt_action, bouncetime=bouncetime)
# GPIO.add_event_detect(btn_rfidoff, GPIO.FALLING, callback=rfidoff_action, bouncetime=bouncetime)
# reco.when_pressed = recordstart_action
# reco.when_released = recordstop_action
# play.when_pressed = recordplaylatest_action


# Switch on power led after boot to indicate state "on" for phoniebox
GPIO.output(led_power, GPIO.HIGH)

pause()
@Barzille Barzille added the bug label Oct 12, 2020
@s-martin
Copy link
Collaborator

The reader seems to disconnect, see here:

Oct 12 20:38:29 raspberrypi kernel: [  149.126913] usb 1-1.2: USB disconnect, device number 5
Oct 12 20:38:29 raspberrypi thd[440]: Error reading device '/dev/input/event1'
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]: Traceback (most recent call last):
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/home/pi/RPi-Jukebox-RFID/scripts/daemon_rfid_reader.py", line 38, in <module>
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     cardid = reader.reader.readCard()
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/home/pi/RPi-Jukebox-RFID/scripts/Reader.py", line 58, in readCard
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     for event in self.dev.read():
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:   File "/usr/local/lib/python3.7/dist-packages/evdev/eventio.py", line 67, in read
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]:     events = _input.device_read_many(self.fd)
Oct 12 20:38:29 raspberrypi daemon_rfid_reader.py[1282]: OSError: [Errno 19] No such device

Could you please check, if there's an issue with the hardware, e.g. loose cable, something broken, etc?

@Barzille
Copy link
Author

I believe this one of our attempts to remove and reconnect the device.
We hav meanwhile updated to 2.1 and we use currently the Reader.py.experimental file.

What we currently see is, that after booting it is not working (same as in 2.0) but when we disconnect and reconnect the reader it seems to work.
What we also see is that the Reader Service is stopped after disconnecting the reader, so we have to enable it manually.

I have an assumption that maybe the reader is initialized too early in the boot process, is this possible?

One ting that's also strange: If we shutdown the RPI while music is playing and we start up again we first get the rfid beep, then the music starts and then - while the music plays - we get a startup sound melody. Maybe something in disorder?

@Huseriato Huseriato mentioned this issue Oct 16, 2020
Open
@s-martin s-martin mentioned this issue Nov 21, 2020
Closed
@s-martin
Copy link
Collaborator

Are you experiencing this issue in combination with resume or shuffle?

We released 2.2 a couple of days ago with fixes for both resume and shuffle, so you might want to check, if this fixes also your issue.

@Barzille
Copy link
Author

It's working fine meanwhile

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug need more info
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Barzille @s-martin