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.3k stars 394 forks source link

🐛 | RC522 irq not working properly #2387

Open damaev opened 2 weeks ago

damaev commented 2 weeks ago

Version

3.5.3

Branch

"future3/main", "v2/main"

OS

Bullseye lite 32bit

Pi model

Zero 2w

Hardware

Mfrc522

What happened?

The Reader is reading just from time to time, so it sometimes takes a looong time to read a card. Sometimes its fast. I started having this issue after upgrading to a zero2 with some v3 Version half a year ago. Now i found the time to dig into it. Restarting with a plan v2 Version. Still haveing the issue.

What I tied: Checking the soldering -> unchanged Stopping almost all jobs -> unchanged Starting daemon by hand -> rst pin already in use -> change to unused -> issue persists Using my previous Version of phoniebox v2 from. 2 years ago -> issue persists trying v3 with bullseye instead of bookworm -> issue persists

During that time I got the feeling the irq is not working. Changing irq pin -> issue persists Reading irq pin by hand -> interrupts appear randomly -> changing mfrc522 board -> interrupts appear randomly -> issue persists Changing cables - issue persists

I got the feeling that for some reason, the irq is not working (maybe anymore) as planned by the designer of the underlying rc522.py library Using another library without irq -> uid is read at hand

Digging into the Reader component of phoniebox again, I commented out the line "self.waiting_for_tag()" Now I directly get the uid. -> ISSUE SOLVED

However, y am I the only one with this issue? Will it cause more trouble? Should an option "skip_irq" for rc522 readers be integrated.

Maybe someone has the time and hardware to dig into it.

Logs

No response

Configuration

No response

More info

issue solved but see above

s-martin commented 2 weeks ago

Can you post the log here?

damaev commented 2 weeks ago

the error.log is empty. the app.log1 showing the delay between reading a card beeing in place all the time:

20.06.2024 16:06:03 -   19:readerbase.py      - jb.rfid.522(read_00) - read_00Thread   - INFO     - Initializing reader 'MFRC522 via SPI' from '/home/pi/RPi-Jukebox-RFID/src/jukebox/components/rfid/hardware/rc522_spi/rc522_spi.py'
20.06.2024 16:06:03 -   20:readerbase.py      - jb.rfid.522(read_00) - read_00Thread   - DEBUG    - Reader object is <components.rfid.hardware.rc522_spi.rc522_spi.ReaderClass object at 0x61b31bf8> for reader config key 'read_00'
20.06.2024 16:06:03 -   78:rc522_spi.py       - jb.rfid.522(read_00) - read_00Thread   - INFO     - Using legacy_mode = 'False'
20.06.2024 16:06:06 -  695:plugs.py           - jb.plugin.call       - StartJingle     - DEBUG    - Calling: volume.ctrl.set_volume(args=[40], kwargs=None)
20.06.2024 16:06:12 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:06:14 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:07:02 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'b4c4cc0c-96e1-46b0-9dc6-4bcd36e66ce1', 'package': 'cards', 'plugin': 'list_cards', 'method': None, 'kwargs': {}}
20.06.2024 16:07:02 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: cards.list_cards(args=(), kwargs={})
20.06.2024 16:07:02 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {}, 'id': 'b4c4cc0c-96e1-46b0-9dc6-4bcd36e66ce1'}
20.06.2024 16:07:48 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:07:48 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:08:06 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:08:06 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:08:42 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:08:42 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:08:55 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:08:55 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:09:28 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:09:28 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:10:00 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:10:00 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:10:13 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:10:13 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:10:44 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:10:44 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:11:18 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:11:18 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:11:37 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:11:37 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:11:54 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:11:54 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:12:13 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:12:13 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:13:26 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:13:26 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:13:47 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:13:47 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:14:07 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:14:07 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:14:28 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:14:28 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:14:49 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:14:49 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:15:37 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:15:37 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:15:54 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '75cb3abe-6079-4fc4-85d9-1e9644016f24', 'package': 'cards', 'plugin': 'list_cards', 'method': None, 'kwargs': {}}
20.06.2024 16:15:54 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: cards.list_cards(args=(), kwargs={})
20.06.2024 16:15:54 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {}, 'id': '75cb3abe-6079-4fc4-85d9-1e9644016f24'}
20.06.2024 16:15:56 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:15:56 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:15:59 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '3d572116-124b-4c86-ba62-0d1d7c565bcc', 'package': 'cards', 'plugin': 'list_cards', 'method': None, 'kwargs': {}}
20.06.2024 16:15:59 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: cards.list_cards(args=(), kwargs={})
20.06.2024 16:15:59 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {}, 'id': '3d572116-124b-4c86-ba62-0d1d7c565bcc'}
20.06.2024 16:16:15 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:16:15 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:16:35 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:16:35 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:16:55 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:16:55 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:17:15 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:17:15 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:17:37 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:17:37 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:17:58 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:17:58 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:18:18 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:18:18 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:19:04 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:19:04 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:19:23 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:19:23 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:19:42 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:19:42 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:20:02 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 16:20:02 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 16:20:39 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 16:20:40 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 16:20:41 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 16:20:41 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'

