[Bug]: Jukebox control does not work about navidrome HOT 35 OPEN

@cyberfarer, yes I ran it manually in a command window. I found the error in the logs, extracted the command and ran it in a command window, receiving an error. When I added the quotes it worked.

@deluan , thank you for the explanation!

from navidrome.

I also got the above errors.
Looking at the code, shouldn't

from navidrome.

Yeah this just looks like needing to quote the filename in the cmd string when Navidrome calls out to mpv

I don't know what is the issue, but I'm pretty sure that is not the case. This is just how array of strings are displayed in the logs. I an assure you that the filename is only one argument and is not split by spaces. This is the same way it works for ffmpeg for both importing and transcoding.

The quotes in @cyberfarer command is for bash/zsh to consider the filename one argument, but it is not necessary when calling it out with Go's exec.Command

I just checked my Linux test instance and I am able to play songs with spaces in the path without issues. See the log:

DEBU[0054] Executing mpv command        cmd="[/usr/bin/mpv --audio-device=auto --no-audio-display --pause music/My latin way/VOODOOCUTS - My latin way - 01 Mi amor.mp3 --input-ipc-server=/tmp/mpv-ctrl-9078e11172ab0d743d3bc20fd3cf33c4.socket]"

from navidrome.

@mpdevivo

I found my way here after posting about my jukebox trouble on Reddit ( https://www.reddit.com/r/navidrome/comments/1ar4sc8/error_with_jukebox_mode_and_music_files_with/ )

For me, the quotes seem to have fixed the error when calling MPV to play a file.

If you need to call mpv (or any other command for that matter) from the command line, so then yes, you need to put quotes around filepaths with spaces. But that's NOT the case, as Navidrome is NOT using the shell to execute the command. The fact that you see the command in the logs without quotes does NOT means the filepath is split when calling mpv. This is just the way Navidrome logs array of strings, and the fact that it looks like a valid command line, it is not meant to be.

So no, that's not the issue. And you can see in my previous comment that I am able to play files with spaces on a Linux machine without this issue. What we have here is something else.

But that's not your fault, the log format is really misleading. Maybe a better way to represent the command to be executed is something like this:

Executing mpv command cmd="['/usr/bin/mpv','--audio-device=alsa/sysdefault:CARD=sndrpihifiberry', '--no-audio-display', '--pause', '/media/volumio/MP3/Various/00s Miscellaneous/01 Tubthumper.mp3', '--input-ipc-server=/tmp/mpv-ctrl-7dcd7ec4fc01af918a1752c863c73709.socket']"

This is the actual command being launched by Navidrome. I'll probably change the logs to this format above to stop the confusion.

Do you mean by manually running the command or did
you amend the code?

@cyberfarer there's nothing to amend in the code regarding quotes, this is not the issue.

@thulard Thanks for the detailed analysis. Hopefully @ms140569 will be able to get back to this sooner than later.

from navidrome.

Confirming the same issue. I have updated the default Ubuntu 0.32.0-1ubuntu1 to 0.36.0+fruit~ubuntu2004 without any change.

from navidrome.

Same issue here on a raspberry pi 3b+ running OSMC
The command starting MPV works when typed manually in the terminal but fails when initated by navidrome with the error : "got the mpv error: property unavailable error, retry ..."

Navidrome is installed from the official binary and run as a systemd service. I thought it could be related to that but I get the same error if I start Navidrome manually.

from navidrome.

I cannot reproduce this error here with DSub. For Ultrasonic, there is another issue that prevents it to work properly with Navidrome: https://gitlab.com/ultrasonic/ultrasonic/-/issues/1266

I'll release a new version in the next couple of days, with the change mentioned in the Ultrasonic's issue, but not sure if this will have any effect on this issue here.

If you don't want to wait for the release and want to test right away, you can use the latest development build: https://nightly.link/navidrome/navidrome/workflows/pipeline/master

from navidrome.

Tried with the latest nightly and I still get the same error using DSub and Ultrasonic.

from navidrome.

Tried with DSUB and get the same error. Is it possibly restricted to Ubuntu?

from navidrome.

thanks @deluan for looking into this! Unfortunately this hasn't solved the issue for me (neither with Ultrasonic nor DSub).
Server version: [0.50.1-SNAPSHOT] (2b33ef72)
Output from journalctl -f -u navidrome.service |grep level=error upon pressing "Play" on Ultrasonic with Jukebox function 'on':

Jan 21 20:54:23 myservice navidrome[2315877]: time="2024-01-21T20:54:23+01:00" level=error msg="Could not set the position in track" error="mpv error: property unavailable" offset=4 track="Name: file.mp3, Socket: /tmp/mpv-ctrl-78a46eb2fb2b3094e09ce01b380a6ab0.socket"
Jan 21 20:54:23 myservice navidrome[2315877]: time="2024-01-21T20:54:23+01:00" level=error msg="error setting position" error="mpv error: property unavailable" requestId=myservice/19pB3ypxxD-001499 username=username
Jan 21 20:54:23 egon navidrome[2315877]: time="2024-01-21T20:54:23+01:00" level=error msg="Error sending quit command to mpv-ipc socket" error="trying to send command on closed mpv client"
[multiple identical messages]
Jan 21 20:54:25 egon navidrome[2315877]: time="2024-01-21T20:54:25+01:00" level=error msg="Problem getting paused status" error="trying to send command on closed mpv client" track="Name: file.mp3, Socket: /tmp/mpv-ctrl-b08c6e5b0946f2e44035c3b9b47cd6d9.socket"
Jan 21 20:54:25 egon navidrome[2315877]: time="2024-01-21T20:54:25+01:00" level=error msg="Error sending quit command to mpv-ipc socket" error="trying to send command on closed mpv client"
[multiple identical messages]

With DSub:

Jan 21 20:49:56 myservice navidrome[2315877]: time="2024-01-21T20:49:56+01:00" level=error msg="Error sending quit command to mpv-ipc socket" error="trying to send command on closed mpv client"
[multiple identical messages]
Jan 21 20:50:00 myservice navidrome[2315877]: time="2024-01-21T20:50:00+01:00" level=error msg="Problem getting paused status" error="trying to send command on closed mpv client" track="Name: file.mp3, Socket: /tmp/mpv-ctrl-9aea46747499e3dd3619df4ec41f3ec0.socket"
Jan 21 20:50:00 myservice navidrome[2315877]: time="2024-01-21T20:50:00+01:00" level=error msg="Error sending quit command to mpv-ipc socket" error="trying to send command on closed mpv client"
[multiple identical messages]

Please let me know if you need further info. I'm also open to using another Jukebox-compatible client if it works :-)

from navidrome.

I have to admit I don't understand the whole of the Jukebox code, and I don't use it myself, but maybe @ms140569 can chime in?

from navidrome.

@julienlag which version of mpv is running on your box?
I'm on my way to FOSDEM but will look into this once I'm back.

from navidrome.

here, @ms140569 :

mpv --version
mpv 0.34.1 Copyright © 2000-2021 mpv/MPlayer/mplayer2 projects
 built on UNKNOWN
FFmpeg library versions:
   libavutil       56.70.100
   libavcodec      58.134.100
   libavformat     58.76.100
   libswscale      5.9.100
   libavfilter     7.110.100
   libswresample   3.9.100
FFmpeg version: 4.4.2-0ubuntu0.22.04.1

from navidrome.

@ms140569 upgraded mpv to version 0.37.0, the problem unfortunately remains... :-(

from navidrome.

from navidrome.

from navidrome.

Yeah this just looks like needing to quote the filename in the cmd string when Navidrome calls out to mpv

from navidrome.

Yeah this just looks like needing to quote the filename in the cmd string when Navidrome calls out to mpv

This may be correct. When I run the command manually with quotations around the string it does work. I will give it a try. Although, honestly, at this time I use bluetooth and it all works quite nicely.

from navidrome.

I found my way here after posting about my jukebox trouble on Reddit ( https://www.reddit.com/r/navidrome/comments/1ar4sc8/error_with_jukebox_mode_and_music_files_with/ )

For me, the quotes seem to have fixed the error when calling MPV to play a file.

from navidrome.

from navidrome.

I also got the above errors. Looking at the code, shouldn't

navidrome/core/playback/mpv/track.go

Line 156 in 61257f8

break

be a continue instead of break? Maybe add some (exponential) back off / pause until the next IPC request as well?

I'm also running navidrome 0.51.0 with mpv 0.32.0 on a Raspberry Pi 4 Model B Rev 1.5 and I'm getting the same errors
I tried to follow the log and code, I arrived to the same conclusion.

Executing the mpv command doesn't raise any error and the track is then unpause.

Looking at the Start function, on device.go, the function is calling getStatus()

getStatus() call the pd.ActiveTrack.Position() function.

Position() on track.go is the one returning the "mpv error: property unavailable" but never retry due to the break.

From the player point of view (DSub), the song never progress and stay at 0:00.
Hope this feedback is helpful

from navidrome.

I experience the same issue with playing files; trying to cast internet radio via DSub gives me a different error:

Feb 21 17:19:33 raspberrypi navidrome[11380]: time="2024-02-21T17:19:33Z" level=error msg="internal error: current song index out of bounds" idx=0 length=0

Streaming internet radio with mpg123 works just fine.

from navidrome.

@ms140569 Have you had the time to look at this?

from navidrome.

I experience the same issue with playing files; trying to cast internet radio via DSub gives me a different error:

Feb 21 17:19:33 raspberrypi navidrome[11380]: time="2024-02-21T17:19:33Z" level=error msg="internal error: current song index out of bounds" idx=0 length=0

Streaming internet radio with mpg123 works just fine.

Can confirm the problem with radios, I have only aac and flac streams and none of them work.
Latest MPV.
Normal, local jukebox mode [via DSUB] is also wonky, you have to pause/unpause to get it to play.
Ultrasonic seems to behave better when Jukebox is set as default in config.

from navidrome.

I was also hitting "Hitting end-of-stream, signalling on channel" on Linux (Raspbian 11) with navidrome 0.52.0 (92a98cd) and mpv 0.37, using iSub as the client.

When starting navidrome from the command-line, jukebox worked fine:

	cd /var/lib/navidrome; /opt/navidrome/navidrome --configfile "/var/lib/navidrome/navidrome.toml"

...so I figured it was due to extra security options in the systemd unit. I commented out those and it works now as a service as well:

# DevicePolicy=closed
# NoNewPrivileges=yes
# PrivateTmp=yes
# PrivateUsers=yes
# ProtectControlGroups=yes
# ProtectKernelModules=yes
# ProtectKernelTunables=yes
# RestrictAddressFamilies=AF_UNIX AF_INET AF_INET6
# RestrictNamespaces=yes
# RestrictRealtime=yes
# SystemCallFilter=~@clock @debug @module @mount @obsolete @reboot @setuid @swap
# ReadWritePaths=/var/lib/navidrome
# ...
# ProtectSystem=full

Didn't have the time to debug this further; I ran under with User=nickolay, Group=nickolay, MusicFolder="/home/nickolay/Music. (I didn't have success with play:Sub even after iSub started working, anyone else got it working?)

The failing logs were:

level=debug msg="Executing mpv command" cmd="[/usr/bin/mpv --audio-device=auto --no-audio-display --pause /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3 --input-ipc-server=/tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket]"
level=debug msg="Socket found" retries=2 waitTime=201ms
level=debug msg="Setting position" offset=0 track="Name: /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3, Socket: /tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket"
level=debug msg="Got mpv error, retrying..." error="mpv error: property unavailable" retries=1
level=debug msg="No position difference, skipping operation" track="Name: /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3, Socket: /tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket"
level=info msg="Hitting end-of-stream, signalling on channel"
level=error msg="Error getting position in track" error="trying to send command on closed mpv client" track="Name: /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3, Socket: /tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket"
level=debug msg="Checking if track is playing" track="Name: /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3, Socket: /tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket"
level=error msg="Problem getting paused status" error="trying to send command on closed mpv client" track="Name: /home/nickolay/Music/children-songs/xxx-xxxxxxx-xxxxx.mp3, Socket: /tmp/mpv-ctrl-ed38f1d6-3810-48dd-bb10-b35897ece8a1.socket"
level=debug msg="API: Successful response" endpoint=/rest/jukeboxControl.view requestId=argon/yBUWuPtrnN-000013 status=OK

from navidrome.

from navidrome.

@julienlag Have you added your user to the "audio" group? Here's my service file which works on rpi4:

`[Unit]
Description=Navidrome Music Server and Streamer compatible with Subsonic/Airsonic
After=remote-fs.target network.target
AssertPathExists=/var/lib/navidrome

[Install]
WantedBy=multi-user.target

[Service]
User=schmidtm
Group=schmidtm
Type=simple
ExecStart=/home/schmidtm/prj/navidrome/fork/navidrome/navidrome --configfile "/var/lib/navidrome/navidrome.toml"
WorkingDirectory=/var/lib/navidrome
Restart=on-failure`

from navidrome.

from navidrome.

@julienlag Have you added your user to the "audio" group? Here's my service file which works on rpi4:

`[Unit] Description=Navidrome Music Server and Streamer compatible with Subsonic/Airsonic After=remote-fs.target network.target AssertPathExists=/var/lib/navidrome

[Install] WantedBy=multi-user.target

[Service] User=schmidtm Group=schmidtm Type=simple ExecStart=/home/schmidtm/prj/navidrome/fork/navidrome/navidrome --configfile "/var/lib/navidrome/navidrome.toml" WorkingDirectory=/var/lib/navidrome Restart=on-failure`

thanks, but none of this worked for me

from navidrome.

@cyberfarer @julienlag

Are you both trying to play static files? I'm loosing the overview which one is facing which problem. We might deal with multiple problems. I know this is already going on for some time, but could you guys please paste the relevant/last part of the logfile showing the error? Bear with me, Matthias.

from navidrome.

@cyberfarer @julienlag

Are you both trying to play static files? I'm loosing the overview which one is facing which problem. We might deal with multiple problems. I know this is already going on for some time, but could you guys please paste the relevant/last part of the logfile showing the error? Bear with me, Matthias.

thanks @ms140569 for looking into this. You're right, this thread is getting difficult to follow
In summary: I'm the original issue poster, you can find my report above. Since the original report I have upgraded MPV to v.0.38.0 and navidrome to v0.52.5, tried all suggestions made by others in this thread, without success (i.e. I'm seeing the same MPV-related error messages in the log as originally reported). Happy to provide more details

from navidrome.

from navidrome.

@julienlag I've a hard time to reproduce your issue. I'm using Ultrasonic as well against various versions of ND on a Rpi4.

Do I get this right: You always get the error-sequence given in the Bug-description above on the first attempt to play any file in Jukebox-Mode?

So, you always get this message:

"got the mpv error: property unavailable error, retry ..."

correct?

from navidrome.

@julienlag I've a hard time to reproduce your issue. I'm using Ultrasonic as well against various versions of ND on a Rpi4.

Do I get this right: You always get the error-sequence given in the Bug-description above on the first attempt to play any file in Jukebox-Mode?

So, you always get this message:

"got the mpv error: property unavailable error, retry ..."

correct?

Yes, exactly!

from navidrome.

@julienlag I've a hard time to reproduce your issue. I'm using Ultrasonic as well against various versions of ND on a Rpi4.
Do I get this right: You always get the error-sequence given in the Bug-description above on the first attempt to play any file in Jukebox-Mode?
So, you always get this message:
"got the mpv error: property unavailable error, retry ..."
correct?

Yes, exactly!

I can confirm the same behaviour on a rpi3b+

from navidrome.