Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

vollibrespot panics on album play #519

Closed
blynnumass opened this issue Feb 29, 2024 · 9 comments
Closed

vollibrespot panics on album play #519

blynnumass opened this issue Feb 29, 2024 · 9 comments
Labels
bug help wanted

Comments

@blynnumass
Copy link

DO NOT remove the blocks below, but fill these with the requested data. Incomplete bug reports will be ignored!
You should remove this comment before posting the bug report.

Describe the bug
Vollibrespot panics on certain album playlists. The panics are consistent and easily reproducible.

HiFiBerryOS version
20230404

HiFiBerry sound card
DAC2 HD in a Pi4

To Reproduce
This occurs with various albums. One example:

  1. Go to the album "Loss of Life" by MGMT in the Spotify app.
  2. Select the HiFiBerry as the output device.
  3. Click on the play button for the album.
  4. The first song will play but the second song will not. This is because vollibrespot will have panicked.

Expected behavior
Expected behavior is for the entire album to play (and no panic).

Screenshots
Here is the journal entry. Note the "failed to fill whole buffer" error.

Feb 28 19:02:04 hifiberry systemd[1]: fstrim.service: Deactivated successfully.
Feb 28 19:02:04 hifiberry systemd[1]: Finished Discard unused blocks on filesystems from /etc/fstab.
Feb 28 19:02:08 hifiberry vollibrespot[754]: thread '' panicked at 'Vorbis error: OggError(ReadError(Error { kind: UnexpectedEof, message: "failed to fill whole buffer" }))', /home/matuschd/buildroot-
Feb 28 19:02:08 hifiberry vollibrespot[754]: stack backtrace:
Feb 28 19:02:08 hifiberry vollibrespot[754]: 0: 0xa37b38 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 1: 0xa5eff0 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 2: 0xa304d8 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 3: 0xa3a138 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 4: 0xa39b20 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 5: 0xa3a824 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 6: 0xa3a2fc -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 7: 0xa380f0 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 8: 0xa3a244 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 9: 0x5228bc -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 10: 0x522990 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 11: 0x63f464 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 12: 0x56888c -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 13: 0x56a2b8 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 14: 0x5722f0 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 15: 0x58080c -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 16: 0x566a58 -
Feb 28 19:02:08 hifiberry vollibrespot[754]: 17: 0xa3f9fc -
Feb 28 19:02:20 hifiberry node[785]: Checking MPD database update status...
Feb 28 19:02:31 hifiberry sshd[1016]: Connection closed by 192.168.0.60 port 50614 [preauth]
Feb 28 19:02:36 hifiberry ntpd[389]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized

Browser (if applicable)
I'm using the latest version of Spotify for macOS, but it panics regardless of whether I start it from there, an iPhone, etc.

Additional context
I have the gapless setting enabled. I tried burning a new image on a separate SD card and had the same error.
@hifiberry
Copy link
Owner

Unfortunately there isn't really anything we can do here. The best option is probably to change the Spotify player. However, this will need some major development effort. As we don't have any Rust Knowhow I can't say if and how this can be improved.

@hifiberry
Copy link
Owner

Just tested here and it plays fine.

Try setting username and password in /etc/volllibrespot.conf

@blynnumass
Copy link
Author

I do use a username and password. Unfortunately, it has no effect for me.

@pdenooijer
Copy link

Skipping the first number in the playlist somehow fixes the problem for me. Seems to me I have the same error as @blynnumass. I set the username and password in /etc/vollibrespot.conf, as otherwise Spotify Connect does not work at all. Tried to play around with the settings as well, so far no success.

Describe the bug
Vollibrespot panics on all album playlists for me so far. The panics are consistent and easily reproducible.

HiFiBerryOS version
20240319

HiFiBerry sound card
Digi2 Pro on Raspberry Pi 4 Model B Rev 1.4

journalctl

