PeteManchester / MediaPlayer

61 stars 20 forks source link

On a RasPI it works fine with "Buster" OS but not with the "Bullseye" #100

Closed mightyoakbob closed 4 months ago

mightyoakbob commented 2 years ago

Title says it all. I can build a complete system using the mediaplayer from September 24th that you made for me or use the later one from October 20th. Both work fully including with Lumin provided it is built on the Buster OS. Unfortunately the OS has now moved on to Bullseye and I tried again and again but it just doesn't work for me.

I use the dac+ from HiFi-berry bolted on to the pi. Under Bullseye, the green led on the dac that normally comes on when you play music is lit continuously. The device does appear in the control points but you cannot send music to the player.

May I ask why the last 3 beta versions don't become the "latest" replacement?

Thank you.

Bob.

PeteManchester commented 2 years ago

Hi Bob,

If the device appears on the Control points then it's possible the MediaPlayer is working but the app you have chosen (mpd or mplayer) cannot play the track.

Can you set the mediaplayer log level to debug and then capture a log file when you attempt to play a track.

Another option would be to strip back your install so that it uses the aux out to play the track rather than your DAC.

Thanks,

Pete

mightyoakbob commented 2 years ago

Hi Pete, Before upping the log level I decided to take a look at what was in there first. I found that everything goes fatal (and I do mean everything) the moment it tries to execute app.properties. See below.

mpd is installed and not mplayer. The builds I have done over the last few days trying to break this down are all identical, all use mpd and they work fine with Buster but not with bullseye. I've even tried building both OS builds with java 8 and java 11 but it makes no difference in either case buster works with either bullseye doesn't.

I suppose to be strictly accurate, Kazoo does send the track or at least it shows as the current track in Kazoo but it is stopped at the start and cannot be started.

Although it isn't a dac+ problem as it works fine on Buster, how would I go about changing the setting to stop it using the dac+ ? Reversing the changes made to /boot/config.txt presumably or is there something else ?

Friendly Name : Linn_Pi Version : 0.0.1.2 Host name : LinnPi StartTime : Mon Jan 24 14:23:24 GMT 2022 LocalTime : Mon Jan 24 14:23:39 GMT 2022 DST : Offset = 1 Timezone : Europe/London, Greenwich Mean Time, British Summer Time

2022-01-24 14:23:39,682 [main] INFO [org.rpi.config.Config] Logging Configured 2022-01-24 14:23:39,687 [main] FATAL [org.rpi.config.Config] ###Start of app.properties### 2022-01-24 14:23:39,689 [main] FATAL [org.rpi.config.Config] 'mediaplayer_enable_receiver' : 'true' 2022-01-24 14:23:39,689 [main] FATAL [org.rpi.config.Config] 'mplayer_playlist' : 'asx,b4s,kpl,m3u,pls,ram,rm,smil,wax,wvx' 2022-01-24 14:23:39,690 [main] FATAL [org.rpi.config.Config] 'java_sound_software_mixer_enabled' : 'false' 2022-01-24 14:23:39,691 [main] FATAL [org.rpi.config.Config] 'songcast_latency' : '1000' 2022-01-24 14:23:39,691 [main] FATAL [org.rpi.config.Config] 'log_file_level' : 'debug' 2022-01-24 14:23:39,692 [main] FATAL [org.rpi.config.Config] 'airplay_master_volume_enabled' : 'true' 2022-01-24 14:23:39,692 [main] FATAL [org.rpi.config.Config] 'mplayer_cache_min' : '80' 2022-01-24 14:23:39,693 [main] FATAL [org.rpi.config.Config] 'airplay_port' : '5002'

PeteManchester commented 2 years ago

Hi Bob,

The first few lines will show log messages with a fatal level, this is decided in the code, it doesn't mean anything is wrong..

The bit of the log file you are interested in is where you attempt to play a track, you should see a call being made to MPD to play the track..

