[Android Apps and Games] codlord:
Problems using OpenHome renderer with Squeezebox Touch

I have been using BubbleUPNP Server to create an OpenHome renderer to control a Squeezebox v2 for a while now without any problems at all. All works well.

I recently purchased a Squeezebox Touch model but I cannot get the BubbleUPNP/OpenHome to work it properly. Example:

I go to Library -> Albums, click on an album, then click on the large "Play" button. It takes a while for anything to happen and then only the first track of the album is added to the playlist and nothing starts playing. Sometimes it starts to play after a long delay or sometimes it does not play anything. I get quite a few "Action Timeout" messages from the BubbleUPNP client, but not always.

Both the Squeezebox v2 and Squeezebox Touch work fine if I just use their local controls or use Logitech Media Server or even just use BubbleUPNP android client to control the player directly. The problem is ONLY when trying to control the OpenHome version of the Squeezebox Touch renderer.

I have tried various settings, restarting all the servers/clients etc but no change. Anyone have any ideas?

Thanks

BubbleUPNP server v0.9-update31 running on Ubuntu Linux.

BubbleUPNP Android Client v3.2.3 (both arm64-v8a and x86_64 on 2 devices)

Logitech Media Server v7.9.2 - 1556570947 running on the same Linux box.

Linux 5.0.0-13-generic #14-Ubuntu SMP Mon Apr 15 14:59:14 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

MORE INFO FROM BUBBLEUPNP LOGS:

When I press play on the client, the logs indicate that it has inserted all the album tracks to the playlist - several "Squeezebox Touch (OpenHome): inserted track afterId" messages. Although only the first track is actually shown in the playlist. Then it logs a SEVERE timeout message. Then in this case it does eventually play the single track.

[cling-1523 (10008) ] INFO - 24:45:15.323 - .ac : stopping task GetTransportStateTask
[cling-1523 (10008) ] INFO - 24:45:15.336 - .b : Squeezebox Touch: waitForTransportState: waiting for Stopped
[pool-94-thread-1 (9151) ] SEVERE - 24:45:27.118 - .c$a : Error reading state of service after state variable update event: java.lang.RuntimeException: Failed to acquire lock in milliseconds: 10000
[pool-94-thread-1 (9151) ] INFO - 24:45:27.123 - .e : saved file /root/.bubbleupnpserver/Playlists/ec32f065-321d-2747-ffff-ffffb2868ede.dpl ok: 13 items
[cling-1523 (10008) ] INFO - 24:45:30.444 - .b : Squeezebox Touch: timeout waiting for Stopped
[cling-1523 (10008) ] WARNING - 24:45:30.445 - .b : Squeezebox Touch: play: Stop action failed: Current state of service prevents invoking that action. timeout waiting for Stopped. (code: 501)
[cling-1523 (10008) ] INFO - 24:45:30.446 - .a : SetAVTransportURI(http://192.168.0.55:9000/music/130985/download.mp3?bitrate=320, <DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns:sec="http://www.sec.co.kr/" xmlns:pv="http://www.pv.com/pvns/"><item id="/l/9238/t/130985" parentID="/l/9238/t" restricted="1"><upnp:class>object.item.audioItem.musicTrack</upnp:class><dc:title>Tender</dc:title><dc:creator>Blur</dc:creator><upnp:artist>Blur</upnp:artist><upnp:albumArtURI>http://192.168.0.55:9000/music/290daeb1/cover</upnp:albumArtURI><upnp:genre>Pop</upnp:genre><dc:date>1999-01-01</dc:date><upnp:album>13</upnp:album><upnp:originalTrackNumber>1</upnp:originalTrackNumber><res protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=11;DLNA.ORG_FLAGS=01700000000000000000000000000000" bitrate="30750" sampleFrequency="44100" size="14375040" duration="0:07:40.000">http://192.168.0.55:9000/music/130985/download.mp3?bitrate=320</res></item></DIDL-Lite>)
[qtp1791706561-8579 (8579) ] INFO - 24:45:30.452 - .FfmpegPCMDecodeServlet : decode params: {"itemId":"/l/9238/t/130985","url":"http://192.168.0.55:9000/music/130985/download.mp3?bitrate\u003d320","ext":"mp3","supportsL16":true,"supportsL24":false,"supportsWAV":false,"soxResamplePrecision":28,"forcedSamplerate":-1,"maxSamplerate":192000,"defaultSamplerate":192000,"convert24BitTo16Bit":false,"downmixMultichannelToStereo":false,"convertMonoToStereo":true,"padEndOfTrack":true,"replaygain":"drop","rendererIpAddress":"192.168.0.55","rendererUdn":"9E67AE89-ADBF-1DB8-D770-02CC64BAB6AD"}
[qtp1791706561-8579 (8579) ] INFO - 24:45:30.452 - .FFMpegUtils : removed expired cached probe info for http://192.168.0.62:57645/external/audio/media/712.mp3_mp3
[qtp1791706561-8579 (8579) ] INFO - 24:45:30.452 - .FFMpegUtils : removed expired cached probe info for http://192.168.0.62:57645/external/audio/media/1765.mp3_mp3
[qtp1791706561-8579 (8579) ] INFO - 24:45:30.452 - .FFMpegUtils : ffprobe process started, timeout: 30000 ms: ffprobe -show_format -show_streams -seekable 0 http://192.168.0.55:9000/music/130985/download.mp3?bitrate=320
[qtp1791706561-8579 (8579) ] INFO - 24:45:30.476 - .FFMpegUtils : ffprobe finished