Checking MPD database update status...
Mar 20 17:42:46 hifiberry systemd[1]: Starting Store volume...
Mar 20 17:42:46 hifiberry systemd[1]: store-volume.service: Deactivated successfully.
Mar 20 17:42:46 hifiberry systemd[1]: Finished Store volume.
Mar 20 17:42:49 hifiberry vollibrespot[19301]: [Vollibrespot] : couldn't parse packet from [IP_address]:5353: type 47 is invalid
Mar 20 17:42:52 hifiberry vollibrespot[19301]: [Vollibrespot] : Loading <song> with Spotify URI <spotify:track:hash>
Mar 20 17:42:52 hifiberry vollibrespot[19301]: [Vollibrespot] : <song> (152543 ms) loaded
Mar 20 17:43:22 hifiberry vollibrespot[19301]: thread '<unnamed>' panicked at /home/matuschd/buildroot-4/host/share/cargo/git/checkouts/librespot-e4d7c35a023053af/1a224a3/playback/src/player.rs:771:56:
Mar 20 17:43:22 hifiberry vollibrespot[19301]: Vorbis error: OggError(ReadError(Error { kind: UnexpectedEof, message: "failed to fill whole buffer" }))
Mar 20 17:43:22 hifiberry vollibrespot[19301]: stack backtrace:
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    0:       0x55879fa674 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    1:       0x5587a230fc - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    2:       0x55879f6cd8 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    3:       0x55879fa4a8 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    4:       0x55879fbaac - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    5:       0x55879fb7c0 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    6:       0x55879fc068 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    7:       0x55879fbf30 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    8:       0x55879fab58 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:    9:       0x55879fbc88 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   10:       0x55875932f8 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   11:       0x5587593650 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   12:       0x5587673e08 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   13:       0x55875be8d0 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   14:       0x55875bd4f8 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   15:       0x55875e030c - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   16:       0x55875c8034 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   17:       0x5587a0046c - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   18:       0x7fad818e00 - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   19:       0x7fad87e80c - <unknown>
Mar 20 17:43:22 hifiberry vollibrespot[19301]:   20:                0x0 - <unknown>
Mar 20 17:43:28 hifiberry node[737]: Checking MPD database update status...
Mar 20 17:43:49 hifiberry vollibrespot[19301]: [Vollibrespot] : couldn't parse packet from [IP_address]:5353: type 47 is invalid

@hifiberry what player would be a alternative?

Work around
In my situation it seems to work to start the first song and then skip to the second song. After that 'trick' it seems to play as expected, logging output seems to be different then.

journalctl