and after the change

20.06.2024 20:47:31 -   41:daemon.py          - jb.daemon            - MainThread      - INFO     - Starting Jukebox Daemon (Version 3.5.3)
20.06.2024 20:47:32 -   44:daemon.py          - jb.daemon            - MainThread      - INFO     - Git state: 0ab75c1d [2024-04-17] hotfix pyzmq installation on bullseye (pin version <26) (#2345)  (HEAD -> future3/main, tag: v3.5.3, origin/future3/main) [v3.5.3-dirty]
20.06.2024 20:47:32 -  318:cfghandler.py      - jb.cfghandler        - MainThread      - INFO     - (jukebox) Loading yaml file '/home/pi/RPi-Jukebox-RFID/shared/settings/jukebox.yaml'
20.06.2024 20:47:32 -  230:cfghandler.py      - jb.cfghandler        - MainThread      - DEBUG    - (jukebox) Replacing current config data
20.06.2024 20:47:32 -   53:daemon.py          - jb.daemon            - MainThread      - INFO     - Welcome to Jukebox
20.06.2024 20:47:32 -   54:daemon.py          - jb.daemon            - MainThread      - INFO     - Time of start: Thu Jun 20 20:47:31 2024
20.06.2024 20:47:32 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.publishing' as 'publishing'
20.06.2024 20:47:32 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.publishing.republish' as 'publishing.republish' (<class 'function'>)
20.06.2024 20:47:32 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling publishing.initialize()
20.06.2024 20:47:32 -  225:server.py          - jb.pub.server        - MainThread      - DEBUG    - PublishServer initialized (Pyzmq version: 25.1.2; ZMQ version: 4.3.5; has draft API: True)
20.06.2024 20:47:32 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.volume' as 'volume'
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.toggle_output
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.get_outputs
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.publish_volume
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.publish_outputs
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.set_volume
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.get_volume
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.change_volume
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.get_mute
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.mute
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.set_output
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.set_soft_max_volume
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PulseVolumeControl.get_soft_max_volume
20.06.2024 20:47:33 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling volume.initialize()
20.06.2024 20:47:33 -  250:__init__.py        - jb.pulse             - PulseMon        - INFO     - Start Pulse Monitor Thread
20.06.2024 20:47:33 -  613:__init__.py        - jb.pulse             - MainThread      - INFO     - Ignoring secondary audio output configuration because it is missing or incomplete
20.06.2024 20:47:33 -  352:__init__.py        - jb.pulse             - MainThread      - DEBUG    - Configured audio sinks: [PaSink(alias='Built-in speakers', pulse_sink_name='auto_null', volume_limit=100)]
20.06.2024 20:47:33 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.jingle' as 'jingle'
20.06.2024 20:47:33 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.jingle.play' as 'jingle.play' (<class 'function'>)
20.06.2024 20:47:33 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.jingle.play_startup' as 'jingle.play_startup' (<class 'function'>)
20.06.2024 20:47:33 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.jingle.play_shutdown' as 'jingle.play_shutdown' (<class 'function'>)
20.06.2024 20:47:33 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling jingle.initialize()
20.06.2024 20:47:33 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.jingle.alsawave' as 'jingle.alsawave'
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging AlsaWave.play
20.06.2024 20:47:33 -  318:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Decorating class components.jingle.alsawave.AlsaWave for auto-assignment into package 'jingle.alsawave'
20.06.2024 20:47:33 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling jingle.alsawave.initialize()
20.06.2024 20:47:33 -  337:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Instantiating decorated class 'components.jingle.alsawave.AlsaWave' and register as 'jingle.alsawave.alsawave'
20.06.2024 20:47:33 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'components.jingle.alsawave.AlsaWave' as 'jingle.alsawave.alsawave'
20.06.2024 20:47:33 -   24:__init__.py        - jb.jingle            - MainThread      - DEBUG    - Register 'wav' in <class 'components.jingle.JingleFactory'>.
20.06.2024 20:47:33 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.jingle.jinglemp3' as 'jingle.jinglemp3'
20.06.2024 20:47:33 -  318:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Decorating class components.jingle.jinglemp3.JingleMp3Play for auto-assignment into package 'jingle.jinglemp3'
20.06.2024 20:47:33 -  344:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Auto-tagging all methods and functions of class 'components.jingle.jinglemp3.JingleMp3Play'
20.06.2024 20:47:33 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling jingle.jinglemp3.initialize()
20.06.2024 20:47:33 -  337:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Instantiating decorated class 'components.jingle.jinglemp3.JingleMp3Play' and register as 'jingle.jinglemp3.jinglemp3'
20.06.2024 20:47:33 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'components.jingle.jinglemp3.JingleMp3Play' as 'jingle.jinglemp3.jinglemp3'
20.06.2024 20:47:33 -   24:__init__.py        - jb.jingle            - MainThread      - DEBUG    - Register 'mp3' in <class 'components.jingle.JingleFactory'>.
20.06.2024 20:47:33 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.playermpd' as 'player'
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.start
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.cancel
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.toggle
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.trigger
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.is_alive
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.get_timeout
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.set_timeout
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.publish
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericTimerClass.get_state
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericMultiTimerClass.start
20.06.2024 20:47:33 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging GenericMultiTimerClass.get_state
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_player_type_and_version
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.update
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.update_wait
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.play
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.stop
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.pause
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.prev
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.next
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.seek
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.rewind
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.replay
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.toggle
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.replay_if_stopped
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.shuffle
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.repeat
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_current_song
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.map_filename_to_playlist_pos
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.remove
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.move
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.play_single
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.resume
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.play_card
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_single_coverart
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_album_coverart
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_folder_content
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.play_folder
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.play_album
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.queue_load
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.playerstatus
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.playlistinfo
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.list_all_dirs
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.list_albums
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.list_songs_by_artist_and_album
20.06.2024 20:47:34 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging PlayerMPD.get_song_by_url
20.06.2024 20:47:34 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling player.initialize()
20.06.2024 20:47:34 -  169:__init__.py        - jb.PlayerMPD         - MainThread      - INFO     - Connected to MPD Version: 0.22.4
20.06.2024 20:47:34 -  202:multitimer.py      - jb.multitimers       - MainThread      - DEBUG    - mpd.timer_status: State = {'enabled': False, 'wait_seconds_per_iteration': 0.25, 'type': 'GenericEndlessTimerClass'}
20.06.2024 20:47:34 -  202:multitimer.py      - jb.multitimers       - mpd.timer_status - DEBUG    - mpd.timer_status: State = {'enabled': True, 'wait_seconds_per_iteration': 0.25, 'type': 'GenericEndlessTimerClass'}
20.06.2024 20:47:34 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'components.playermpd.PlayerMPD' as 'player.ctrl'
20.06.2024 20:47:34 -   24:__init__.py        - jb.player            - MainThread      - DEBUG    - MPD music lib path = /home/pi/RPi-Jukebox-RFID/shared/audiofolders; from /home/pi/.config/mpd/mpd.conf
20.06.2024 20:47:34 -  751:__init__.py        - jb.PlayerMPD         - MainThread      - INFO     - Change user rights for /home/pi/RPi-Jukebox-RFID/shared/audiofolders
20.06.2024 20:47:34 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.rfid.cards' as 'cards'
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.list_cards' as 'cards.list_cards' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.delete_card' as 'cards.delete_card' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.register_card' as 'cards.register_card' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.register_card_custom' as 'cards.register_card_custom' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.load_card_database' as 'cards.load_card_database' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.rfid.cards.save_card_database' as 'cards.save_card_database' (<class 'function'>)
20.06.2024 20:47:34 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.rfid.reader' as 'rfid'
20.06.2024 20:47:34 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.timers' as 'timers'
20.06.2024 20:47:34 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.hostif.linux' as 'host'
20.06.2024 20:47:34 -   79:multitimer.py      - jb.multitimers       - mpd.timer_status - DEBUG    - Start timer 'mpd.timer_status in endless mode
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.shutdown' as 'host.shutdown' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.reboot' as 'host.reboot' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.jukebox_is_service' as 'host.jukebox_is_service' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.is_any_jukebox_service_active' as 'host.is_any_jukebox_service_active' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.restart_service' as 'host.restart_service' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.get_disk_usage' as 'host.get_disk_usage' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.get_cpu_temperature' as 'host.get_cpu_temperature' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.publish_cpu_temperature' as 'host.publish_cpu_temperature' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.get_ip_address' as 'host.get_ip_address' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.say_my_ip' as 'host.say_my_ip' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.wlan_disable_power_down' as 'host.wlan_disable_power_down' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.get_autohotspot_status' as 'host.get_autohotspot_status' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.stop_autohotspot' as 'host.stop_autohotspot' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.start_autohotspot' as 'host.start_autohotspot' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.hdmi_power_down' as 'host.hdmi_power_down' (<class 'function'>)
20.06.2024 20:47:34 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.hostif.linux.get_throttled' as 'host.get_throttled' (<class 'function'>)
20.06.2024 20:47:35 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling host.initialize()
20.06.2024 20:47:35 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling host.rpi_initialize()
20.06.2024 20:47:35 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.controls.bluetooth_audio_buttons' as 'bluetooth_audio_buttons'
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.controls.bluetooth_audio_buttons.activate' as 'bluetooth_audio_buttons.activate' (<class 'function'>)
20.06.2024 20:47:35 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling bluetooth_audio_buttons.initialize()
20.06.2024 20:47:35 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.gpio.gpioz.plugin' as 'gpio'
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.gpio.gpioz.plugin.on' as 'gpio.on' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.gpio.gpioz.plugin.off' as 'gpio.off' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.gpio.gpioz.plugin.set_value' as 'gpio.set_value' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.gpio.gpioz.plugin.flash' as 'gpio.flash' (<class 'function'>)
20.06.2024 20:47:35 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling gpio.initialize()
20.06.2024 20:47:35 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.synchronisation.rfidcards' as 'sync_rfidcards'
20.06.2024 20:47:35 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging SyncRfidcards.sync_change_on_rfid_scan
20.06.2024 20:47:35 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging SyncRfidcards.sync_all
20.06.2024 20:47:35 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging SyncRfidcards.sync_card_database
20.06.2024 20:47:35 -  459:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Tagging SyncRfidcards.sync_folder
20.06.2024 20:47:35 -  570:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load initializer: calling sync_rfidcards.initialize()
20.06.2024 20:47:35 -   78:__init__.py        - jb.sync_rfidcards    - MainThread      - INFO     - Sync RFID cards deactivated
20.06.2024 20:47:35 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'components.synchronisation.rfidcards.SyncRfidcards' as 'sync_rfidcards.ctrl'
20.06.2024 20:47:35 -  545:plugs.py           - jb.plugin            - MainThread      - INFO     - Loading plugin 'components.misc' as 'misc'
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.rpc_cmd_help' as 'misc.rpc_cmd_help' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_all_loaded_packages' as 'misc.get_all_loaded_packages' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_all_failed_packages' as 'misc.get_all_failed_packages' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_start_time' as 'misc.get_start_time' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_log_debug' as 'misc.get_log_debug' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_log_error' as 'misc.get_log_error' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_version' as 'misc.get_version' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.get_git_state' as 'misc.get_git_state' (<class 'function'>)
20.06.2024 20:47:35 -  278:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting function 'components.misc.empty_rpc_call' as 'misc.empty_rpc_call' (<class 'function'>)
20.06.2024 20:47:35 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling volume.finalize()
20.06.2024 20:47:35 -  455:__init__.py        - jb.pulse             - MainThread      - INFO     - Audio sink is now 'Built-in speakers' :: 'auto_null'
20.06.2024 20:47:35 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'components.volume.PulseVolumeControl' as 'volume.ctrl'
20.06.2024 20:47:35 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling jingle.finalize()
20.06.2024 20:47:35 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: jingle.play_startup(args=(), kwargs=None)
20.06.2024 20:47:35 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling cards.finalize()
20.06.2024 20:47:35 -  695:plugs.py           - jb.plugin.call       - StartJingle     - DEBUG    - Calling: volume.ctrl.get_volume(args=(), kwargs=None)
20.06.2024 20:47:35 -  318:cfghandler.py      - jb.cfghandler        - MainThread      - INFO     - (cards) Loading yaml file '../../shared/settings/cards.yaml'
20.06.2024 20:47:35 -  230:cfghandler.py      - jb.cfghandler        - MainThread      - DEBUG    - (cards) Replacing current config data
20.06.2024 20:47:35 -  695:plugs.py           - jb.plugin.call       - StartJingle     - DEBUG    - Calling: volume.ctrl.set_volume(args=[30], kwargs=None)
20.06.2024 20:47:35 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling rfid.finalize()
20.06.2024 20:47:35 -  318:cfghandler.py      - jb.cfghandler        - MainThread      - INFO     - (rfid) Loading yaml file '../../shared/settings/rfid.yaml'
20.06.2024 20:47:35 -  230:cfghandler.py      - jb.cfghandler        - MainThread      - DEBUG    - (rfid) Replacing current config data
20.06.2024 20:47:35 -  101:__init__.py        - jb.rfid(read_00)     - MainThread      - INFO     - For reader config key 'read_00': loading module 'rc522_spi'
20.06.2024 20:47:36 -  116:__init__.py        - jb.rfid(read_00)     - MainThread      - DEBUG    - Decoded removal action: player.ctrl.pause()
20.06.2024 20:47:36 -   42:__init__.py        - jb.jingle            - StartJingle     - DEBUG    - Auto: 'wav' from ../../resources/audio/startupsound.wav.
20.06.2024 20:47:36 -  139:__init__.py        - jb.rfid(read_00)     - read_00Thread   - DEBUG    - Start listening!
20.06.2024 20:47:36 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling timers.finalize()
20.06.2024 20:47:36 -   50:__init__.py        - jb.alsaif            - StartJingle     - DEBUG    - Playing wave file
20.06.2024 20:47:36 -  202:multitimer.py      - jb.multitimers       - MainThread      - DEBUG    - timers.timer_shutdown: State = {'enabled': False, 'remaining_seconds': 0, 'wait_seconds': 3600, 'type': 'GenericTimerClass'}
20.06.2024 20:47:36 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'jukebox.multitimer.GenericTimerClass' as 'timers.timer_shutdown'
20.06.2024 20:47:36 -  202:multitimer.py      - jb.multitimers       - MainThread      - DEBUG    - timers.timer_stop_player: State = {'enabled': False, 'remaining_seconds': 0, 'wait_seconds': 3600, 'type': 'GenericTimerClass'}
20.06.2024 20:47:36 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'jukebox.multitimer.GenericTimerClass' as 'timers.timer_stop_player'
20.06.2024 20:47:36 -  202:multitimer.py      - jb.multitimers       - MainThread      - DEBUG    - timers.timer_fade_volume: State = {'enabled': False, 'wait_seconds_per_iteration': 900, 'iterations': 1, 'type': 'GenericMultiTimerClass'}
20.06.2024 20:47:36 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'jukebox.multitimer.GenericMultiTimerClass' as 'timers.timer_fade_volume'
20.06.2024 20:47:36 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling host.finalize()
20.06.2024 20:47:36 -  202:multitimer.py      - jb.multitimers       - MainThread      - DEBUG    - host.timer.cputemp: State = {'enabled': False, 'wait_seconds_per_iteration': 10, 'type': 'GenericEndlessTimerClass'}
20.06.2024 20:47:36 -  290:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Enlisting an instance of class 'jukebox.multitimer.GenericEndlessTimerClass' as 'host.timer_temperature'
20.06.2024 20:47:36 -  202:multitimer.py      - jb.multitimers       - host.timer.cputemp - DEBUG    - host.timer.cputemp: State = {'enabled': True, 'wait_seconds_per_iteration': 10, 'type': 'GenericEndlessTimerClass'}
20.06.2024 20:47:36 -  620:plugs.py           - jb.plugin            - MainThread      - DEBUG    - Package load finalizer: calling gpio.finalize()
20.06.2024 20:47:36 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: misc.get_all_loaded_packages(args=(), kwargs=None)
20.06.2024 20:47:36 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: misc.get_all_failed_packages(args=(), kwargs=None)
20.06.2024 20:47:36 -  144:daemon.py          - jb.daemon            - MainThread      - INFO     - Loaded plugins: publishing, volume, jingle, jingle.alsawave, jingle.jinglemp3, player, cards, rfid, timers, host, bluetooth_audio_buttons, gpio, sync_rfidcards, misc
20.06.2024 20:47:36 -   64:server.py          - jb.rpc.server        - MainThread      - INFO     - Init RPC Server (Pyzmq version: 25.1.2; ZMQ version: 4.3.5; has draft API: True)
20.06.2024 20:47:36 -   72:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Connected to address 'inproc://JukeBoxRpcServer'
20.06.2024 20:47:36 -   78:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Connected to address 'tcp://*:5555'
20.06.2024 20:47:36 -   84:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Connected to address 'ws://*:5556'
20.06.2024 20:47:36 -   89:server.py          - jb.rpc.server        - MainThread      - INFO     - All socket connections initialized
20.06.2024 20:47:36 -  229:daemon.py          - jb.daemon            - MainThread      - INFO     - Start-up time: 3383.974 ms
20.06.2024 20:47:36 -  101:server.py          - jb.rpc.server        - MainThread      - INFO     - RPC Servers started
20.06.2024 20:47:36 -   79:multitimer.py      - jb.multitimers       - host.timer.cputemp - DEBUG    - Start timer 'host.timer.cputemp in endless mode
20.06.2024 20:47:36 -   19:readerbase.py      - jb.rfid.522(read_00) - read_00Thread   - INFO     - Initializing reader 'MFRC522 via SPI' from '/home/pi/RPi-Jukebox-RFID/src/jukebox/components/rfid/hardware/rc522_spi/rc522_spi.py'
20.06.2024 20:47:36 -   20:readerbase.py      - jb.rfid.522(read_00) - read_00Thread   - DEBUG    - Reader object is <components.rfid.hardware.rc522_spi.rc522_spi.ReaderClass object at 0x61b558c8> for reader config key 'read_00'
20.06.2024 20:47:36 -   78:rc522_spi.py       - jb.rfid.522(read_00) - read_00Thread   - INFO     - Using legacy_mode = 'False'
20.06.2024 20:47:38 -  695:plugs.py           - jb.plugin.call       - StartJingle     - DEBUG    - Calling: volume.ctrl.set_volume(args=[40], kwargs=None)
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 20:48:13 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 20:48:13 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '1a20104b-4c73-4427-ad23-321c57fc2900', 'package': 'volume', 'plugin': 'ctrl', 'method': 'get_volume', 'kwargs': {}}
20.06.2024 20:48:13 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: volume.ctrl.get_volume(args=(), kwargs={})
20.06.2024 20:48:13 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': 40, 'id': '1a20104b-4c73-4427-ad23-321c57fc2900'}
20.06.2024 20:48:13 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'fc45e6b5-b51b-443f-babe-5f72fc45bf89', 'package': 'volume', 'plugin': 'ctrl', 'method': 'get_soft_max_volume', 'kwargs': {}}
20.06.2024 20:48:13 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: volume.ctrl.get_soft_max_volume(args=(), kwargs={})
20.06.2024 20:48:13 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': 70, 'id': 'fc45e6b5-b51b-443f-babe-5f72fc45bf89'}
20.06.2024 20:48:15 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'e6a0a93d-d682-4b9e-9521-9a44be1ca2b9', 'package': 'cards', 'plugin': 'list_cards', 'method': None, 'kwargs': {}}
20.06.2024 20:48:15 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: cards.list_cards(args=(), kwargs={})
20.06.2024 20:48:15 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {}, 'id': 'e6a0a93d-d682-4b9e-9521-9a44be1ca2b9'}
20.06.2024 20:48:32 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614471002911'
20.06.2024 20:48:32 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614471002911'
20.06.2024 20:48:35 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 20:48:35 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 20:48:38 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614471002911'
20.06.2024 20:48:39 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614471002911'
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:51 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 20:50:52 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:52:12 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 20:58:06 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 20:58:09 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 21:01:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 21:02:04 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149613670231071'
20.06.2024 21:02:04 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149613670231071'
20.06.2024 21:02:10 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614469852193'
20.06.2024 21:02:10 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614469852193'
20.06.2024 21:02:13 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149613670231071'
20.06.2024 21:02:13 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149613670231071'
20.06.2024 21:02:15 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614471002911'
20.06.2024 21:02:15 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614471002911'
20.06.2024 21:02:19 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149613670231071'
20.06.2024 21:02:19 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149613670231071'
20.06.2024 21:02:22 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614216389153'
20.06.2024 21:02:22 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614216389153'
20.06.2024 21:02:24 -  175:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Received card id = '1149614469852193'
20.06.2024 21:02:24 -  224:__init__.py        - jb.rfid(read_00)     - read_00Thread   - INFO     - Unknown card: '1149614469852193'
20.06.2024 21:04:38 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:38 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:38 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:38 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:39 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:39 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:39 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:39 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:04:39 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'batt_status'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.plugins.loaded'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.started_at'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'core.version'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.temperature.cpu'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'host.timer.cputemp'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'playerstatus'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'rfid.card_id'
20.06.2024 21:06:02 -  260:server.py          - jb.pub.server        - PubServer       - INFO     - New subscription for topic b'volume.level'
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '9122ddf2-5eb3-4e7c-b42e-8e7dedb1c51c', 'package': 'host', 'plugin': 'get_disk_usage', 'method': None, 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: host.get_disk_usage(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {'total': 6983, 'used': 3024, 'free': 3643}, 'id': '9122ddf2-5eb3-4e7c-b42e-8e7dedb1c51c'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '4c0924ec-6fed-4241-94bc-3448ebd9f187', 'package': 'host', 'plugin': 'get_ip_address', 'method': None, 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: host.get_ip_address(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': '192.168.50.4', 'id': '4c0924ec-6fed-4241-94bc-3448ebd9f187'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'e34f9e9b-1d10-48d1-8b10-32097718a6a8', 'package': 'timers', 'plugin': 'timer_shutdown', 'method': 'get_state', 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: timers.timer_shutdown.get_state(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {'enabled': False, 'remaining_seconds': 0, 'wait_seconds': 3600, 'type': 'GenericTimerClass'}, 'id': 'e34f9e9b-1d10-48d1-8b10-32097718a6a8'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '995ecc52-194e-4012-957b-3d911cf256b4', 'package': 'timers', 'plugin': 'timer_stop_player', 'method': 'get_state', 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: timers.timer_stop_player.get_state(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {'enabled': False, 'remaining_seconds': 0, 'wait_seconds': 3600, 'type': 'GenericTimerClass'}, 'id': '995ecc52-194e-4012-957b-3d911cf256b4'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'fc99fab4-13cf-4264-a8e5-2066fc26edfe', 'package': 'timers', 'plugin': 'timer_fade_volume', 'method': 'get_state', 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: timers.timer_fade_volume.get_state(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {'enabled': False, 'wait_seconds_per_iteration': 900, 'iterations': 10, 'type': 'GenericMultiTimerClass'}, 'id': 'fc99fab4-13cf-4264-a8e5-2066fc26edfe'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': 'f8482325-1f4d-4496-ada2-e327eba244da', 'package': 'volume', 'plugin': 'ctrl', 'method': 'get_outputs', 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: volume.ctrl.get_outputs(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': {'active_alias': 'Built-in speakers', 'active_sink': 'auto_null', 'sink_list': [{'alias': 'Built-in speakers', 'pulse_sink_name': 'auto_null', 'volume_limit': 100}]}, 'id': 'f8482325-1f4d-4496-ada2-e327eba244da'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '814ef10c-e842-495c-9bed-137df21ae45b', 'package': 'volume', 'plugin': 'ctrl', 'method': 'get_soft_max_volume', 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: volume.ctrl.get_soft_max_volume(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': 70, 'id': '814ef10c-e842-495c-9bed-137df21ae45b'}
20.06.2024 21:06:06 -  111:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Request: {'id': '615a2d16-50d0-4d1e-92ca-f423511f5085', 'package': 'host', 'plugin': 'get_autohotspot_status', 'method': None, 'kwargs': {}}
20.06.2024 21:06:06 -  695:plugs.py           - jb.plugin.call       - MainThread      - DEBUG    - Calling: host.get_autohotspot_status(args=(), kwargs={})
20.06.2024 21:06:06 -  151:server.py          - jb.rpc.server        - MainThread      - DEBUG    - Sending response: {'result': 'not-installed', 'id': '615a2d16-50d0-4d1e-92ca-f423511f5085'}
20.06.2024 21:34:43 -  263:server.py          - jb.pub.server        - PubServer       - INFO     - Un-subscription received
s-martin commented 2 weeks ago

Just to understand your problem: It is working, but sometimes you have a huge delay between reading the card and the action triggered, correct?

could you also post your rfid.yaml and cards.yaml?

As I don’t have a rc522 reader, others may have more experience.

damaev commented 2 weeks ago

I use a fresh system Hence, Cards.yaml should be more or less plain. I edited the rfid.yaml after opening this issue to allow placing instead of swiping. Other than that it's like the setup-script configured it. So the issue used the autoconfig. As I already mentioned, I also tested a plain v2. Even more, I did almost all testing on the v2/main setup. Like disabling all phoniebox services and starting python daemon-rfid.pywhich clearly showed the unsteady delays. Therefore, I conclude, it's either is a problem related to the pi zero2; To my soldering, which I doublechecked (ut who knows); There was an update to the rc522 library or mfrc522-partnever really worked correctly (from my short digging into the documentation of the rc522, the purpose of the irq may not necessarily indicate a nearby card)

damaev commented 2 weeks ago

To clarify: The reading of an uid seems to work pretty fine, like in no time. However the irq-signal is not dropping. Hence, the script keeps waiting for a tag even though a tag is present

flesser commented 1 week ago

Can confirm, I have the same issue with a fresh install from master on a Raspberry 3B+ with RFID-RC522 connected to the default pins.

It hangs at self.device.wait_for_tag() ( https://github.com/MiczFlor/RPi-Jukebox-RFID/blob/master/scripts/Reader.py.experimental#L91 which gets copied to Reader.py be the setup script).

If I comment out that line, tag IDs get read.

damaev commented 1 week ago

Did it work correctly beforhand on the 3b+? I was Using a pi zero 1. So it was always Slowenien, but I wouldn't say that slow.

9month ago the rc522.py library was updated to include a timeout during wait_for_tag() especially for our project. https://github.com/ondryaso/pi-rc522/pull/70 Maybe this update is causing trouble now.

damaev commented 1 week ago

i addad a fix with an additional config param skip_irq, see above

flesser commented 1 week ago

Unfortunately with skip_irq (or commented out line) the "remove card to stop playing" does not work because reader.readCard() in https://github.com/damaev/RPi-Jukebox-RFID/blob/develop/scripts/daemon_rfid_reader.py#L88 now immediately returns even if there is no card, resulting in the alarm to be reset any read attempt, even if the cardid was None

s-martin commented 1 week ago

From my point of view the original problem is tracked in #2373 I suggest to close this issue.