search

MusicPlayerDaemon / MPD

Music Player Daemon
https://www.musicpd.org/
GNU General Public License v2.0
2.19k stars 350 forks source link

Play DSD on Raspbian issue #796

Open starmood opened 4 years ago

starmood commented 4 years ago

Bug report

Describe the bug

If enable FIFO output, when start playing DSD file there will be some 'click' noise for standard Alsa output during first 5 or 10 seconds, sometimes the sound will break for like 0.1 second. If disable FIFO output, then no such issue. I also tried with older version, like 0.21.16, there is no such problem. My test platform is Raspbian Buster 2019-09-26.

Expected Behavior

Actual Behavior

Version

Music Player Daemon 0.22~git (v0.21.20-870-g61b5ab266+) Copyright 2003-2007 Warren Dukes warren.dukes@gmail.com Copyright 2008-2018 Max Kellermann max.kellermann@gmail.com This is free software; see the source for copying conditions. There is NO warranty; not even MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Database plugins: simple proxy upnp

Storage plugins: local curl

Neighbor plugins: upnp

Decoders plugins: [mad] mp3 mp2 [mpg123] mp3 [vorbis] ogg oga [oggflac] ogg oga [flac] flac [opus] opus ogg oga [sndfile] wav aiff aif au snd paf iff svx sf voc w64 pvf xi htk caf sd2 [audiofile] wav au aiff aif [dsdiff] dff [dsf] dsf [hybrid_dsd] m4a [faad] aac [mpcdec] mpc [wavpack] wv [modplug] 669 amf ams dbm dfm dsm far it med mdl mod mtm mt2 okt s3m stm ult umx xm [mikmod] amf dsm far gdm imf it med mod mtm s3m stm stx ult uni xm [sidplay] sid mus str prg P00 [wildmidi] mid [fluidsynth] mid [adplug] amd d00 hsc laa rad raw sa2 [ffmpeg] 16sv 3g2 3gp 4xm 8svx aa3 aac ac3 adx afc aif aifc aiff al alaw amr anim apc ape asf atrac au aud avi avm2 avs bap bfi c93 cak cin cmv cpk daud dct divx dts dv dvd dxa eac3 film flac flc fli fll flx flv g726 gsm gxf iss m1v m2v m2t m2ts m4a m4b m4v mad mj2 mjpeg mjpg mka mkv mlp mm mmf mov mp+ mp1 mp2 mp3 mp4 mpc mpeg mpg mpga mpp mpu mve mvi mxf nc nsv nut nuv oga ogm ogv ogx oma ogg omg opus psp pva qcp qt r3d ra ram rl2 rm rmvb roq rpl rvc shn smk snd sol son spx str swf tak tgi tgq tgv thp ts tsp tta xa xvid uv uv2 vb vid vob voc vp6 vmd wav webm wma wmv wsaud wsvga wv wve [gme] ay gbs gym hes kss nsf nsfe sap spc vgm vgz [pcm]

Filters: libsamplerate soxr

Tag plugins: id3tag

Output plugins: shout null fifo sndio pipe alsa openal httpd recorder

Encoder plugins: null vorbis opus lame twolame wave flac shine

Archive plugins: [bz2] bz2 [zzip] zip [iso] iso

Input plugins: file archive alsa tidal qobuz curl ffmpeg mms cdio_paranoia

Playlist plugins: extm3u m3u pls xspf asx rss soundcloud flac cue embcue

Protocols: file:// alsa:// cdda:// ftp:// ftps:// gopher:// http:// https:// mms:// mmsh:// mmst:// mmsu:// qobuz:// rtmp:// rtmps:// rtmpt:// rtmpts:// rtp:// scp:// sftp:// smb:// srtp:// tidal://

Other features: avahi dbus epoll icu inotify systemd tcp un

Log

MaxKellermann commented 4 years ago

Configuration and verbose log missing.

starmood commented 4 years ago

conf file

music_directory "/opt/mpd/var/lib/mpd/music" playlist_directory "/opt/mpd/var/lib/mpd/playlists" db_file "/opt/mpd/var/lib/mpd/mpd.db" log_file "/opt/mpd/var/lib/mpd/mpd.log" pid_file "/opt/mpd/var/run/mpd/pid" state_file "/opt/mpd/var/lib/mpd/mpdstate" sticker_file "/opt/mpd/var/lib/mpd/sticker.sql" user "mpd" group "audio" auto_update "no" restore_paused "yes" bind_to_address "any" port "6600" log_level "default" follow_outside_symlinks "yes" follow_inside_symlinks "yes" volume_normalization "no" audio_buffer_size "4096" buffer_before_play "10%" gapless_mp3_playback "yes" id3v1_encoding "UTF-8" filesystem_charset "UTF-8"

input { plugin "curl" }

audio_output { type "alsa" name "ALSA default" device "hw:0,0" mixer_type "hardware" mixer_control "Digital" mixer_device "hw:0" mixer_index "0" dop "yes" }

