Open TobiBu opened 1 year ago
TobiBu
commented
1 year ago I could narrow this down to the fact that for some reasons the while loop in daemon_rfid_reader.py takes quite long up to 5 seconds. this clashes with setting of the signal to force stop the playout which is set to 1 second. Any ideas why sometimes one loop might take 5 seconds?
AlvinSchiller
commented
1 year ago Hi, i tested your situation and couldn't reproduce it on a fresh installation (also with a RPi 4 and RC522 Reader). If i add a manuell "sleep" after the reading of the card (before the signal will be reseted), then it behaves just like you described. So something seems to be causing a delay while reading/processing the card.
Have you tried the rfid reader without phoniebox, if this delay is there noticable too (simple script to read the id)?
AlvinSchiller
commented
1 year ago Are you still having this Problem?
I noticed something simliar today when i was setting up a new Raspberry Pi (3A+) with a fresh image. The RFID Scan was very delayed, but the rest seemed to work fine. I tried the "Placing card" mode and got the behavior you described.
I checked the processes with "top" and turned out that "mpg123" was using 95% - 100% CPU. I killed the process and after that the scan was working normal again. mpg123 is used to play the Startup / Shutdown sound which seemed to hang, as the sound wasn't played.
I tried to play the sound directly with /usr/bin/mpg123 /home/pi/RPi-Jukebox-RFID/shared/startupsound.mp3 and got this error. Also using amixer scontrols was producing it.
...
ALSA lib conf.c:1970:(_snd_config_load_with_include) _toplevel_:18:1:Unexpected char
ALSA lib conf.c:3817:(config_file_open) /home/pi/.asoundrc may be old or corrupted: consider to remove or fix it
...I removed/renamed the "/home/pi/.asoundrc" file and the problems where gone.
TobiBu
commented
1 year ago Hi Alvin,
thanks for sharing these insights! I checked with top and for me there is no command "mpg123" running. Also manually invoking it does not result in any error. So I assume my issue is something else.
Anyways, I fixed it by changing one line in "~/RPi-Jukebox-RFID/scripts/daemon_rfid_reader.py"
I changed the signal alarm from 1 second to 10 seconds which circumvents my issues. But that's only a very crude quick fix...
`if swipe_or_place == "PLACENOTSWIPE":
signal.alarm(10)`
Mannshoch
commented
9 months ago As advised in (https://github.com/MiczFlor/RPi-Jukebox-RFID/discussions/2058#discussioncomment-7522310)
I have a Raspberry Pi 3 Model B Rev 1.2
Debian
Beschreibung
Debian GNU/Linux 11 (bullseye)
2.4 - abcf6e92 - master
Hardware: Neuftech USB 13,56 MHz kontaktlos Kartenleser 14443A-Protokoll IC
(Log deleted)WIFIconfig=NO
WIFIcountryCode=DE
EXISTINGuse=NO
AUDIOiFace="Headphone"
SPOTinstall="NO"
SPOTIuser=""
SPOTIpass=""
SPOTIclientid=""
SPOTIclientsecret=""
MPDconfig="YES"
DIRaudioFolders="/home/pi/RPi-Jukebox-RFID/shared/audiofolders"
GPIOconfig="YES"Hi, thanks for the log. Did you activate the mqtt service? It seems it is running but constantly restarting due to failure in the configuration. Can you deactivate the service and see if the situation gets better?
Mannshoch
commented
9 months ago I played around with mqtt for a while. As you said I deactivated it.
sudo systemctl stop phoniebox-mqtt-client
sudo systemctl disable phoniebox-mqtt-client
sudo systemctl rebootThe problem still exist.
Jan 8 22:26:22 phoniebox systemd[1]: Starting Samba NMB Daemon...
Jan 8 22:26:22 phoniebox systemd[1]: Starting /etc/rc.local Compatibility...
Jan 8 22:26:22 phoniebox systemd[1]: Started /etc/rc.local Compatibility.
Jan 8 22:26:22 phoniebox systemd[1]: Started Getty on tty1.
Jan 8 22:26:22 phoniebox systemd[1]: Reached target Login Prompts.
Jan 8 22:26:22 phoniebox systemd[1]: Started Samba NMB Daemon.
Jan 8 22:26:22 phoniebox systemd[1]: Starting Samba SMB Daemon...
Jan 8 22:26:23 phoniebox exim4[751]: Starting MTA: exim4.
Jan 8 22:26:23 phoniebox systemd[1]: Started LSB: exim Mail Transport Agent.
Jan 8 22:26:23 phoniebox systemd[1]: Started Samba SMB Daemon.
Jan 8 22:26:23 phoniebox lighttpd[752]: 2024-01-08 22:26:22: configfile.c.461) Warning: "mod_compress" is DEPRECATED and has been replaced with "mod_deflate". A future release of lighttpd 1.4.x will not contain mod_compress and lighttpd may fail to start up
Jan 8 22:26:23 phoniebox lighttpd[752]: 2024-01-08 22:26:22: mod_deflate.c.567) DEPRECATED: compress.filetype replaced with deflate.mimetypes
Jan 8 22:26:23 phoniebox lighttpd[752]: 2024-01-08 22:26:22: mod_deflate.c.580) DEPRECATED: compress.cache-dir replaced with deflate.cache-dir
Jan 8 22:26:23 phoniebox systemd[1]: Started Lighttpd Daemon.
Jan 8 22:26:24 phoniebox systemd[1]: systemd-rfkill.service: Succeeded.
Jan 8 22:26:24 phoniebox bthelper[1034]: Changing power off succeeded
Jan 8 22:26:24 phoniebox lighttpd[1026]: 2024-01-08 22:26:23: configfile.c.461) Warning: "mod_compress" is DEPRECATED and has been replaced with "mod_deflate". A future release of lighttpd 1.4.x will not contain mod_compress and lighttpd may fail to start up
Jan 8 22:26:24 phoniebox bthelper[594]: Changing power on succeeded
Jan 8 22:26:25 phoniebox bash[720]: [0:04] Decoding of startupsound.mp3 finished.
Jan 8 22:26:25 phoniebox bash[1041]: Updating DB (#1) ...
Jan 8 22:26:25 phoniebox bash[1041]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:26:25 phoniebox systemd[1]: Finished Phoniebox Startup.
Jan 8 22:26:25 phoniebox systemd[1]: Reached target Multi-User System.
Jan 8 22:26:25 phoniebox systemd[1]: Starting Update UTMP about System Runlevel Changes...
Jan 8 22:26:25 phoniebox systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Jan 8 22:26:25 phoniebox systemd[1]: Finished Update UTMP about System Runlevel Changes.
Jan 8 22:26:25 phoniebox systemd[1]: Startup finished in 4.014s (kernel) + 18.664s (userspace) = 22.678s.
(List of Media)
Jan 8 22:26:42 phoniebox systemd[1]: systemd-fsckd.service: Succeeded.
Jan 8 22:26:57 phoniebox systemd-timesyncd[325]: Initial synchronization to time server 216.229.0.50:123 (2.debian.pool.ntp.org).
Jan 8 22:27:02 phoniebox systemd[1]: Stopping Phoniebox RFID-Reader Service...
Jan 8 22:27:02 phoniebox systemd[1]: phoniebox-rfid-reader.service: Succeeded.
Jan 8 22:27:02 phoniebox systemd[1]: Stopped Phoniebox RFID-Reader Service.
Jan 8 22:27:02 phoniebox systemd[1]: Started Phoniebox RFID-Reader Service.
Jan 8 22:27:02 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:02,945 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Jan 8 22:27:03 phoniebox systemd[1]: systemd-hostnamed.service: Succeeded.
Jan 8 22:27:04 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:04,149 - root - INFO - No RFID Signal detected.
Jan 8 22:27:04 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:04,149 - root - INFO - Trigger Pause Force
Jan 8 22:27:19 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:19,487 - root - INFO - Trigger Play Cardid=0662287364
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1328]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1362]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1363]: loading: Lieder % kinderlieder - 100 Kinderlieder zum Mitsingen _ Die 30 Besten
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1372]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1381]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1390]: OK MPD 0.22.4
Jan 8 22:27:20 phoniebox daemon_rfid_reader.py[1390]: OK
Jan 8 22:27:20 phoniebox mpd: exception: Failed to open mixer for 'My ALSA Device': no such mixer control: Headphone
Jan 8 22:27:22 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:22,943 - root - INFO - No RFID Signal detected.
Jan 8 22:27:22 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:22,944 - root - INFO - Trigger Pause Force
Jan 8 22:27:23 phoniebox daemon_rfid_reader.py[1448]: Kinderlieder zum Mitsingen || Kinderlieder
Jan 8 22:27:23 phoniebox daemon_rfid_reader.py[1448]: [paused] #1/98 0:04/2:14 (2%)
Jan 8 22:27:23 phoniebox daemon_rfid_reader.py[1448]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:27:29 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:29,337 - root - INFO - Trigger Play Cardid=0662287364
Jan 8 22:27:29 phoniebox mpd: exception: Failed to open mixer for 'My ALSA Device': no such mixer control: Headphone
Jan 8 22:27:31 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:31,084 - root - INFO - No RFID Signal detected.
Jan 8 22:27:31 phoniebox daemon_rfid_reader.py[1154]: 2024-01-08 22:27:31,085 - root - INFO - Trigger Pause Force
Jan 8 22:27:31 phoniebox idle-watchdog.sh[1655]: warning: commands will be executed using /bin/sh
Jan 8 22:27:31 phoniebox idle-watchdog.sh[1655]: job 7 at Mon Jan 8 22:57:00 2024
Jan 8 22:27:31 phoniebox daemon_rfid_reader.py[1664]: Kinderlieder zum Mitsingen || Kinderlieder
Jan 8 22:27:31 phoniebox daemon_rfid_reader.py[1664]: [paused] #1/98 0:06/2:14 (4%)
Jan 8 22:27:31 phoniebox daemon_rfid_reader.py[1664]: volume: n/a repeat: off random: off single: off consume: off
Jan 8 22:28:19 phoniebox systemd[1]: getty@tty1.service: Succeeded.
Jan 8 22:28:19 phoniebox systemd[1]: getty@tty1.service: Scheduled restart job, restart counter is at 1.
Jan 8 22:28:19 phoniebox systemd[1]: Stopped Getty on tty1.
Jan 8 22:28:19 phoniebox systemd[1]: Started Getty on tty1.
Jan 8 22:30:10 phoniebox systemd[1]: Starting Discard unused blocks on filesystems from /etc/fstab...
Jan 8 22:30:18 phoniebox fstrim[2999]: /: 53.8 GiB (57810141184 bytes) trimmed on /dev/mmcblk0p2
Jan 8 22:30:18 phoniebox fstrim[2999]: /boot: 224.3 MiB (235245568 bytes) trimmed on /dev/mmcblk0p1
Jan 8 22:30:18 phoniebox systemd[1]: fstrim.service: Succeeded.
Jan 8 22:30:18 phoniebox systemd[1]: Finished Discard unused blocks on filesystems from /etc/fstab.
Jan 8 22:31:22 phoniebox systemd[1]: Created slice User Slice of UID 1000.
Jan 8 22:31:22 phoniebox systemd[1]: Starting User Runtime Directory /run/user/1000...
Jan 8 22:31:22 phoniebox systemd[1]: Finished User Runtime Directory /run/user/1000.
Jan 8 22:31:22 phoniebox systemd[1]: Starting User Manager for UID 1000...
Jan 8 22:31:23 phoniebox systemd[3642]: Queued start job for default target Main User Target.
Jan 8 22:31:23 phoniebox systemd[3642]: Created slice User Application Slice.
Jan 8 22:31:23 phoniebox systemd[3642]: Reached target Paths.
Jan 8 22:31:23 phoniebox systemd[3642]: Reached target Timers.
Jan 8 22:31:23 phoniebox systemd[3642]: Listening on GnuPG network certificate management daemon.
Jan 8 22:31:23 phoniebox systemd[3642]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Jan 8 22:31:23 phoniebox systemd[3642]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Jan 8 22:31:23 phoniebox systemd[3642]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Jan 8 22:31:23 phoniebox systemd[3642]: Listening on GnuPG cryptographic agent and passphrase cache.
Jan 8 22:31:23 phoniebox systemd[3642]: Reached target Sockets.
Jan 8 22:31:23 phoniebox systemd[3642]: Reached target Basic System.
Jan 8 22:31:23 phoniebox systemd[1]: Started User Manager for UID 1000.
Jan 8 22:31:23 phoniebox systemd[3642]: Reached target Main User Target.
Jan 8 22:31:23 phoniebox systemd[3642]: Startup finished in 486ms.
Jan 8 22:31:23 phoniebox systemd[1]: Started Session 1 of user pi.Could you also post the result of top, amixer scontrols and the content of the file ./setting/Audio_iFace_Name to get a better picture of the possible problem?
Mannshoch
commented
9 months ago top
top - 20:09:35 up 4 min, 1 user, load average: 0.08, 0.18, 0.09
Tasks: 157 total, 1 running, 156 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.7 us, 1.8 sy, 0.0 ni, 97.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 909.6 total, 478.3 free, 128.1 used, 303.2 buff/cache
MiB Swap: 100.0 total, 100.0 free, 0.0 used. 716.9 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2420 pi 20 0 10000 2936 2420 R 0.7 0.3 0:00.10 top
98 root 0 -20 0 0 0 I 0.3 0.0 0:00.33 kworker/2:1H-kblockd
150 root 20 0 57180 21292 20232 S 0.3 2.3 0:01.47 systemd-journal
498 root 20 0 6692 3068 2756 S 0.3 0.3 0:01.41 cleanshutd
580 root 0 -20 0 0 0 I 0.3 0.0 0:00.16 kworker/u9:2-brcmf_wq/mmc1:0001:1
753 root 20 0 73412 14320 11964 S 0.3 1.5 0:00.31 nmbd
1 root 20 0 167044 10276 7288 S 0.0 1.1 0:04.47 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.03 kthreadd
3 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_gp
4 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_par_gp
5 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 slub_flushwq
6 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 netns
7 root 20 0 0 0 0 I 0.0 0.0 0:00.00 kworker/0:0-events
8 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 kworker/0:0H-mmc_complete
9 root 20 0 0 0 0 I 0.0 0.0 0:01.93 kworker/u8:0-events_unbound
10 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 mm_percpu_wq
11 root 20 0 0 0 0 I 0.0 0.0 0:00.00 rcu_tasks_kthread
12 root 20 0 0 0 0 I 0.0 0.0 0:00.00 rcu_tasks_rude_kthread
13 root 20 0 0 0 0 I 0.0 0.0 0:00.00 rcu_tasks_trace_kthread
14 root 20 0 0 0 0 S 0.0 0.0 0:00.04 ksoftirqd/0
15 root 20 0 0 0 0 I 0.0 0.0 0:00.41 rcu_preempt
16 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
17 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/0
18 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/1
19 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/1
20 root 20 0 0 0 0 S 0.0 0.0 0:00.03 ksoftirqd/1
21 root 20 0 0 0 0 I 0.0 0.0 0:00.00 kworker/1:0-cgroup_destroy
22 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 kworker/1:0H-mmc_complete
23 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/2
24 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/2
25 root 20 0 0 0 0 S 0.0 0.0 0:00.03 ksoftirqd/2
26 root 20 0 0 0 0 I 0.0 0.0 0:00.21 kworker/2:0-events_freezable_power_
27 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 kworker/2:0H-kblockd
28 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/3
29 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/3
30 root 20 0 0 0 0 S 0.0 0.0 0:00.02 ksoftirqd/3
31 root 20 0 0 0 0 I 0.0 0.0 0:00.00 kworker/3:0-rcu_gp
32 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 kworker/3:0H-events_highpri
33 root 20 0 0 0 0 S 0.0 0.0 0:00.01 kdevtmpfs
34 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 inet_frag_wq amixer scontrols
Simple mixer control 'PCM',0
./setting/Audio_iFace_Name contain Headphone
Mannshoch
commented
9 months ago Until now I did not remove the Beeper from the scanner. How does the play until remove work? shouldn't there be a beep all x seconds?
AlvinSchiller
commented
9 months ago amixer scontrols
Simple mixer control 'PCM',0
./setting/Audio_iFace_Namecontain Headphone
This is a misconfiguration. Can you update your settings and replace Headphone with PCM, then reboot and try again?
The relevant files are: /etc/mpd.conf /home/pi/RPi-Jukebox-RFID/settings/global.conf /home/pi/RPi-Jukebox-RFID/settings/Audio_iFace_Name /home/pi/PhonieboxInstall.conf
AlvinSchiller
commented
9 months ago Until now I did not remove the Beeper from the scanner. How does the play until remove work? shouldn't there be a beep all x seconds?
It looks like the neuftech usb reader does not support the "place" option. https://github.com/MiczFlor/RPi-Jukebox-RFID/issues/1498#issuecomment-912650061
There's a hack for this in the wiki: https://github.com/MiczFlor/RPi-Jukebox-RFID/wiki/Stop-on-removal-with-USB-RFID-Reader
But you are probably better of with another reader if the place option is mandatory for you. RC522 is working well
Mannshoch
commented
9 months ago Could I somhow thest this? I think it should work. because the auto shutdown not work if a nfc card is placed on the box.
Bug
What I did
I had to reinstall the RPi Jukebox and now the feature that a song is played as long as a card is placed on the raid reader and when removed the player stops doesn't work anymore. In my previous installed version it worked perfectly.
What happened
nothing special happened :-) Its just that when a card is left on the reader, the song starts every few seconds again if the second swipe option is set to restart playlist. if this is set to only system commands the song starts for a few second and then stops and nothing else happens. I can only play the entire song/playlist when using the play/pause buttons. The changing the settings to swiping starts the player then swiping starts the song as expected.
I expected this to happen
A song should play as long as a card is placed on the raid reader. upon removal it should stop playing.
Further information that might help
I am using the classic version on an raspberry pi 4 with the raid reader RC522.
Software
Base image and version
Raspberry Pi OS Lite (64 bit) Debian Bullseye port
Branch / Release
masterInstallscript
scripts/installscripts/buster-install-default.shHardware
RaspberryPi version
4
RFID Reader
RC522