search

hifiberry / hifiberry-os

Linux distribution optimized for audio playback
MIT License
1.01k stars 128 forks source link

Going from Bluetooth source to Radio, "Now Playing" ist not updating anymore #148

Closed tobiv closed 2 years ago

tobiv commented 4 years ago

Describe the bug If I start the Radio source after the Bluetooth source was active (Bluetooth icon and name of connected device is shown in Now Playing), the Now Playing panel does not update and stays on Bluetooth. The Stop button also does not stop Radio playback. Only after a reboot can I see the station, song title and cover art again. (I don't know about other sources as I don't have anything else connected yet.)

HiFiBerryOS version 20200908

HiFiBerry sound card DAC+ ADC Pro

To Reproduce Steps to reproduce the behavior:

  1. Select source 'Bluetooth'
  2. Pair a device and start playback – Now Playing shows Bluetooth
  3. Select source 'Radio', look for a station and start playback
  4. Now Playing is stuck on Bluetooth

Expected behavior After switching source, Now Playing should immediately update to new source.

Screenshots N/A

Browser

Additional context n/a

hifiberry commented 3 years ago

Can you try the latest 20201101 release?

tobiv commented 3 years ago

I have updatedto 20201101, still no change (stays on Bluetooth and last played title).

stutteringp0et commented 3 years ago

same issue - 20201101 version. Also going from Bluetooth to Music. Tomorrow I'll be connecting SPDIF input and I can offer that info as well.

stutteringp0et commented 3 years ago

The same issue exists going from optical to another input. I have to shut down the optical input to show something else in now playing.

hifiberry commented 3 years ago

Some patches have been integrated in 20201202 and 20201213. I don't see this problem here. Can you try the latest 20201213 release?

fiveminutespast11 commented 3 years ago

Hi Guys! The problem is still there. I have patched to level 20201213. If you connect via Bluetooth, the web front-end shows still the connection with the last song played (in case it isnt connected anymore). The problem is also that you can not connect via Bluetooth anymore. You have to reboot the device. The mentioned patch @hifiberry tackled the problem relating to switching between the sources. Please review. Happy New Year :-)

PS: If you need more info...pls let me know. Thanks!

fiveminutespast11 commented 3 years ago

Screenshot from 2021-01-09 12-40-34

fiveminutespast11 commented 3 years ago

It plays currently from LMS but not Bluetooth. The current status is not shown and Bluetooth is not working anymore (only in case of a reboot).

hifiberry commented 3 years ago

To better understand if this is a bug in the frontend or the backend, please run the following command when you see this happening again:

curl 127.0.0.1:81/api/player/status

This gives us an internal state table.

fiveminutespast11 commented 3 years ago

@hifiberry: Thanks. I tried immediately to reproduce but without success. I will reply as soon as possible!

RavanH commented 3 years ago

@hifiberry this is the player status output after I first started playing Renegades via MPD, then connected my phone via BT and started Monkey Man (which pushed out MPD info and correctly updated the player info to BT info) and then switched to Radio. This last source playing at the time of the status pull, was not visible in the live player info bar nor in the state table:

{"players": [{"name": "mpd", "state": "paused", "artist": "X Ambassadors", "title": "Renegades", "supported_commands": ["Next", "Previous", "Pause", "PlayPause", "Stop", "Play", "Seek", "Random", "RandomOff", "RepeatAll", "RepeatOff"]}, {"name": "spotify", "state": "stopped", "artist": null, "title": null, "supported_commands": ["Next", "Previous", "Pause", "PlayPause", "Play"]}, {"name": "ThinkPad_T420", "state": "stopped", "artist": null, "title": "", "supported_commands": ["stop", "pause", "next", "previous", "play", "seek"]}, {"name": "Mi_A2_Spotify", "state": "playing", "artist": "The Rolling Stones", "title": "Monkey Man", "supported_commands": ["stop", "pause", "next", "previous", "play", "seek"]}], "last_updated": "2021-01-20 13:03:28.815607"}

At this point, on the Sources list BT will show the loudspeaker icon. Switching off the BT source completely will not update the player bar/status info. Switching back to MPD source will not show in player either. The state table does not get updated anymore...