Mar 20 18:38:14 hifiberry node[737]: Checking MPD database update status...
Mar 20 18:38:40 hifiberry vollibrespot[20181]: [Vollibrespot] : Event: Next { track_id: SpotifyId { id: [id], audio_type: Track } }
Mar 20 18:38:40 hifiberry vollibrespot[20181]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: [id], audio_type: Track }, track_id: SpotifyId { id: [id], audio_type: Track } }
Mar 20 18:38:40 hifiberry python3[517]: ERROR: vollibrespot - {'album_id': '[id]', 'album_name': '[name]', 'albumartId': ['id', 'id', 'id'], 'artist_id': ['id'], 'artist_name': 
Mar 20 18:38:41 hifiberry python3[517]: INFO: http_post - posted metadata update to http://127.0.0.1:80/sources/metadata ({[metadata]
Mar 20 18:38:41 hifiberry python3[517]: INFO: mbxml - in <ws2:release-group>, uncaught attribute type-id
Mar 20 18:38:41 hifiberry python3[517]: INFO: musicbrainz - found data for <artist> on musicbrainz
Mar 20 18:38:42 hifiberry python3[517]: INFO: mbxml - in <ws2:recording>, uncaught <first-release-date>
Mar 20 18:38:42 hifiberry python3[517]: INFO: mbxml - in <ws2:release-group>, uncaught attribute type-id
Mar 20 18:38:42 hifiberry python3[517]: INFO: musicbrainz - found data for <song> on musicbrainz
Mar 20 18:38:45 hifiberry python3[517]: INFO: http_post - posted metadata update to http://127.0.0.1:80/sources/metadata ({[metadata]
Mar 20 18:38:49 hifiberry vollibrespot[20181]: [Vollibrespot] : couldn't parse packet from [IP_address]:5353: type 47 is invalid
Mar 20 18:39:05 hifiberry systemd[1]: Starting Store volume...
Mar 20 18:39:05 hifiberry systemd[1]: store-volume.service: Deactivated successfully.
Mar 20 18:39:05 hifiberry systemd[1]: Finished Store volume.

@EpicLPer
Copy link

EpicLPer commented Apr 3, 2024

I think this issue is related to the problem I've been having for a few weeks/months now. I initially thought it was due to me using HiFiBerryOS Alpha, cause it started exactly at the time I used it, but I switched back to stable HiFiBerryOS today and it's still happening no matter what playlist I'm playing.

For me the journalctl output looks very similar to the one people above me posted:

Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', /home/matuschd/buildroot-3/host/share/cargo/git/checkouts/librespot-e4d7c35a023053af/1a224a3/playback/src/player.rs:232:61
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]: stack backtrace:
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    0:   0x9d7b20 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    1:   0x9fefd8 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    2:   0x9d04c0 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    3:   0x9da120 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    4:   0x9d9b08 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    5:   0x9da80c - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    6:   0x9da2e4 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    7:   0x9d80d8 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    8:   0x9da22c - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:    9:   0x4c28bc - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   10:   0x4c2990 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   11:   0x5da23c - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   12:   0x5a8d60 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   13:   0x5a6ab4 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   14:   0x4e5db0 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   15:   0x508250 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   16:   0x50aaf8 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   17:   0x4f76bc - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   18:   0x50a818 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   19:   0x532014 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   20:   0x4fcce8 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   21:   0x4e85e8 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   22:   0x520b18 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   23:   0x520ce4 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   24:   0x9dacfc - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   25:   0x4e9d28 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   26: 0x76ca46e0 - <unknown>
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]:   27: 0x76ca47e4 - __libc_start_main
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]: [Vollibrespot] : Player thread panicked!
Apr 03 15:10:36 hifiberry-stefan-zimmer vollibrespot[1707]: [Vollibrespot] : EventSender disconnected
Apr 03 15:10:36 hifiberry-stefan-zimmer systemd[1]: spotify.service: Main process exited, code=exited, status=101/n/a
Apr 03 15:10:36 hifiberry-stefan-zimmer systemd[1]: spotify.service: Failed with result 'exit-code'.
Apr 03 15:10:36 hifiberry-stefan-zimmer python3[369]: INFO: powercontroller - Update LED state for state=paused
Apr 03 15:10:36 hifiberry-stefan-zimmer python3[369]: ERROR: powercontroller - Could not write to power controller: 121
Apr 03 15:10:36 hifiberry-stefan-zimmer node[747]: Source 'spotify' has deactivated.
Apr 03 15:10:36 hifiberry-stefan-zimmer python3[369]: INFO: http_post - posted metadata update to http://127.0.0.1:80/sources/metadata ({'artist': 'Da Tweekaz', 'title': 'Sunrise', 'albumArtist': None, 'albumTitle': 'Sunrise', 'artUrl': 'https://i.scdn.co/image/ab67616d0000b273cdab17d23a96e5a0d08d2f37', 'externalArtUrl': None, 'discNumber': None, 'tracknumber': None, 'playerName': 'spotify', 'playerState': 'paused', 'streamUrl': None, 'playCount': None, 'mbid': None, 'artistmbid': None, 'albummbid': None, 'loved': None, 'wiki': None, 'loveSupported': False, 'tags': [], 'skipped': False, 'host_uuid': None, 'releaseDate': None, 'trackid': None, 'hifiberry_cover_found': False, 'duration': 0, 'time': 0, 'position': 0, 'positionupdate': 1712148474.585062})
Apr 03 15:10:37 hifiberry-stefan-zimmer sshd[2160]: kex_exchange_identification: Connection closed by remote host
Apr 03 15:10:37 hifiberry-stefan-zimmer sshd[2160]: Connection closed by XXXXXX port 55987
Apr 03 15:10:41 hifiberry-stefan-zimmer node[747]: Checking MPD database update status...
Apr 03 15:10:41 hifiberry-stefan-zimmer systemd[1]: spotify.service: Scheduled restart job, restart counter is at 3.
Apr 03 15:10:41 hifiberry-stefan-zimmer systemd[1]: Stopped Vollibrespot.

@EpicLPer EpicLPer mentioned this issue Apr 3, 2024
Open
@hifiberry
Copy link
Owner

With the next release of HiFiBerryOS64, we'll offering a Spotifyd extension as an alternative. You might try if this works better for you. HBOS64 Alpha 7 will be available soon.

@hifiberry
Copy link
Owner

https://github.com/hifiberry/hifiberry-os/releases/tag/64alpha7

@EpicLPer
Copy link

https://github.com/hifiberry/hifiberry-os/releases/tag/64alpha7

Thanks for the update!
Is there any way to upgrade existing Alpha installations or do I have to install it from scratch?

@hifiberry
Copy link
Owner

No, right now there is no upgrade for alpha versions. I hope this will be available again with the next alpha

@JCBird1012 JCBird1012 mentioned this issue Jun 24, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug help wanted
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@blynnumass @pdenooijer @hifiberry @EpicLPer