2022-01-24 18:10:50,145 [Thread-36] DEBUG [org.rpi.player.PlayManager] PlayThis: Track Id: 2085930449 + URI: http://192.168.1.205:26125/content/c2/b16/f44100/d-3598637355698486438-coBDE65A359132B7BE.flac MetaData:

Where The Streets Have No Name object.item.audioItem.musicTrack http://192.168.1.205:26125/aa/135677837160359/cover.jpg?size=0 The Joshua Tree U2 U2 1987-01-01 Rock http://192.168.1.205:26125/content/c2/b16/f44100/d-3598637355698486438-coBDE65A359132B7BE.flac upnp.cd ://track?udn=8c22f9f9-3131-44e1-0-123456789abc&me=8c22f9f9-3131-44e1-0-123456789abc&trackId=d-3598637355698486438-coBDE65A359132B7BE&version=1 upnp.cd track

2022-01-24 18:10:50,146 [Thread-36] DEBUG [org.rpi.providers.PrvProduct] Source Selected: PlayList 2022-01-24 18:10:50,146 [Thread-36] DEBUG [org.rpi.providers.PrvProduct] update: @.*** 2022-01-24 18:10:50,146 [Thread-36] DEBUG [org.rpi.player.PlayManager] EventStatusChanged: Buffering 2022-01-24 18:10:50,146 [Thread-36] INFO [org.rpi.player.PlayManager] SetStatus: Buffering Source: PLAYER 2022-01-24 18:10:50,146 [Thread-36] DEBUG [org.rpi.providers.PrvAVTransport] Status: Buffering 2022-01-24 18:10:50,148 [Thread-36] DEBUG [org.rpi.radio.parsers.FileParser] FLAC File: http://192.168.1.205:26125/content/c2/b16/f44100/d-3598637355698486438-coBDE65A359132B7BE.flac 2022-01-24 18:10:50,164 [Thread-36] DEBUG [org.rpi.mpdplayer.MPDPlayer] ADD TO PLAYLIST{Id=27} 2022-01-24 18:10:50,278 [Thread-0] DEBUG [org.rpi.mpdplayer.StatusMonitor] Song Changed From : 26 To: 27 2022-01-24 18:10:50,282 [Thread-0] DEBUG [org.rpi.mpdplayer.MPDPlayer] Status Changed: Playing 2022-01-24 18:10:50,282 [Thread-0] DEBUG [org.rpi.player.PlayManager] EventStatusChanged: Playing 2022-01-24 18:10:50,282 [Thread-0] INFO [org.rpi.player.PlayManager] SetStatus: Playing Source: PLAYER 2022-01-24 18:10:50,283 [Thread-0] DEBUG [org.rpi.providers.PrvAVTransport] Status: Playing

If you are using MPD have a look at the MPD log files to see what is happening, the log file is configured in /etc/mpd.conf.

Pete.

On Mon, 24 Jan 2022 at 14:49, mightyoakbob @.***> wrote:

Hi Pete, Before upping the log level I decided to take a look at what was in there first. I found that everything goes fatal (and I do mean everything) the moment it tries to execute app.properties. See below.

mpd is installed and not mplayer. The builds I have done over the last few days trying to break this down are all identical, all use mpd and they work fine with Buster but not with bullseye. I've even tried building both OS builds with java 8 and java 11 but it makes no difference in either case buster works with either bullseye doesn't.

I suppose to be strictly accurate, Kazoo does send the track or at least it shows as the current track in Kazoo but it is stopped at the start and cannot be started.

Although it isn't a dac+ problem as it works fine on Buster, how would I go about changing the setting to stop it using the dac+ ? Reversing the changes made to /boot/config.txt presumably or is there something else ?

Friendly Name : Linn_Pi Version : 0.0.1.2 Host name : LinnPi StartTime : Mon Jan 24 14:23:24 GMT 2022 LocalTime : Mon Jan 24 14:23:39 GMT 2022 DST : Offset = 1 Timezone : Europe/London, Greenwich Mean Time, British Summer Time