audio_output { type "fifo" name "FIFO default" path "/opt/run/mpd_oled_fifo" format "44100:16:2" }

Log

Mar 19 22:40 : avahi: Initializing interface Mar 19 22:40 : exception: RTIOThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted Mar 19 22:40 : avahi: Client changed to state 2 Mar 19 22:40 : avahi: Client is RUNNING Mar 19 22:40 : avahi: Registering service _mpd._tcp/Music Player @ raspberrypi Mar 19 22:40 : avahi: Service group changed to state 0 Mar 19 22:40 : avahi: Service group is UNCOMMITED Mar 19 22:40 : state_file: Loading state file /opt/mpd/var/lib/mpd/mpdstate Mar 19 22:40 : playlist: queue song 1:"USB/CAE4-5CA7/Scott Hamilton - Ballads for Audiophiles SACD/02 All or Nothing at All.dsf" Mar 19 22:40 : decoder_thread: probing plugin dsf Mar 19 22:40 : decoder: audio_format=dsd64:2, seekable=true Mar 19 22:40 : exception: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted Mar 19 22:40 : avahi: Service group changed to state 1 Mar 19 22:40 : avahi: Service group is REGISTERING Mar 19 22:40 : client: [0] opened from 127.0.0.1:60008 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : avahi: Service group changed to state 2 Mar 19 22:40 : avahi: Service 'Music Player @ raspberrypi' successfully established. Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [1] opened from 127.0.0.1:60012 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "playlistid" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "1"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "play "1"" Mar 19 22:40 : playlist: play 1:"USB/CAE4-5CA7/Scott Hamilton - Ballads for Audiophiles SACD/02 All or Nothing at All.dsf" Mar 19 22:40 : decoder_thread: probing plugin dsf Mar 19 22:40 : decoder: audio_format=dsd64:2, seekable=true Mar 19 22:40 : alsa_output: opened hw:0,0 type=HW Mar 19 22:40 : alsa_output: buffer: size=64..65536 time=362..371520 Mar 19 22:40 : alsa_output: period: size=32..32768 time=181..185760 Mar 19 22:40 : alsa_output: default period_time = buffer_time/4 = 371519/4 = 92879 Mar 19 22:40 : alsa_output: format=S32_LE (Signed 32 bit Little Endian) Mar 19 22:40 : alsa_output: buffer_size=65536 period_size=16384 Mar 19 22:40 : alsa_output: DoP (DSD over PCM) enabled Mar 19 22:40 : output: opened "ALSA default" (alsa) audio_format=dsd64:2 Mar 19 22:40 : exception: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted Mar 19 22:40 : output: opened "FIFO default" (fifo) audio_format=44100:16:2 Mar 19 22:40 : libsamplerate: setting samplerate conversion ratio to 0.12 Mar 19 22:40 : output: converting in=dsd64:2 -> f=dsd64:2 -> out=44100:16:2 Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : playlist: queue song 2:"USB/CAE4-5CA7/Scott Hamilton - Ballads for Audiophiles SACD/03 The Gypsy.dsf" Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "playlistid" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : state_file: Saving state file /opt/mpd/var/lib/mpd/mpdstate Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : alsa_output: Underrun on ALSA device "hw:0,0" Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "playlistid" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "pause "1"" Mar 19 22:40 : output: closed "FIFO default" (fifo) Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : output: closed "ALSA default" (alsa) Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "status" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "currentsong" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "ping" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [1] process command "playlistid" Mar 19 22:40 : client: [1] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [2] opened from 127.0.0.1:60016 Mar 19 22:40 : client: [2] process command "outputs" Mar 19 22:40 : client: [2] command returned 0 Mar 19 22:40 : client: [2] process command "currentsong" Mar 19 22:40 : client: [2] command returned 0 Mar 19 22:40 : client: [2] process command "status" Mar 19 22:40 : client: [2] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "status" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "currentsong" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [0] process command "playlistinfo "2"" Mar 19 22:40 : client: [0] command returned 0 Mar 19 22:40 : client: [2] process command "currentsong" Mar 19 22:40 : client: [2] command returned 0 Mar 19 22:40 : client: [2] process command "status" Mar 19 22:40 : client: [2] command returned 0 Mar 19 22:40 : state_file: Saving state file /opt/mpd/var/lib/mpd/mpdstate Mar 19 22:40 : client: [0] process command "status"

MaxKellermann commented 4 years ago

Is your CPU overloaded? If other processes take away CPU time from MPD, it could be useful to fix the real-time scheduling problems first. See the warnings in your log?

starmood commented 4 years ago

CPU is not overloaed. FIFO thread keeps ~ 20%.

I will take a look at RT error tomorrow. But actually if I switch to 0.21.16, same RT scheduling error is also in the log, but there is no DSD playing issue.

starmood commented 4 years ago

I used systemd to start the mpd, now RT scheduling error is gone. But the problem is still same.