DLNA / UPNP binding

Can anyone tell me how to get the player on main UI? Since the channel uses an integrated widget, I do not seem to find a solution to get it to work on Main UI. Thanks for the help.

I assume that you are new the MainUI?

  1. You can start with the Semantic Model to get an auto-generated dashboard of your controls. → gets all of your stuff to the dashboard but very generic.
  2. You can create a widget on your own or get one from the marketplace like Multiroom Audio Player or Custom Widget: Music Control. → gets just your audio player done and could require more time for customization.

I did both in that particular order.

Hello yahoodee. Thank you for your reply. I am very new to all the openHab environment. It is a little frustrating that each interface behaves in a diffeent manner. You think you have understood how to get around somenthing and then the next thing does not work as expected. See in example the issue with the slection widget in Habpanel, which is way better than main UI. Anyhow, I do use the semantic model, but do not see how this can help. Generating a tile in Main UI from the model does not provide access to the player. I get RENDERER, MAIN TITLE and MAIN TITLE SELCTION id working as expected, but then the player does not work so cannot start the renderer. The idea is to send any type of file to an Oppo player. I was able to get it working somehow using Habpanel (found a player widget that interfaces with the player channel). However, you have the issue of the file selection process (refresh page). To make things worse, it is not possible to put in MAIN UI the SELECTION and RENDERER and have the play widget in Habpanel.

I configured all of the items which I need as point - > control to the model as a equipment of type speaker and placed it in the room where it is installed. So i see the items in the overview page via location and equipment tab. They are displayed with their default list widget which was working out of the box in my case.

But I am not sure if I got you right. Probably some screenshots would help. I will post some of my setup sunday evening.

Another option would be to go to settings>pages>overview and add a cell/widget. There you can select a ‘player card’ and point to your item for the ‘control’ channel.
This approach would lead to many independent widgets (player, loudness, mute, stop, etc) which would not look nice imho.

@yhd thatnk you for the explenation. I confirm I have done both things. I was able to get my Oppo to receive the stream at some point, but then stopped working. To be quite frank, I would be only interested to work on it a little longer if I could get the file list to show up appropriately in the hub panel, which for now is not possible. I may give it another try if I find a use for it.

Also for me it is not running perfectly, tbh. I have two issues atm.

  1. One renderer which “disappears” after 30 minutes with this message:

UPnP device with UDN […] not yet registered

This seems to be renderer specific and independant of docker like here. I found a manual workaround by doing a discovery. This prevents the renderer from disappearing and also brings it back. So I automated it and build a cron job to run a shell script to restart the karaf bundle for upnp discovery every 20 minutes. Not nice, but it works.

  1. Playback sometimes stops after playing a song. Even if there should be more on the playlist.
    I am analyzing this atm. What I can say is that it sometimes need to trigger a ‘stop’ command on the upnpserver / reselecting the renderer and/or restart to browse the content to get the playback running again. I am quite confident to get it running more stable.

But in general the dynamic update of the renderer and browser channels works:
Renderer:


Browser (current media id):

Starting with the widget from ysc I made the upper one for my upnpserver and the lower one for all of my speakers:
image

ftr i am using plex as upnp server

Very nice job indeed. The issue for me is that I have no experience with openHab and only started working on it like four weeks back. Most of the things I wanted to control and automise I managed to do even using some workarounds (such as using IFTT to control my light scenario with Smart Things). UpnP would have been a very nice addition if I could get it to work with HabPanel, which it does not. The first setup I did was with MainUi, but I found the interface to be primitive to say the least. HabPanel is nice and it can get even nicer as people provide more widgets to customise.
I could start studying java and how to create bindings and widgets, but just do not have the time for now. So I am heavily relying on this brilliant community of superskilled people to do the work :sweat_smile:

@yhd

If you are OK to spend the time to further analyze this, let me know. While the binding relies on the underlying UPnP library, it tries to keep track of devices. 1 sounds like a device not sending a keep alive. 2 is a tricky one and depends on the specific renderers. Logic was built in the binding to overcome this, but it may not be perfect. TRACE logs would reveal what exactly is happening.