2022-01-24 14:23:39,682 [main] INFO [org.rpi.config.Config] Logging Configured 2022-01-24 14:23:39,687 [main] FATAL [org.rpi.config.Config] ###Start of app.properties### 2022-01-24 14:23:39,689 [main] FATAL [org.rpi.config.Config] 'mediaplayer_enable_receiver' : 'true' 2022-01-24 14:23:39,689 [main] FATAL [org.rpi.config.Config] 'mplayer_playlist' : 'asx,b4s,kpl,m3u,pls,ram,rm,smil,wax,wvx' 2022-01-24 14:23:39,690 [main] FATAL [org.rpi.config.Config] 'java_sound_software_mixer_enabled' : 'false' 2022-01-24 14:23:39,691 [main] FATAL [org.rpi.config.Config] 'songcast_latency' : '1000' 2022-01-24 14:23:39,691 [main] FATAL [org.rpi.config.Config] 'log_file_level' : 'debug' 2022-01-24 14:23:39,692 [main] FATAL [org.rpi.config.Config] 'airplay_master_volume_enabled' : 'true' 2022-01-24 14:23:39,692 [main] FATAL [org.rpi.config.Config] 'mplayer_cache_min' : '80' 2022-01-24 14:23:39,693 [main] FATAL [org.rpi.config.Config] 'airplay_port' : '5002'

— Reply to this email directly, view it on GitHub https://github.com/PeteManchester/MediaPlayer/issues/100#issuecomment-1020179053, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA5RVJ2RJYXFYMVFKU2XM5LUXVRIVANCNFSM5MVGFQOQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you commented.Message ID: @.***>

mightyoakbob commented 2 years ago

Hi Pete, I've hopefully attached I've hopefully attached a zip archive containing a segment of the log file from where a track is selected to play. Would take a look please, Can't see the wood for the trees myself.

Thanks

Bob. logfile.zip

PeteManchester commented 2 years ago

Hi Bob,

To me it looks like MediaPlayer is working as it should, it is instructing MPD to play a track and for some reason MPD cannot play that track..

2022-01-25 10:00:02,561 [Thread-21] DEBUG [org.rpi.providers.PrvProduct] Source Selected: PlayList 2022-01-25 10:00:02,561 [Thread-21] DEBUG [org.rpi.providers.PrvProduct] update: @.** 2022-01-25 10:00:02,562 [Thread-21] DEBUG [org.rpi.player.PlayManager] EventStatusChanged: Buffering 2022-01-25 10:00:02,562 [Thread-21] INFO [org.rpi.player.PlayManager] SetStatus: Buffering Source: PLAYER 2022-01-25 10:00:02,563 [Thread-21] DEBUG [org.rpi.providers.PrvAVTransport] Status: Buffering 2022-01-25 10:00:02,574 [Thread-21] DEBUG [org.rpi.radio.parsers.FileParser] FLAC File: http://192.168.1.240:9790/minimserver//Library/Rock20and20Pop/Norah20Jones/Come20Away20with20Me/05_Come_Away_With_Me.flac 2022-01-25 10:00:02,579 [Thread-21] DEBUG [org.rpi.mpdplayer.MPDPlayer] ADD TO PLAYLIST{Id=3} 2022-01-25 10:00:02,783 [Thread-0] DEBUG [org.rpi.mpdplayer.StatusMonitor] Song Changed From : 2 To: 3 2022-01-25 10:00:02,798 [Thread-0] DEBUG [org.rpi.mpdplayer.StatusMonitor] Status Changed From : Stopped To: Paused 2022-01-25 10:00:02,799 [Thread-0] DEBUG [org.rpi.mpdplayer.MPDPlayer] Status Changed: Paused 2022-01-25 10:00:02,800 [Thread-0] DEBUG [org.rpi.player.PlayManager] EventStatusChanged: Paused 2022-01-25 10:00:02,801 [Thread-0] INFO [org.rpi.player.PlayManager] SetStatus: Paused Source: PLAYER 2022-01-25 10:00:02,802 [Thread-0] DEBUG [org.rpi.providers.PrvAVTransport] Status: Paused