hifiberry commented 3 years ago

Interesting. My guess is that something crashed on the backend in this case. Check out output of

journalctl -u audiocontrol | grep -v GET

RavanH commented 3 years ago

I guess I have to connect to the hifiberry via terminal to get journalctl info. I tried ssh but connexion is refused. Any documentation on remote command line administration?

hifiberry commented 3 years ago

Just enabled it in settings under "Remote login".

RavanH commented 3 years ago

Just enabled it in settings under "Remote login".

Ah, if everything in life were that simple... ;)

# journalctl -u audiocontrol | grep -v GET
-- Logs begin at Sat 2020-09-12 14:16:33 CEST, end at Wed 2021-01-20 14:52:50 CET. --
-- No entries --
hifiberry commented 3 years ago

:(

fiveminutespast11 commented 3 years ago

Hi @hifiberry: The bug has occurred again. The output of curl 127.0.0.1:81/api/player/status is as follows:

{"players": [{"name": "mpd", "state": "stopped", "artist": null, "title": null, "supported_commands": ["Next", "Previous", "Pause", "PlayPause", "Stop", "Play", "Seek", "Random", "RandomOff", "RepeatAll", "RepeatOff"]}, {"name": "spotify", "state": "stopped", "artist": null, "title": null, "supported_commands": ["Next", "Previous", "Pause", "PlayPause", "Play"]}, {"name": "lms", "state": "stopped", "artist": "Type O Negative", "title": "Can't Lose You", "supported_commands": ["stop", "pause", "next", "previous", "play"]}, {"name": "Nyx", "state": "stopped", "artist": null, "title": null, "supported_commands": ["stop", "pause", "next", "previous", "play", "seek"]}, {"name": "Nyx_DS_audio", "state": "paused", "artist": "Almyrkvi", "title": "Vaporous Flame", "supported_commands": ["stop", "pause", "next", "previous", "play", "seek"]}], "last_updated": "2021-01-20 12:41:01.645308"}`

fiveminutespast11 commented 3 years ago

I have played several songs from Bandcamp. After a while it (Bluetooth) crashed. What happened in detail:

  1. I went to Bandcamp played an album
  2. I switched on Bandcamp to another album of that artist
  3. It crashed (I guess)
  4. I cant connect via Bluetooth anymore

If I connect and disconnect only, all is fine and it works (before the issue occurs). Only after playing some songs (pls look above) to issue occurs.

fiveminutespast11 commented 3 years ago

More info:

UNIT LOAD ACTIVE SUB JOB DESCRIPTION
a2dp-agent.service loaded active running Bluetooth A2DP agent
activate-data-partition.service loaded inactive dead Activate /data
alsa-restore.service loaded inactive dead Save/Restore Sound Card State
alsa-state.service loaded inactive dead Manage Sound Card State (restore and store)
alsaloop.service loaded inactive dead alsaloop
audiocontrol2.service loaded active running Audiocontrol2
● auditd.service not-found inactive dead auditd.service
avahi-daemon.service loaded active running Avahi mDNS/DNS-SD Stack
avahi-dnsconfd.service loaded active running Avahi DNS Configuration Daemon
beocreate2.service loaded active running Beocreate 2 Server
bluealsa-aplay.service loaded active running BlueALSA aplay
bluealsa.service loaded active running BlueALSA
● bluetooth.service loaded failed failed Bluetooth service
btuart.service loaded active running Bluetooth hardware initialisiation
configure-players.service loaded inactive dead Reconfigure players
containers.service loaded inactive dead Start containers
datacollector.service loaded active running Usage data collector
dbus.service loaded active running D-Bus System Message Bus
dlnampris.service loaded inactive dead DLNA MPRIS
docker.service loaded active running Docker Application Container Engine
● dsptoolkit.service not-found inactive dead dsptoolkit.service
e2scrub_all.service loaded inactive dead Online ext4 Metadata Check for All Filesystems
e2scrub_reap.service loaded inactive dead Remove Stale Online ext4 Metadata Check Snapshots
emergency.service loaded inactive dead Emergency Shell
● firewalld.service not-found inactive dead firewalld.service
fix-ntp.service loaded inactive dead Disable DNSSEC for ntp.org
fstrim.service loaded inactive dead Discard unused blocks on filesystems from /etc/fstab
getty@tty1.service loaded active running Getty on tty1
hifiberry-detect.service loaded inactive dead HiFiBerry detect
hifiberry-finish.service loaded inactive dead HiFiBerry final
● initial-volume.service not-found inactive dead initial-volume.service
kmod-static-nodes.service loaded active exited Create list of static device nodes for the current kernel lmsmpris.service loaded active running LMS MPRIS
mount-data.service loaded active exited Mount /data
● mpd-mpris.service not-found inactive dead mpd-mpris.service
mpd-update-notifier.service loaded active running mpd update notifier
mpd.service loaded active running mpd
mpris-proxy.service loaded active running Bluetooth MPRIS proxy
myip.service loaded inactive dead MyIP - say local IP
ntpd.service loaded active running Network Time Service
pigpio.service loaded active running PiGPIOd
● plymouth-quit-wait.service not-found inactive dead plymouth-quit-wait.service
● plymouth-start.service not-found inactive dead plymouth-start.service
psplash-quit.service loaded inactive dead Terminate Psplash Boot Screen
psplash-start.service loaded inactive dead Starts Psplash Boot screen
pushdata.service loaded inactive dead Push usage data to cloud
raat.service loaded inactive dead Roon

fiveminutespast11 commented 3 years ago

If I try to connect....the output of...

btmon --write ~/hcitrace.snoop | tee hcitrace.txt

Bluetooth monitor ver 5.55 = Note: Linux version 5.4.77-v7l (armv7l) 0.816263 = Note: Bluetooth subsystem version 2.22 0.816277 = New Index: DC:A6:32:BD:1E:88 (Primary,UART,hci0) [hci0] 0.816283 = Open Index: DC:A6:32:BD:1E:88 [hci0] 0.816289 = Index Info: DC:A6:32:BD:1E:88 (Cypress Semiconductor) [hci0] 0.816295

HCI Event: Connect Request (0x04) plen 10 #1 [hci0] 16.115402 Address: 50:BC:96:93:68:04 (OUI 50-BC-96) Class: 0x7a020c Major class: Phone (cellular, cordless, payphone, modem) Minor class: Smart phone Networking (LAN, Ad hoc) Capturing (Scanner, Microphone) Object Transfer (v-Inbox, v-Folder) Audio (Speaker, Microphone, Headset) Telephony (Cordless telephony, Modem, Headset) Link type: ACL (0x01) < HCI Command: Accept Connection Re.. (0x01|0x0009) plen 7 #2 [hci0] 16.115486 Address: 50:BC:96:93:68:04 (OUI 50-BC-96) Role: Slave (0x01) HCI Event: Command Status (0x0f) plen 4 #3 [hci0] 16.115951 Accept Connection Request (0x01|0x0009) ncmd 1 Status: Success (0x00) HCI Event: Connect Complete (0x03) plen 11 #4 [hci0] 16.129020 Status: Success (0x00) Handle: 11 Address: 50:BC:96:93:68:04 (OUI 50-BC-96) Link type: ACL (0x01) Encryption: Disabled (0x00) < HCI Command: Read Remote Supporte.. (0x01|0x001b) plen 2 #5 [hci0] 16.129236 Handle: 11 HCI Event: Command Status (0x0f) plen 4 #6 [hci0] 16.129702 Read Remote Supported Features (0x01|0x001b) ncmd 1 Status: Success (0x00) HCI Event: Read Remote Supported Features (0x0b) plen 11 #7 [hci0] 16.129847 Status: Success (0x00) Handle: 11 Features: 0xbf 0xfe 0xcf 0xfe 0xdb 0xff 0x7b 0x87 3 slot packets 5 slot packets Encryption Slot offset Timing accuracy Role switch Sniff mode Power control requests Channel quality driven data rate (CQDDR) SCO link HV2 packets HV3 packets u-law log synchronous data A-law log synchronous data CVSD synchronous data Paging parameter negotiation Power control Transparent synchronous data Flow control lag (most significant bit) Broadcast Encryption Enhanced Data Rate ACL 2 Mbps mode Enhanced Data Rate ACL 3 Mbps mode Enhanced inquiry scan Interlaced inquiry scan Interlaced page scan RSSI with inquiry results Extended SCO link (EV3 packets) EV4 packets EV5 packets AFH capable slave AFH classification slave LE Supported (Controller) 3-slot Enhanced Data Rate ACL packets 5-slot Enhanced Data Rate ACL packets Sniff subrating Pause encryption AFH capable master AFH classification master Enhanced Data Rate eSCO 2 Mbps mode Enhanced Data Rate eSCO 3 Mbps mode 3-slot Enhanced Data Rate eSCO packets Extended Inquiry Response Simultaneous LE and BR/EDR (Controller) Secure Simple Pairing Encapsulated PDU Erroneous Data Reporting Non-flushable Packet Boundary Flag Link Supervision Timeout Changed Event Inquiry TX Power Level Enhanced Power Control Extended features < HCI Command: Read Remote Extended.. (0x01|0x001c) plen 3 #8 [hci0] 16.129905 Handle: 11 Page: 1 HCI Event: Command Status (0x0f) plen 4 #9 [hci0] 16.130244 Read Remote Extended Features (0x01|0x001c) ncmd 1 Status: Success (0x00) HCI Event: Read Remote Extended Features (0x23) plen 13 #10 [hci0] 16.130345 Status: Success (0x00) Handle: 11 Page: 1/2 Features: 0x0f 0x00 0x00 0x00 0x00 0x00 0x00 0x00 Secure Simple Pairing (Host Support) LE Supported (Host) Simultaneous LE and BR/EDR (Host) Secure Connections (Host Support) < HCI Command: Remote Name Request (0x01|0x0019) plen 10 #11 [hci0] 16.130439 Address: 50:BC:96:93:68:04 (OUI 50-BC-96) Page scan repetition mode: R2 (0x02) Page scan mode: Mandatory (0x00) Clock offset: 0x0000 < ACL Data TX: Handle 11 flags 0x00 dlen 10 #12 [hci0] 16.130469 L2CAP: Information Request (0x0a) ident 1 len 2 Type: Extended features supported (0x0002) HCI Event: Command Status (0x0f) plen 4 #13 [hci0] 16.131019 Remote Name Request (0x01|0x0019) ncmd 1 Status: Success (0x00) HCI Event: Max Slots Change (0x1b) plen 3 #14 [hci0] 16.132685 Handle: 11 Max slots: 5 ACL Data RX: Handle 11 flags 0x02 dlen 10 #15 [hci0] 16.140911 L2CAP: Information Request (0x0a) ident 19 len 2 Type: Extended features supported (0x0002) < ACL Data TX: Handle 11 flags 0x00 dlen 16 #16 [hci0] 16.140980 L2CAP: Information Response (0x0b) ident 19 len 8 Type: Extended features supported (0x0002) Result: Success (0x0000) Features: 0x000002b8 Enhanced Retransmission Mode Streaming Mode FCS Option Fixed Channels Unicast Connectionless Data Reception ACL Data RX: Handle 11 flags 0x02 dlen 16 #17 [hci0] 16.143883 L2CAP: Information Response (0x0b) ident 1 len 8 Type: Extended features supported (0x0002) Result: Success (0x0000) Features: 0x000002a8 Enhanced Retransmission Mode FCS Option Fixed Channels Unicast Connectionless Data Reception < ACL Data TX: Handle 11 flags 0x00 dlen 10 #18 [hci0] 16.143942 L2CAP: Information Request (0x0a) ident 2 len 2 Type: Fixed channels supported (0x0003) HCI Event: Remote Name Req Complete (0x07) plen 255 #19 [hci0] 16.146275 Status: Success (0x00) Address: 50:BC:96:93:68:04 (OUI 50-BC-96) Name: Nyx HCI Event: Number of Completed Packets (0x13) plen 5 #20 [hci0] 16.146287 Num handles: 1 Handle: 11 Count: 2 ACL Data RX: Handle 11 flags 0x02 dlen 10 #21 [hci0] 16.146400 L2CAP: Information Request (0x0a) ident 20 len 2 Type: Fixed channels supported (0x0003) < ACL Data TX: Handle 11 flags 0x00 dlen 20 #22 [hci0] 16.146471 L2CAP: Information Response (0x0b) ident 20 len 12 Type: Fixed channels supported (0x0003) Result: Success (0x0000) Channels: 0x0000000000000086 L2CAP Signaling (BR/EDR) Connectionless reception Security Manager (BR/EDR) ACL Data RX: Handle 11 flags 0x02 dlen 20 #23 [hci0] 16.147654 L2CAP: Information Response (0x0b) ident 2 len 12 Type: Fixed channels supported (0x0003) Result: Success (0x0000) Channels: 0x04010c00000000f6 L2CAP Signaling (BR/EDR) Connectionless reception Attribute Protocol L2CAP Signaling (LE) Security Manager (LE) Security Manager (BR/EDR) Unknown channels (0x4010c0000000000) HCI Event: Number of Completed Packets (0x13) plen 5 #24 [hci0] 16.150253 Num handles: 1 Handle: 11 Count: 2 ACL Data RX: Handle 11 flags 0x02 dlen 12 #25 [hci0] 16.152638 L2CAP: Connection Request (0x02) ident 21 len 4 PSM: 1 (0x0001) Source CID: 2312 < ACL Data TX: Handle 11 flags 0x00 dlen 16 #26 [hci0] 16.152695 L2CAP: Connection Response (0x03) ident 21 len 8 Destination CID: 0 Source CID: 2312 Result: Connection refused - PSM not supported (0x0002) Status: No further information available#

fiveminutespast11 commented 3 years ago

Jan 31 19:43:24 erato bluetoothd[353]: profiles/audio/avctp.c:auth_cb() Access denied: Connection rejected Jan 31 19:43:26 erato kernel: input: Nyx (AVRCP) as /devices/virtual/input/input8 Jan 31 19:43:37 erato bluetoothd[353]: /org/bluez/hci0/dev_50_BC_96_93_68_04/fd7: fd(39) ready Jan 31 19:43:37 erato bluealsa[272]: /usr/bin/bluealsa: W: Activating RTP mark bit quirk workaround Jan 31 19:43:37 erato /bin/cat[29604]: 20210131-194337 20210131-194337 pause-all bluetooth Jan 31 19:43:37 erato beocreate2[729]: Volume received from AudioControl: 100 %. Jan 31 19:44:07 erato beocreate2[729]: Checking MPD database update status... Jan 31 19:44:44 erato systemd[1]: Starting Store volume... Jan 31 19:44:44 erato store-volume[29611]: Storing ALSA volume... Jan 31 19:44:44 erato systemd[1]: store-volume.service: Succeeded. Jan 31 19:44:44 erato systemd[1]: Finished Store volume. Jan 31 19:45:09 erato beocreate2[729]: Checking MPD database update status... Jan 31 19:46:01 erato mpris-proxy[10164]: dbus[10164]: arguments to dbus_connection_get_object_path_data() were incorrect, assertion "connection != NULL" failed in file dbus-conn Jan 31 19:46:01 erato mpris-proxy[10164]: This is normally a bug in some application using the D-Bus library. Jan 31 19:46:01 erato mpris-proxy[10164]: D-Bus not built with -rdynamic so unable to print a backtrace Jan 31 19:46:01 erato audit[10164]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 pid=10164 comm="mpris-proxy" exe="/usr/bin/mpris-proxy" sig=6 res=1 Jan 31 19:46:01 erato systemd[1]: mpris-proxy.service: Main process exited, code=killed, status=6/ABRT Jan 31 19:46:01 erato systemd[1]: mpris-proxy.service: Failed with result 'signal'. Jan 31 19:46:01 erato bluetoothd[353]: Player unregistered: sender=:1.49 path=/_1_25 Jan 31 19:46:01 erato kernel: audit: type=1701 audit(1612118761.512:42): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=10164 comm="mpris-proxy" exe="/usr/bin/mpris-proxy" sig=6 Jan 31 19:46:01 erato systemd[1]: Starting Store volume... Jan 31 19:46:01 erato systemd[1]: store-volume.service: Succeeded. Jan 31 19:46:01 erato systemd[1]: Finished Store volume. Jan 31 19:46:06 erato systemd[1]: mpris-proxy.service: Scheduled restart job, restart counter is at 2. Jan 31 19:46:06 erato systemd[1]: Stopped Bluetooth MPRIS proxy. Jan 31 19:46:06 erato systemd[1]: Starting Bluetooth MPRIS proxy... Jan 31 19:46:06 erato systemd[1]: Started Bluetooth MPRIS proxy. Jan 31 19:46:06 erato bluetoothd[353]: Player registered: sender=:1.71 path=/_1_25

Jan 31 19:46:06 erato systemd[1]: mpris-proxy.service: Scheduled restart job, restart counter is at 2. Jan 31 19:46:06 erato systemd[1]: Stopped Bluetooth MPRIS proxy. Jan 31 19:46:06 erato systemd[1]: Starting Bluetooth MPRIS proxy... Jan 31 19:46:06 erato systemd[1]: Started Bluetooth MPRIS proxy. Jan 31 19:46:06 erato bluetoothd[353]: Player registered: sender=:1.71 path=/_1_25 Jan 31 19:46:11 erato beocreate2[729]: Checking MPD database update status... Jan 31 19:46:12 erato bluealsa[272]: /usr/bin/bluealsa: W: Activating RTP mark bit quirk workaround Jan 31 19:46:12 erato /bin/cat[29653]: 20210131-194612 20210131-194612 pause-all bluetooth Jan 31 19:46:16 erato audit[353]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 pid=353 comm="bluetoothd" exe="/usr/libexec/bluetooth/bluetoothd" sig=11 res=1 Jan 31 19:46:16 erato kernel: audit: type=1701 audit(1612118776.802:43): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=353 comm="bluetoothd" exe="/usr/libexec/bluetooth/bluetoot Jan 31 19:46:16 erato systemd[1]: bluetooth.service: Main process exited, code=killed, status=11/SEGV Jan 31 19:46:16 erato systemd[1]: bluetooth.service: Failed with result 'signal'. Jan 31 19:47:13 erato beocreate2[729]: Checking MPD database update status...

fiveminutespast11 commented 3 years ago

systemctl status bluetooth

● bluetooth.service - Bluetooth service Loaded: loaded (/usr/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled) Active: failed (Result: signal) since Sun 2021-01-31 19:46:16 CET; 1h 58min ago Docs: man:bluetoothd(8) Process: 353 ExecStart=/usr/libexec/bluetooth/bluetoothd (code=killed, signal=SEGV) Main PID: 353 (code=killed, signal=SEGV) Status: "Running"

Jan 31 19:43:24 erato bluetoothd[353]: profiles/audio/avctp.c:auth_cb() Access denied: Connection rejected Jan 31 19:43:37 erato bluetoothd[353]: /org/bluez/hci0/dev_50_BC_96_93_68_04/fd7: fd(39) ready Jan 31 19:46:01 erato bluetoothd[353]: Player unregistered: sender=:1.49 path=/_1_25 Jan 31 19:46:06 erato bluetoothd[353]: Player registered: sender=:1.71 path=/_1_25 Jan 31 19:46:16 erato systemd[1]: bluetooth.service: Main process exited, code=killed, status=11/SEGV Jan 31 19:46:16 erato systemd[1]: bluetooth.service: Failed with result 'signal'. Warning: journal has been rotated since unit was started, output may be incomplete.

bglnelissen commented 3 years ago

I have the same issue. To replicate:

  1. Play a song via airplay
  2. Play a song via bluetooth
  3. Play a song via airplay

Result: the ‘/api/player/status’ keeps displaying the last song played over bluetooth.

I’ll keep watching this thread.

hifiberry commented 2 years ago

Is this still a problem in the latest release? The bug report is quite old.

RavanH commented 2 years ago

Hi, I've tried reproducing the steps in version 20220826. It looks like the issue does not occur anymore. Not when following the steps described in the original report at least :)

hifiberry commented 2 years ago

Thank you for the feedback.

RavanH commented 2 years ago

Excellent work! Thank you for maintaining Hifiberry :)