Yes I am.

  1. Thats also what I think. I loose the device also in Bubbleupnp and the Intel developer tools after a while. Its a cheap “AudioCast” china device found on amazon. So I got what I paid for… =(

  2. I will get some trace logs in the upcomming days. The other renderers are mopidy clients with upmpdcli. I am not sure if they have that onlyplayone flag set or repeat unset by default.

  3. I quite forgot that I also have a Marantz AVR thats handled by the denonmarantz binding that gets not discovered as upnp device with OH despite working flawless with bubbleupnp.

Thanks in advance

I found some time read through this thread and do some testing.

  1. Device disappearing after 30 mins” - Is there any chance to keep it alive nevertheless?
  2. Playback sometimes stops after playing a song” - I moved to another renderer which has not “disappearing after 30 mins” issues → Pi with Moode Audio Player which also uses Upmpd.

I think one of my causes come from using bubbleupnp and OH as control points in turn. Are there any known issues in general? Is there a sequence in usage that should not cause any side effects?

Nevertheless I also had trouble while only using OH as control point. Here is a sequence where the current playing track comes to the end and playback stops even there is more on the queue. Manually resuming playback works.

==> /var/log/openhab/events.log <==
2023-02-24 10:01:07.313 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Position' changed from 180 s to 182 s
==> /var/log/openhab/openhab.log <==
2023-02-24 10:01:08.294 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="b9c4946cca1966048b48" parentID="e4ddede036e92ae673d2" restricted="true"><dc:title>The Edge</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Electronic Circus</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>30</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 10:01:08.295 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsTime with value 0:03:02 from service AVTransport
2023-02-24 10:01:08.296 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelCount with value 0 from service AVTransport
2023-02-24 10:01:08.297 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelTime with value 0:03:02 from service AVTransport
2023-02-24 10:01:08.301 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackURI with value http://192.168.0.33:32469/object/b9c4946cca1966048b48/file.mp3 from service AVTransport
2023-02-24 10:01:08.302 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsCount with value 0 from service AVTransport
2023-02-24 10:01:08.303 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable Track with value 1 from service AVTransport
2023-02-24 10:01:08.304 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackDuration with value 0:03:03 from service AVTransport
2023-02-24 10:01:08.466 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<PlaybackStorageMedium val="NONE"/>
<AbsoluteTimePosition val="0:00:00"/>
<TransportState val="STOPPED"/>
<CurrentTransportActions val="Next,Previous,Play"/>
<CurrentMediaDuration val="00:00:00"/>
<CurrentTrackDuration val="00:00:00"/>
<RelativeTimePosition val="0:00:00"/>
</InstanceID>
</Event>
from service AVTransport
2023-02-24 10:01:08.474 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsoluteTimePosition with value 0:00:00 from service AVTransport
2023-02-24 10:01:08.475 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable PlaybackStorageMedium with value NONE from service AVTransport
2023-02-24 10:01:08.476 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTransportActions with value Next,Previous,Play from service AVTransport
2023-02-24 10:01:08.477 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 10:01:08.478 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentMediaDuration with value 00:00:00 from service AVTransport
2023-02-24 10:01:08.479 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelativeTimePosition with value 0:00:00 from service AVTransport
2023-02-24 10:01:08.479 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackDuration with value 00:00:00 from service AVTransport
2023-02-24 10:01:08.483 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TransportState with value STOPPED from service AVTransport
2023-02-24 10:01:08.484 [DEBUG] [internal.handler.UpnpRendererHandler] - Update server UPnP Server channel PAUSE with state upnpcontrol:upnprenderer:01c78e72-f10f-e21f-dbd6-e45f0190013a:control from renderer UpnpRenderer
2023-02-24 10:01:08.491 [DEBUG] [internal.handler.UpnpRendererHandler] - Serve next media 'Better Mind - Original Mix' from queue on renderer UpnpRenderer
2023-02-24 10:01:08.492 [TRACE] [internal.handler.UpnpRendererHandler] - Serve next, current queue index: 6
2023-02-24 10:01:08.493 [TRACE] [internal.handler.UpnpRendererHandler] - Serve media on renderer UpnpRenderer
2023-02-24 10:01:08.499 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:08.501 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:08.502 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
2023-02-24 10:01:08.517 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetAVTransportURI on service AVTransport with inputs {InstanceID=0, CurrentURI=http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3, CurrentURIMetaData=<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="1dec3ae9ef54ae8ac80b" parentID="e4ddede036e92ae673d2" restricted="true"><dc:title>Better Mind - Original Mix</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Electronic Circus</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>14</upnp:originalTrackNumber></item></DIDL-Lite>}
2023-02-24 10:01:08.539 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetAVTransportURI on service AVTransport reply null
==> /var/log/openhab/events.log <==
2023-02-24 10:01:08.511 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Duration' changed from 183 s to 0 s
2023-02-24 10:01:08.513 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UPnPServer_Fernbedienung' changed from PLAY to PAUSE
2023-02-24 10:01:08.529 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Fernbedienung' changed from PLAY to PAUSE
2023-02-24 10:01:08.534 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Position' changed from 182 s to 0 s
2023-02-24 10:01:08.570 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Titel' changed from The Edge to UNDEF
2023-02-24 10:01:08.572 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Album_Art' changed from raw type (image/jpeg): 22670 bytes to UNDEF
2023-02-24 10:01:08.573 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Kunstler' changed from Various Artists to UNDEF
2023-02-24 10:01:08.575 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Titel' changed from UNDEF to Better Mind - Original Mix
2023-02-24 10:01:08.577 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Album_Art' changed from UNDEF to raw type (image/jpeg): 22670 bytes
2023-02-24 10:01:08.581 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Kunstler' changed from UNDEF to Various Artists
==> /var/log/openhab/openhab.log <==
2023-02-24 10:01:09.470 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<AVTransportURI val="http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3"/>
<CurrentTrackURI val="http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3"/>
<CurrentTrackMetaData val="&lt;DIDL-Lite xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;1dec3ae9ef54ae8ac80b&quot; parentID=&quot;e4ddede036e92ae673d2&quot; restricted=&quot;true&quot;&gt;&lt;dc:title&gt;Better Mind - Original Mix&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;upnp:album&gt;Electronic Circus&lt;/upnp:album&gt;&lt;upnp:albumArtURI&gt;http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg&lt;/upnp:albumArtURI&gt;&lt;dc:creator&gt;Various Artists&lt;/dc:creator&gt;&lt;upnp:artist&gt;Various Artists&lt;/upnp:artist&gt;&lt;dc:publisher&gt;&lt;/dc:publisher&gt;&lt;upnp:genre&gt;Unknown&lt;/upnp:genre&gt;&lt;upnp:originalTrackNumber&gt;14&lt;/upnp:originalTrackNumber&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;"/>
<AVTransportURIMetaData val="&lt;DIDL-Lite xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;1dec3ae9ef54ae8ac80b&quot; parentID=&quot;e4ddede036e92ae673d2&quot; restricted=&quot;true&quot;&gt;&lt;dc:title&gt;Better Mind - Original Mix&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;upnp:album&gt;Electronic Circus&lt;/upnp:album&gt;&lt;upnp:albumArtURI&gt;http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg&lt;/upnp:albumArtURI&gt;&lt;dc:creator&gt;Various Artists&lt;/dc:creator&gt;&lt;upnp:artist&gt;Various Artists&lt;/upnp:artist&gt;&lt;dc:publisher&gt;&lt;/dc:publisher&gt;&lt;upnp:genre&gt;Unknown&lt;/upnp:genre&gt;&lt;upnp:originalTrackNumber&gt;14&lt;/upnp:originalTrackNumber&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;"/>
</InstanceID>
</Event>
from service AVTransport
2023-02-24 10:01:09.477 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackURI with value http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3 from service AVTransport
2023-02-24 10:01:09.479 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer received URI: http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3
2023-02-24 10:01:09.484 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer current URI: http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3, equal to received URI true
2023-02-24 10:01:09.485 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer next URI: http://192.168.0.33:32469/object/813c88e01ec9ab81d899/file.mp3
2023-02-24 10:01:09.485 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackURI with value http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3 from service AVTransport
2023-02-24 10:01:09.487 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer received URI: http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3
2023-02-24 10:01:09.489 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer current URI: http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3, equal to received URI true
2023-02-24 10:01:09.490 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer next URI: http://192.168.0.33:32469/object/813c88e01ec9ab81d899/file.mp3
2023-02-24 10:01:09.491 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 10:01:09.492 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="1dec3ae9ef54ae8ac80b" parentID="e4ddede036e92ae673d2" restricted="true"><dc:title>Better Mind - Original Mix</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Electronic Circus</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>14</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 10:01:09.498 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:09.499 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:09.500 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
2023-02-24 10:01:09.521 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="1dec3ae9ef54ae8ac80b" parentID="e4ddede036e92ae673d2" restricted="true"><dc:title>Better Mind - Original Mix</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Electronic Circus</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>14</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 10:01:09.529 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:09.530 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: 1dec3ae9ef54ae8ac80b
2023-02-24 10:01:09.531 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
==> /var/log/openhab/events.log <==
2023-02-24 10:01:09.481 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LautsprecherArbeitszimmer_URI' changed from http://192.168.0.33:32469/object/b9c4946cca1966048b48/file.mp3 to http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3
2023-02-24 10:10:32.064 [DEBUG] [internal.handler.UpnpRendererHandler] - Handle command PLAY for channel upnpcontrol:upnprenderer:01c78e72-f10f-e21f-dbd6-e45f0190013a:control on renderer UpnpRenderer
2023-02-24 10:10:32.066 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action Play on service AVTransport with inputs {Speed=1, InstanceID=0}
==> /var/log/openhab/events.log <==
2023-02-24 10:10:32.051 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'UpnpRenderer_Fernbedienung' received command PLAY
2023-02-24 10:10:32.052 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'UpnpRenderer_Fernbedienung' predicted to become PLAY
2023-02-24 10:10:32.062 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Fernbedienung' changed from PAUSE to PLAY
==> /var/log/openhab/openhab.log <==
2023-02-24 10:10:32.089 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action Play on service AVTransport reply null
2023-02-24 10:10:32.145 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<PlaybackStorageMedium val="HDD"/>
<TransportState val="PLAYING"/>
<CurrentTransportActions val="Next,Previous,Pause,Stop,Seek"/>
<CurrentMediaDuration val="0:06:04"/>
<CurrentTrackDuration val="0:06:04"/>
</InstanceID>
</Event>
from service AVTransport
2023-02-24 10:10:32.152 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable PlaybackStorageMedium with value HDD from service AVTransport
2023-02-24 10:10:32.153 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTransportActions with value Next,Previous,Pause,Stop,Seek from service AVTransport
2023-02-24 10:10:32.154 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 10:10:32.155 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentMediaDuration with value 0:06:04 from service AVTransport
2023-02-24 10:10:32.155 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackDuration with value 0:06:04 from service AVTransport
2023-02-24 10:10:32.158 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TransportState with value PLAYING from service AVTransport
2023-02-24 10:10:32.160 [DEBUG] [internal.handler.UpnpRendererHandler] - Update server UPnP Server channel PLAY with state upnpcontrol:upnprenderer:01c78e72-f10f-e21f-dbd6-e45f0190013a:control from renderer UpnpRenderer
==> /var/log/openhab/events.log <==
2023-02-24 10:10:32.169 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Duration' changed from 0 s to 364 s
2023-02-24 10:10:32.171 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UPnPServer_Fernbedienung' changed from PAUSE to PLAY
==> /var/log/openhab/openhab.log <==
2023-02-24 10:10:33.269 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="1dec3ae9ef54ae8ac80b" parentID="e4ddede036e92ae673d2" restricted="true"><dc:title>Better Mind - Original Mix</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Electronic Circus</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/e7c7b13bb7fb3e112a10/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>14</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 10:10:33.269 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsTime with value 0:00:01 from service AVTransport
2023-02-24 10:10:33.271 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelCount with value 0 from service AVTransport
2023-02-24 10:10:33.272 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelTime with value 0:00:01 from service AVTransport
2023-02-24 10:10:33.275 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackURI with value http://192.168.0.33:32469/object/1dec3ae9ef54ae8ac80b/file.mp3 from service AVTransport
2023-02-24 10:10:33.276 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsCount with value 0 from service AVTransport
2023-02-24 10:10:33.277 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable Track with value 1 from service AVTransport
2023-02-24 10:10:33.278 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackDuration with value 0:06:04 from service AVTransport

A bundle:restart org.openhab.binding.upnpcontrol does not lead to normal behaviour.

  1. DenonMarantz Avr not discovered as renderer” - the log shows the device but no renderer like my Upmpd-devices:
2023-02-24 10:40:02.545 [DEBUG] [very.UpnpControlDiscoveryParticipant] - Device type AiosDevice, manufacturer Marantz, model Marantz SR6015, SN# MBCL112003130, UDN 49ffc712-b43c-174b-0080-00067851e9ee
2023-02-24 10:40:02.524 [DEBUG] [very.UpnpControlDiscoveryParticipant] - Device type MediaRenderer, manufacturer JF Light Industries, model UpMPD, SN# upmpdcli version 1.7.2 libupnpp 0.22.4 mpd 0.19.0, UDN 3d514499-4e16-edb0-47ad-dca63249033a
2023-02-24 10:40:02.533 [DEBUG] [very.UpnpControlDiscoveryParticipant] - Device type MediaRenderer, manufacturer JF Light Industries, model UpMPD, SN# upmpdcli version 1.5.13 libupnpp 0.21.0 mpd 0.19.0, UDN dd9064db-6c4d-1f2b-9bda-b827eb7afc0d
2023-02-24 10:40:02.551 [DEBUG] [very.UpnpControlDiscoveryParticipant] - Device type MediaRenderer, manufacturer JF Light Industries, model UpMPD, SN# upmpdcli version 1.5.11 libupnpp 0.21.0, UDN 01c78e72-f10f-e21f-dbd6-e45f0190013a

Device Spy:


The avr is shown as a kind of sub-device whereas the discovered ones are not
Device Validator:
image
Is there any chance to get it working?

I really appreciate your efforts!
Thanks

Just saw that setting shuffle to true also sets onlyplayone to true but doesnt update the channel/item:
chrome_o0z7w2Jgjo

I think this message received from the renderer is what makes OH switch from Play to Stop. It would be interesting to see the log for a successful continuation as well, to make sure. But OH clearly receives a STOPPED message from the renderer. I don’t know what is causing this.

I would need to see if it would be possible to discover the subdevices as well in the code. That’s going to be hard without hardware that has that kind of behaviour. I don’t have a DenonMarantz AVR.

All of the discovery and availability of the upnp devices is handled by the underlying jupnp library. The binding only reacts on it, without having much control. I am not sure I can do much about that, but I will check.

1 Like

Are you sure your items are linked to the right channel?

I just asked myself the same and checked it:


Its just that particular single item thats linked to that channel.

I made a new gif which shows filters for shuffle and onlyplayone:
ctQ24FXEXp

I think I can workaround this issue for now. I just verified that it affects at least one other players (mopidy+upmpd) of mine. =(
Afaik all the raspberry music distros out there use upmpd, so the scope of this issue could be more than just me even if I am the first one mentioning this. More community feedback is welcome.

Please let me know if I can provide more logs or do some testing.

Ftr in case of continuing playback it also logs:
<TransportState val="STOPPED"/> but with a following <TransportState val="PLAYING"/>

Thanks again!

I found the issue in the code and submitted [upnpcontrol] Fix shuffle switch also switching only play one by mherwege · Pull Request #14490 · openhab/openhab-addons · GitHub to fix this. It is on the 4.0 branch, so will not be available immediately on 3.4. If you are eager to get it, I would need to compile a 3.4 version.

Do these 2 events immediately follow each other, or is there something in between? Not receiving the PLAYING event in time obviously is the problem, but not sure about the timings and how to solve this. It would be interesting to see what exactly happens at that point in time.

It takes two seconds and there are no other TransportStates in between:

==> /var/log/openhab/events.log <==
2023-02-24 12:20:27.833 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Position' changed from 159 s to 160 s
==> /var/log/openhab/openhab.log <==
2023-02-24 12:20:28.455 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<PlaybackStorageMedium val="NONE"/>
<AbsoluteTimePosition val="0:00:00"/>
<TransportState val="STOPPED"/>
<CurrentTransportActions val="Next,Previous,Play"/>
<CurrentMediaDuration val="00:00:00"/>
<CurrentTrackDuration val="00:00:00"/>
<RelativeTimePosition val="0:00:00"/>
</InstanceID>
</Event>
 from service AVTransport
2023-02-24 12:20:28.472 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsoluteTimePosition with value 0:00:00 from service AVTransport
2023-02-24 12:20:28.474 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable PlaybackStorageMedium with value NONE from service AVTransport
2023-02-24 12:20:28.477 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTransportActions with value Next,Previous,Play from service AVTransport
2023-02-24 12:20:28.479 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 12:20:28.481 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentMediaDuration with value 00:00:00 from service AVTransport
2023-02-24 12:20:28.482 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelativeTimePosition with value 0:00:00 from service AVTransport
2023-02-24 12:20:28.483 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackDuration with value 00:00:00 from service AVTransport
2023-02-24 12:20:28.488 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TransportState with value STOPPED from service AVTransport
2023-02-24 12:20:28.489 [DEBUG] [internal.handler.UpnpRendererHandler] - Update server UPnP Server channel PAUSE with state upnpcontrol:upnprenderer:01c78e72-f10f-e21f-dbd6-e45f0190013a:control from renderer UpnpRenderer
2023-02-24 12:20:28.501 [DEBUG] [internal.handler.UpnpRendererHandler] - Serve next media 'Come Around' from queue on renderer UpnpRenderer
2023-02-24 12:20:28.502 [TRACE] [internal.handler.UpnpRendererHandler] - Serve next, current queue index: 1
2023-02-24 12:20:28.503 [TRACE] [internal.handler.UpnpRendererHandler] - Serve media on renderer UpnpRenderer
2023-02-24 12:20:28.507 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:28.509 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:28.510 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
2023-02-24 12:20:28.526 [TRACE] [internal.handler.UpnpRendererHandler] - Ready to play 'Come Around' from queue
2023-02-24 12:20:28.527 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetAVTransportURI on service AVTransport with inputs {InstanceID=0, CurrentURI=http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3, CurrentURIMetaData=<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="ab57ea26b21a51ee3c89" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Come Around</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>16</upnp:originalTrackNumber></item></DIDL-Lite>}
2023-02-24 12:20:28.551 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetAVTransportURI on service AVTransport reply null
==> /var/log/openhab/events.log <==
2023-02-24 12:20:28.492 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Duration' changed from 162 s to 0 s
2023-02-24 12:20:28.507 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UPnPServer_Fernbedienung' changed from PLAY to PAUSE
2023-02-24 12:20:28.509 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Fernbedienung' changed from PLAY to PAUSE
2023-02-24 12:20:28.517 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Position' changed from 160 s to 0 s
2023-02-24 12:20:28.522 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Titel' changed from One Last Fire to UNDEF
2023-02-24 12:20:28.524 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Album_Art' changed from raw type (image/jpeg): 25325 bytes to UNDEF
2023-02-24 12:20:28.525 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Kunstler' changed from Various Artists to UNDEF
2023-02-24 12:20:28.528 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Titel' changed from UNDEF to Come Around
2023-02-24 12:20:28.549 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Album_Art' changed from UNDEF to raw type (image/jpeg): 25325 bytes
2023-02-24 12:20:28.551 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Kunstler' changed from UNDEF to Various Artists
==> /var/log/openhab/openhab.log <==
2023-02-24 12:20:29.452 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<AVTransportURI val="http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3"/>
<CurrentTrackURI val="http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3"/>
<CurrentTrackMetaData val="&lt;DIDL-Lite xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;ab57ea26b21a51ee3c89&quot; parentID=&quot;7bdcf62f942e7fd26bdf&quot; restricted=&quot;true&quot;&gt;&lt;dc:title&gt;Come Around&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;upnp:album&gt;Rock-Motivation&lt;/upnp:album&gt;&lt;upnp:albumArtURI&gt;http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg&lt;/upnp:albumArtURI&gt;&lt;dc:creator&gt;Various Artists&lt;/dc:creator&gt;&lt;upnp:artist&gt;Various Artists&lt;/upnp:artist&gt;&lt;dc:publisher&gt;&lt;/dc:publisher&gt;&lt;upnp:genre&gt;Unknown&lt;/upnp:genre&gt;&lt;upnp:originalTrackNumber&gt;16&lt;/upnp:originalTrackNumber&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;"/>
<AVTransportURIMetaData val="&lt;DIDL-Lite xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;ab57ea26b21a51ee3c89&quot; parentID=&quot;7bdcf62f942e7fd26bdf&quot; restricted=&quot;true&quot;&gt;&lt;dc:title&gt;Come Around&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;upnp:album&gt;Rock-Motivation&lt;/upnp:album&gt;&lt;upnp:albumArtURI&gt;http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg&lt;/upnp:albumArtURI&gt;&lt;dc:creator&gt;Various Artists&lt;/dc:creator&gt;&lt;upnp:artist&gt;Various Artists&lt;/upnp:artist&gt;&lt;dc:publisher&gt;&lt;/dc:publisher&gt;&lt;upnp:genre&gt;Unknown&lt;/upnp:genre&gt;&lt;upnp:originalTrackNumber&gt;16&lt;/upnp:originalTrackNumber&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;"/>
</InstanceID>
</Event>
 from service AVTransport
2023-02-24 12:20:29.459 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackURI with value http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3 from service AVTransport
2023-02-24 12:20:29.460 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action Play on service AVTransport with inputs {Speed=1, InstanceID=0}
2023-02-24 12:20:29.462 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer received URI: http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3
2023-02-24 12:20:29.463 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer current URI: http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3, equal to received URI true
2023-02-24 12:20:29.466 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer next URI: http://192.168.0.33:32469/object/577f725f9fda069f8950/file.mp3
2023-02-24 12:20:29.468 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackURI with value http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3 from service AVTransport
2023-02-24 12:20:29.473 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer received URI: http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3
2023-02-24 12:20:29.474 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer current URI: http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3, equal to received URI true
2023-02-24 12:20:29.476 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer next URI: http://192.168.0.33:32469/object/577f725f9fda069f8950/file.mp3
2023-02-24 12:20:29.479 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action Play on service AVTransport reply null
2023-02-24 12:20:29.480 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetNextAVTransportURI on service AVTransport with inputs {InstanceID=0, NextURI=http://192.168.0.33:32469/object/577f725f9fda069f8950/file.mp3, NextURIMetaData=<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="577f725f9fda069f8950" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Stay Ready</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>17</upnp:originalTrackNumber></item></DIDL-Lite>}
2023-02-24 12:20:29.481 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 12:20:29.482 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="ab57ea26b21a51ee3c89" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Come Around</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>16</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 12:20:29.489 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:29.490 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:29.491 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
2023-02-24 12:20:29.506 [DEBUG] [control.internal.handler.UpnpHandler] - UPnP device UpnpRenderer invoke upnp action SetNextAVTransportURI on service AVTransport reply null
2023-02-24 12:20:29.540 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="ab57ea26b21a51ee3c89" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Come Around</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>16</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 12:20:29.547 [TRACE] [internal.handler.UpnpRendererHandler] - Renderer UpnpRenderer, received media ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:29.548 [TRACE] [internal.handler.UpnpRendererHandler] - Current ID: ab57ea26b21a51ee3c89
2023-02-24 12:20:29.549 [TRACE] [internal.handler.UpnpRendererHandler] - Received meta data is for current entry: true
==> /var/log/openhab/events.log <==
2023-02-24 12:20:29.467 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LautsprecherArbeitszimmer_URI' changed from http://192.168.0.33:32469/object/03b755dbcbc2fda47e6b/file.mp3 to http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3
==> /var/log/openhab/openhab.log <==
2023-02-24 12:20:30.467 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable LastChange with value <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS">
<InstanceID val="0">
<PlaybackStorageMedium val="HDD"/>
<NextAVTransportURIMetaData val="&lt;DIDL-Lite xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;577f725f9fda069f8950&quot; parentID=&quot;7bdcf62f942e7fd26bdf&quot; restricted=&quot;true&quot;&gt;&lt;dc:title&gt;Stay Ready&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;upnp:album&gt;Rock-Motivation&lt;/upnp:album&gt;&lt;upnp:albumArtURI&gt;http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg&lt;/upnp:albumArtURI&gt;&lt;dc:creator&gt;Various Artists&lt;/dc:creator&gt;&lt;upnp:artist&gt;Various Artists&lt;/upnp:artist&gt;&lt;dc:publisher&gt;&lt;/dc:publisher&gt;&lt;upnp:genre&gt;Unknown&lt;/upnp:genre&gt;&lt;upnp:originalTrackNumber&gt;17&lt;/upnp:originalTrackNumber&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;"/>
<NextAVTransportURI val="http://192.168.0.33:32469/object/577f725f9fda069f8950/file.mp3"/>
<AbsoluteTimePosition val="0:00:01"/>
<TransportState val="PLAYING"/>
<CurrentTransportActions val="Next,Previous,Pause,Stop,Seek"/>
<CurrentMediaDuration val="0:03:32"/>
<CurrentTrackDuration val="0:03:32"/>
<RelativeTimePosition val="0:00:01"/>
</InstanceID>
</Event>
 from service AVTransport
2023-02-24 12:20:30.474 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsoluteTimePosition with value 0:00:01 from service AVTransport
2023-02-24 12:20:30.475 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable PlaybackStorageMedium with value HDD from service AVTransport
2023-02-24 12:20:30.476 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable NextAVTransportURIMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="577f725f9fda069f8950" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Stay Ready</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>17</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 12:20:30.482 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTransportActions with value Next,Previous,Pause,Stop,Seek from service AVTransport
2023-02-24 12:20:30.484 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable InstanceID with value 0 from service AVTransport
2023-02-24 12:20:30.485 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentMediaDuration with value 0:03:32 from service AVTransport
2023-02-24 12:20:30.485 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelativeTimePosition with value 0:00:01 from service AVTransport
2023-02-24 12:20:30.486 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable NextAVTransportURI with value http://192.168.0.33:32469/object/577f725f9fda069f8950/file.mp3 from service AVTransport
2023-02-24 12:20:30.487 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable CurrentTrackDuration with value 0:03:32 from service AVTransport
2023-02-24 12:20:30.490 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TransportState with value PLAYING from service AVTransport
2023-02-24 12:20:30.495 [DEBUG] [internal.handler.UpnpRendererHandler] - Update server UPnP Server channel PLAY with state upnpcontrol:upnprenderer:01c78e72-f10f-e21f-dbd6-e45f0190013a:control from renderer UpnpRenderer
==> /var/log/openhab/events.log <==
2023-02-24 12:20:30.496 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Duration' changed from 0 s to 212 s
2023-02-24 12:20:30.505 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UPnPServer_Fernbedienung' changed from PAUSE to PLAY
2023-02-24 12:20:30.506 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Fernbedienung' changed from PAUSE to PLAY
==> /var/log/openhab/openhab.log <==
2023-02-24 12:20:31.524 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackMetaData with value <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="ab57ea26b21a51ee3c89" parentID="7bdcf62f942e7fd26bdf" restricted="true"><dc:title>Come Around</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><upnp:album>Rock-Motivation</upnp:album><upnp:albumArtURI>http://192.168.0.33:32469/proxy/9ccb6767f0cb27edd9c1/albumart.jpg</upnp:albumArtURI><dc:creator>Various Artists</dc:creator><upnp:artist>Various Artists</upnp:artist><dc:publisher></dc:publisher><upnp:genre>Unknown</upnp:genre><upnp:originalTrackNumber>16</upnp:originalTrackNumber></item></DIDL-Lite> from service AVTransport
2023-02-24 12:20:31.525 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsTime with value 0:00:02 from service AVTransport
2023-02-24 12:20:31.526 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelCount with value 0 from service AVTransport
2023-02-24 12:20:31.527 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable RelTime with value 0:00:02 from service AVTransport
2023-02-24 12:20:31.531 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackURI with value http://192.168.0.33:32469/object/ab57ea26b21a51ee3c89/file.mp3 from service AVTransport
2023-02-24 12:20:31.534 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable AbsCount with value 0 from service AVTransport
2023-02-24 12:20:31.535 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable Track with value 1 from service AVTransport
2023-02-24 12:20:31.536 [TRACE] [internal.handler.UpnpRendererHandler] - UPnP device UpnpRenderer received variable TrackDuration with value 0:03:32 from service AVTransport
==> /var/log/openhab/events.log <==
2023-02-24 12:20:31.542 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'UpnpRenderer_Track_Position' changed from 0 s to 2 s

I played a bit with the Intel Dev Tools Renderer to separate specific issues of my renderer and general ones.
My renderer seems to go from <TransportState val="STOPPED"/> to <TransportState val="PLAYING"/> without <TransportState val="TRANSITIONING"/>.
Can that cause any issues?

Fyi using my renderer I noticed that the playback triggered through URI channel or an action is not always starting immediately as the docs say. I can workaround this by a stop>set uri>play sequence in my rule. Probably its related to the above?

I don’t think that is an issue. The binding does not make assumptions on this, even filters for renderers that send multiple stop commands.

I am not sure if it is related. Again, when that happens, logs would be usefult to debug.

Analyzing the two logs, there is one difference. The following line does not appear in the logs when the problem happens:

2023-02-24 12:20:28.526 [TRACE] [internal.handler.UpnpRendererHandler] - Ready to play 'Come Around' from queue

This is just before the binding gives the play command for the next song. I am checking for some statuses before giving that command, and if not OK, the command is not given. I don’t see yet how this happens, but I would appreciate if you could run with a test jar for 3.x. I created with an extra log statement, that shows me this check. The jar is here. I would be interested to see what is in the log when the next song fails.
I don’t think it is your renderer. From what I can see, the logs are what I expect, except for this one line and no play being called.
BTW: the shuffle issue is also solved in this jar.

@yhd I loaded a new version of the test jar file. This one tries to discover and add subdevices. I cannot test myself, so if you are willing to go the extra mile, test and give me feedback, I can try to get it working.

I will get some logs but I do not have much spare time atm.

I just set up all my devices to an openhab-only usage without bubbleupnp to minimize side effects.