Have you managed to test your HifiBerry DAC as described in their docs using aplay -l and trying to play a file using SOX https://www.hifiberry.com/docs/software/playing-test-sounds/? If that works then my guess is that the problem is with the config of MPD.

What does the green LED on your DAC indicate, is it that something is supposed to be playing? Another test you could do is to remove the MediaPlayer service using 'insserv -r mediaplayer' then reboot and see if the green light is still on. If it is still on when MPD has not started then it is unlikely that MediaPlayer is causing the issue..

On Tue, 25 Jan 2022 at 10:13, mightyoakbob @.***> wrote:

Hi Pete, I've hopefully attached I've hopefully attached a zip archive containing a segment of the log file from where a track is selected to play. Would take a look please, Can't see the wood for the trees myself.

Thanks

Bob. logfile.zip https://github.com/PeteManchester/MediaPlayer/files/7932622/logfile.zip

— Reply to this email directly, view it on GitHub https://github.com/PeteManchester/MediaPlayer/issues/100#issuecomment-1021022215, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA5RVJ6FSQYGCB4FJQ37SDTUXZZTRANCNFSM5MVGFQOQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you commented.Message ID: @.***>

mightyoakbob commented 2 years ago

Hi Pete, I installed SOX but it errors with 'play FAIL sox: Sorry, there is no default audio device configured' Done plenty of googling but can't find any clue how to fix that anywhere.

I have though looked at the mpd log when you play a track. See end. That does look interesting and I've included at the very end an mpd log for a track that plays on Buster for comparison. Quite what to do about "Failed to open mixer for 'My ALSA Device':" I don't know but it does play. I think the mpd logs may tell where the problem is but remember Identical configuartion on both OS.

On Buster, - when running, the green led comes on when playing a track and goes out again when it stops. When building the system, the green light comes on following a the reboot after adding init=/bin/systemd to the end of /boot/cmdline.txt. It goes out again following.. sudo systemctl enable mediaplayer.service sudo systemctl start mediaplayer.service It also comes on when the system is powered up but goes out again when boot complete.

With Bullseye, the green light doesn't go out with those commands or when its finished booting.

Jan 25 11:57 : jack_output: Cannot connect to server socket err = No such file or directory Jan 25 11:57 : jack_output: Cannot connect to server request channel Jan 25 11:57 : jack_output: jack server is not running or cannot be started Jan 25 11:57 : jack_output: JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock Jan 25 11:57 : jack_output: JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock Jan 25 11:57 : exception: Failed to enable output "default detected output" (jack); Failed to connect to JACK server, status=17 Jan 25 11:57 : exception: Failed to enable output "default detected output" (jack); Failed to connect to JACK server, status=17 Jan 25 11:57 : player: problems opening audio device while playing "http://192.168.1.240:9790/minimserver/*/Library/Rock*20and*20Pop/Boz*20Scaggs/Dig/02_Sarah.flac"

From working buster... Jan 25 12:44 : player: played "http://192.168.1.240:9790/minimserver/*/Library/Rock*20and*20Pop/Pink*20Floyd/The*20Dark*20Side*20of*20the*20Moon/07_Us_and_Them.flac" Jan 25 12:44 : zeroconf: No global port, disabling zeroconf Jan 25 12:44 : exception: Failed to open mixer for 'My ALSA Device': no such mixer control: PCM Jan 25 12:44 : client: [0] opened from 127.0.0.1:36078

Cheers,

Bob.

mightyoakbob commented 2 years ago

I have stumbled on a part solution. After days of searching the net I found this forum and comment.. https://www.hydrus.org.uk/journal/raspberry-pi-11.html In the comment the guy suggest creating a file called .asoundrc and gives the code to place in it. Then save the file in /var/lib/mpd For him it got the volume control working but for me it extinguishes the green light on the dac and allows music to be played whilst using bullseye for the first time.

I note though that although the volume control on the iPad apps appears to work on screen, it has no effect on the playback volume. Is that to be expected or should the volume control work?

Cheers,

Bob.

PeteManchester commented 2 years ago

Hi Bob,

Whether the volume control works depends on the DAC, what you could try is to edit the /etc/mpd.conf .

In the mpd.conf you should have something like this:

Set the Audio Output

audio_output { type "alsa" name "My ALSA Device" device "hw:0,0" # optional format "44100:16:2" # optional

mixer_device "default" # optional

#mixer_control  "PCM"       # optional
#mixer_index    "0"     # optional

}

Try adding in the line: mixer_type "software"

And restart MPD

https://github.com/PeteManchester/MediaPlayer/wiki/MPD-Info

Cheers,

Pete.

On Thu, 27 Jan 2022 at 19:38, mightyoakbob @.***> wrote:

I have stumbled on a part solution. After days of searching the net I found this forum and comment.. https://www.hydrus.org.uk/journal/raspberry-pi-11.html In the comment the guy suggest creating a file called .asoundrc and gives the code to place in it. Then save the file in /var/lib/mpd For him it got the volume control working but for me it extinguishes the green light on the dac and allows music to be played whilst using bullseye for the first time.

I note though that although the volume control on the iPad apps appears to work on screen, it has no effect on the playback volume. Is that to be expected or should the volume contro work?

Cheers,

Bob.

— Reply to this email directly, view it on GitHub https://github.com/PeteManchester/MediaPlayer/issues/100#issuecomment-1023573687, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA5RVJ4BP5ITA2MEJ4ZEJQLUYGNJ7ANCNFSM5MVGFQOQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you commented.Message ID: @.***>

mightyoakbob commented 2 years ago

Hi Pete, Thank you for that gem and testing this morning shows you are correct. If when using an sd card built using "Buster" I add that line to ALSA config in mpd.conf then I do indeed get the volume control working from the iPad apps - brilliant thanks.

However, attempt to do that on a Bullseye built sd card and it breaks the system again, no sound, green light stuck on just like I had all week.

This whole problem is clearly to do with audio output from mpd which I just don't understand too complex. Whereas the deafult settings for mpd on Buster are just like you suggsted, all of the audio output ALSA settings in a bullseye build are remmed out.

I have tried endless combinations of ALSA settings and the moment you un-rem any of it, the green light stays on and you get no sound.

The code I found yesterday changes an output from 0 to 1, I pressume that's a device output. So I guessed that it may be something to do with the ALSA line: device "hw:0,0" I tried "hw:1" and "hw:1,1" but made no difference back to "dead" with any setting. I removed the extra code I added yesterday and tried both options again - still dead. I'd love to know what the comma and second digit does as in 0,0 . Search as I have, I can find no explanation for the second digit, what does it do?

Anyhting else I can try? Wish I had more understanding of these outputs.

Thanks.

Bob.

mightyoakbob commented 2 years ago

Hi Pete, Found it, and when you know - it's so simple. Unlike Buster, Bullseye enables an extra sound card with the line: dtoverlay=vc4-kms-v3d in /boot/config.txt REM out or remove that line, simples.

Bob.

PeteManchester commented 2 years ago

Hi Bob,

That's great news..

I suprising how hard it is to find the simple things that have changed between versions. I've just spent a week finding all the changes on one of my apps at work after upgrading the version of Angular..

Do you know what the extra soundcard was meant to be used for?

Cheers,

Pete.

mightyoakbob commented 2 years ago

Hi Pete, Yes, the extra driver is for HDMI sound. So on older pi variants with 1 HDMI port you get two sound cards. On a Pi4 you get 3 sound cards, the on-board, and two HDMIs for the two HDMI ports. By removing : dtparam=audio=on (on board) dtoverlay=vc4-kms-v3d (hdmi) both from /boot/config.txt You can remove all sound cards prior to installing a driver for the HIFIBerry card.

Cheers, Bob.