search

StevenLooman / async_upnp_client

Async UPnP Client for Python
Other
46 stars 37 forks source link

async_upnp_client.client.UpnpError: Invalid response #68

Closed jacobdmoore closed 3 years ago

jacobdmoore commented 3 years ago

I'm trying to connect my stereo (Klipsch Powergate) to HA via dlna_dmr. I get an unexpected response from the Klipsch during dlna_dmr setup. I opened an identical issue in Home Assistant Core (https://github.com/home-assistant/core/issues/49258), but thought I'd post here to see if you can provide some recommended troubleshooting tips to see if this is a problem specific to my dlna player or not. You can find the error, some more detailed log info, and the description xml file from the Klipsch in that link.

Some information that may or may not be helpful:

StevenLooman commented 3 years ago

Thank you for this issue @jacobdmoore. I have replied in the home assistant issue.

StevenLooman commented 3 years ago

Any luck @jacobdmoore?

jacobdmoore commented 3 years ago

I think so. Here's the response from the support team in charge of their DMR tech (PhorusSupport@xperi.com):

I’ll file it and see if we can implement the change for an improvement. I’m going to try to see if we can fit it into this upcoming update if possible, at which point it would only take about a month.

My worry is that there could be another bug further down the pipeline that I haven't encountered yet, which would require contacting them again and repeating this process...could be pretty drawn out in time. Do you have any guidance on checking the subsequent steps in the process for compatibility?

StevenLooman commented 3 years ago

Great! I do have a fix as well, just to make it more compatible with broken devices, but I want to test it a bit more before I'll release it.

jacobdmoore commented 3 years ago

Looking forward to it. Let me know when this version is released and I'll check back to see if it solves my issue. Thanks, Steven!

StevenLooman commented 3 years ago

The PR was merged. I expect it to be available in home assistant in a 2021.6 beta or 2021.6 itself. Free free to post any feedback here, or open a new issue when the problem isn't solved.

jacobdmoore commented 3 years ago

Hey Steven, thanks for your work on the new update. The new software update has not yet rolled out from Klipsch yet, so I was hoping the new version of async_upnp_client in HA 2021.6 might solve my issue in the meantime. Unfortunately, I'm receiving the same error message:

Source: components/dlna_dmr/media_player.py:202
Integration: Media player (documentation, issues)
First occurred: 8:14:42 AM (1 occurrences)
Last logged: 8:14:42 AM

dlna_dmr: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 432, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 550, in async_device_update
    await task
  File "/usr/src/homeassistant/homeassistant/components/dlna_dmr/media_player.py", line 202, in async_update
    await self._device.async_update()
  File "/usr/local/lib/python3.8/site-packages/async_upnp_client/profiles/dlna.py", line 210, in async_update
    await self._async_poll_transport_info()
  File "/usr/local/lib/python3.8/site-packages/async_upnp_client/profiles/dlna.py", line 223, in _async_poll_transport_info
    result = await action.async_call(InstanceID=0)
  File "/usr/local/lib/python3.8/site-packages/async_upnp_client/client.py", line 561, in async_call
    response_args = self.parse_response(
  File "/usr/local/lib/python3.8/site-packages/async_upnp_client/client.py", line 622, in parse_response
    return self._parse_response_args(service_type, xml)
  File "/usr/local/lib/python3.8/site-packages/async_upnp_client/client.py", line 642, in _parse_response_args
    raise UpnpError(
async_upnp_client.client.UpnpError: Invalid response: <ns0:Envelope xmlns:ns0="http://schemas.xmlsoap.org/soap/envelope/" xmlns:ns1="urn:upnp-org:serviceId:AVTransport" ns0:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><ns0:Body>
<ns1:GetTransportInfoResponse>
<CurrentTransportState>STOPPED</CurrentTransportState>
<CurrentTransportStatus>OK</CurrentTransportStatus>
<CurrentSpeed>1</CurrentSpeed>
</ns1:GetTransportInfoResponse>
</ns0:Body> </ns0:Envelope>

If you'd like, I can dig into the more detailed logs, but it appears to be the same issue as before. Is there any additional troubleshooting on my end you might recommend?

StevenLooman commented 3 years ago

Thank you for re-opening the issue. I think this is more of the same problem. Either I didn't fix it properly the first time, or it is more of the same problem but causing it to fail somewhere else. I'll investigate and let you know.

StevenLooman commented 3 years ago

Looking at the response, it seems the Klipsch Powergate does something non-stardard again:

<ns0:Envelope xmlns:ns0="http://schemas.xmlsoap.org/soap/envelope/"
              xmlns:ns1="urn:upnp-org:serviceId:AVTransport"
              ns0:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
    <ns0:Body>
        <ns1:GetTransportInfoResponse>
            <CurrentTransportState>STOPPED</CurrentTransportState>
            <CurrentTransportStatus>OK</CurrentTransportStatus>
            <CurrentSpeed>1</CurrentSpeed>
        </ns1:GetTransportInfoResponse>
    </ns0:Body>
</ns0:Envelope>

The namespace aliased to ns1 is off: urn:upnp-org:serviceId:AVTransport. In the UPnP Device Architecture document, section 3.2.2 Control: Action: Response/page 50 the proper namespace is given:

<?xml version="1.0"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:actionNameResponse xmlns:u="urn:schemas-upnp-org:service:serviceType:v">
      <argumentName>out arg value</argumentName>
      other out args and their values go here, if any
    </u:actionNameResponse>
  </s:Body>
</s:Envelope>

Note the urn:schemas-upnp-org:service:serviceType:v. In this case it should be: urn:schemas-upnp-org:service:AVTransport:1.

Given that the namespace could be anything, it seems hard to fix this in a proper way. A way would be to add a mapping table to apply fixes for (parts of) namespaces, but I'm afraid this would be a never-ending story. Or a different way would be to ignore namespaces altogether.

The last fix was just stripping a part of the namespace, which was a bit easier (though perhaps not the best option for this.) Not sure if this library should support as many devices as possible, or it should stick to the standard in a reasonable way.

I'll take a further look later this day, hopefully.

StevenLooman commented 3 years ago

I was hoping Travis CI would run some tests for me so I can see if this works for older versions of Python as well, but it seems things have changed at Travis. I have created a ticket, hopefully they'll respond soon.

The change I've added ignores any namespaces in the action-response in non-strict mode. Non-strict mode is what Home Assistant uses, so hopefully this is a better fix for the Klipsch Powergate and other devices as well.

My only doubt is that the fix works for older Python versions, hence the need for Travis CI which does CI using newer and older Python versions. I'll post a new comment once I have a response. This response in an older Python ticket notes that lxml allows one to use {*} as a namespace, effectively ignoring namespaces. Hopefully this works for older Python versions as well, as it does work on my installation (Python 3.9 on Ubuntu 20.04)

jacobdmoore commented 3 years ago

That wildcard namespace would do the job! Hopefully you hear back from Travis CI about it. In the meantime, I'll update Klipsch support with the new information you found. Thank you for your diligence.

StevenLooman commented 3 years ago

The good news is that Travis CI was generous enough to give me more credits, thank you Travis CI!

The bad news is that the build broke: https://travis-ci.com/github/StevenLooman/async_upnp_client/builds/228240283. Though, all of the failed tests are due to Python 3.6 not having the function asyncio.get_running_loop(), which is available since Python 3.7.

Either Python 3.6 support is dropped (which is officially supported until the end of this year, see Status of Python branches) from async_upnp_client, or it uses asyncio.get_event_loop() instead.

@chishm what do you think? I wouldn't mind using get_event_loop() for now, and move to get_running_loop() in the future.

chishm commented 3 years ago

@StevenLooman Going with what already exists, most of the code currently uses asyncio.get_event_loop() with only two new places using asyncio.get_running_loop(). So I'd be happy with using asyncio.get_event_loop() everywhere for now.

Another thing to note is that Home Assistant dropped support for Python 3.7 in release 2021.2.0, which means many users of this library are already on at least Python 3.8. Perhaps that can ease your maintenance burden?

Edit: I've also installed Pythons 3.6 - 3.9 on my dev machine, so hopefully this won't slip past me again.

StevenLooman commented 3 years ago

Thank you for your response @chishm.

Another thing to note is that Home Assistant dropped support for Python 3.7 in release 2021.2.0, which means many users of this library are already on at least Python 3.8. Perhaps that can ease your maintenance burden?

Good point. The thing is mostly that I don't know who is using async_upnp_client in what context. I doubt there are many users/uses outside of Home Assistant, but still... lets postpone this decision for now. ;)

For now lets use asyncio.get_event_loop(), such that Python 3.6 keeps working. I'll update this soon, probably later today.

StevenLooman commented 3 years ago

Travis CI build is ok now. I plan to wait until ~20th of June and then create a new release + PR for Home Assistant to update. If @chishm has any other PRs ready those changes can be included. If not, then I'll create another release later on (so no rush!)

jacobdmoore commented 3 years ago

If you want me to check if these changes fix the issue with my media player before the PR, let me know what I should do if that would be of any help.

StevenLooman commented 3 years ago

I'll create a new release this weekend and a PR for home assistant to update. Hopefully you'll be able to test this then.

If you're able to test this beforehand, feel free to do so!

StevenLooman commented 3 years ago

@jacobdmoore I've merged it into home assistant/dev. Not sure if you're able to directly install dev itself, but there is progress...

StevenLooman commented 3 years ago

This should help: https://www.home-assistant.io/common-tasks/supervised/#run-a-development-version Although I cannot recommend that you do this, see the warning.

jacobdmoore commented 3 years ago

I was planning on checking it out possibly in a virtual instance of Home Assistant some time this week if that doesn't prove too difficult. May also just backup and temporarily join dev to test and then go back to the stable release. I'll let you know what I find out.

jacobdmoore commented 3 years ago

Progress! Ran version 2021.7.0.dev20210621 and the good news is that my stereo is now successfully added as an entity (media_player.klipsch_powergate) whether manually specifying the dlna_dmr configuration or using discovery with dlna_dmr enabled in the config.yaml file. After checking the functionality briefly, I noticed a few things:

I think there might be even more issues to uncover with more investigation, but I am not sure if this issue is the right place to continue this. Should I open a new one elsewhere or do you think we should keep debugging here? Any tips on what I should look for to ensure proper functionality now that dlna_dmr successfully adds the entity? I have some log files I can look through but need help finding the needle in the haystack.

StevenLooman commented 3 years ago

First of all, I'm not using the dlna_dmr-integration myself anymore. Your mileage may vary. Also, as you've already noticed, not all devices appear to be as fully DLNA/DMR compatible as they claim. Not to say your device is broken, it does appear to work for you.

@chishm is also busy working on the DLNA side and already provided many improvements to async_upnp_client. I think we'll see even more improvements further down the line, not just to this library, but also to Home Assistant. I think lots of problems will be solved.

Points 1 & 2: At first glance I would say that you're using a different URL to the device description (a XML file describing the device, with its services etc) for manual vs discovery. You can enable logging in home assistant by adding this to your configuration.yaml file:

logger:
  default: info
  logs:
    homeassistant.components.dlna_dmr: debug
    async_upnp_client: debug
    async_upnp_client.search: error
    async_upnp_client.ssdp: error
    async_upnp_client.traffic: error
    async_upnp_client.device_updater: error

This will show the used URL in the Home Assistant Logs.

Point 3: I think enabling logging will provide more information. I'm unsure what is happening. Currently the device is polled regularly (every 5 seconds?) about what it is playing. Perhaps the Klipsch has more non-standard responses which are not parsed properly.

Point 4: Usually Text To Speech (TTS) is something you can try. Note that some devices are very picky about the source it wants to play from. My Samsung TV wants specific DLNA-headers from the HTTP-source to play from. TTS does not work through home assistant as it does not provide those headers.

StevenLooman commented 3 years ago

Great news by the way that we're getting somewhere!

StevenLooman commented 3 years ago

Didn't really read the last part of your comment yesterday.

I think there might be even more issues to uncover with more investigation, but I am not sure if this issue is the right place to continue this. Should I open a new one elsewhere or do you think we should keep debugging here?

Here is fine for now.

Any tips on what I should look for to ensure proper functionality now that dlna_dmr successfully adds the entity? I have some log files I can look through but need help finding the needle in the haystack.

Enable the logging as proposed yesterday. Then... I just noticed I can't really find logging for what we're looking for (information about basic device initialization.) You can turn on additional UPnP-traffic logging, which dumps all traffic from/to the device. Update your logger configuration to this:

logger:
  default: warning
  logs:
    homeassistant.components.dlna_dmr: debug
    async_upnp_client: debug
    async_upnp_client.search: error
    async_upnp_client.ssdp: error
    async_upnp_client.traffic: error
    async_upnp_client.traffic.upnp: debug
    async_upnp_client.device_updater: error

This will show things like:

2021-06-24 21:39:07 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
GET http://192.168.178.19:1400/xml/SystemProperties1.xml

There will be lots of logging as this will log the contents of the requests as well, which will be bulky. Try to see if you find any differences between discovery and manual set up.

Also, this will mostly disable logging for other parts of home assistant, so be sure to remove this once you've got the data.

jacobdmoore commented 3 years ago

Thanks, Steven! This paves a very clear path forward for me. I'll post here as soon as I have some more specific information from the logs or anything else.

jacobdmoore commented 3 years ago

After further testing, the differences I initially saw in using manual vs. discovery have not been reproducible nor have there been differences in the logs that I've seen, so we can disregard that. I've also been able to play TTS through the Klipsch with either method successfully. However, the other issue (the player not updating with the current media playing) still persists.

With the extra logging, I was not able to find a SystemProperties file. Here are the files that were accessed according to the logs:

Further non-standard responses from the Klipsch seem likely to be the culprit. Do you think any of these files could hold clues as to what exactly they are? If so, I can send the contents of them.

StevenLooman commented 3 years ago

The files accessed is the normal initialization of the device. async_upnp_client reads the device description file (description.xml in your case) from which it gets information about your device. Also, it sees four services in your case. Each of those services has its own service description file which is downloaded and read. This all looks fine and standard. For now I don't think these files will provide any clues.

Normally the component polls the DLNA/DMR device every few seconds to get the current state. This is done here: https://github.com/home-assistant/core/blob/dev/homeassistant/components/dlna_dmr/media_player.py#L202

If this polling fails the device is marked as unavailable and a DEBUG log message generated: Device unavailable. If this succeeds it should set the state to playing if it is actually playing something, or set it to idle if not. This polling should generate regular traffic which should show up in the logging. Do you see either of the above in the logs? I'm interested in the raw request and response from the polling.

StevenLooman commented 3 years ago

An example of a request + response is as follows:

Request:

2021-07-05 20:11:21 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.178.19:1400/MediaRenderer/AVTransport/Control
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo"
Host: 192.168.178.19:1400
Content-Type: text/xml; charset="utf-8"
Content-Length: 295
<?xml version="1.0"?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
<s:Body>
  <u:GetTransportInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
    <InstanceID>0</InstanceID>
  </u:GetTransportInfo>
</s:Body>
</s:Envelope>

Response:

2021-07-05 20:11:21 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 399
Content-Type: text/xml; charset="utf-8"
EXT: 
Server: Linux UPnP/1.0 Sonos/63.2-89260 (ZPS21)
Connection: close

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body>
  <u:GetTransportInfoResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
    <CurrentTransportState>PLAYING</CurrentTransportState>
    <CurrentTransportStatus>OK</CurrentTransportStatus>
    <CurrentSpeed>1</CurrentSpeed>
  </u:GetTransportInfoResponse>
</s:Body>
</s:Envelope>

I've formatted the XML a bit to make it more readable.

Actually, another request/response is done after this. This is to get information about the current media being played. For example, request:

2021-07-05 20:12:31 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.178.19:1400/MediaRenderer/AVTransport/Control
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo"
Host: 192.168.178.19:1400
Content-Type: text/xml; charset="utf-8"
Content-Length: 293
<?xml version="1.0"?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
<s:Body>
  <u:GetPositionInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
    <InstanceID>0</InstanceID>
  </u:GetPositionInfo>
</s:Body>
</s:Envelope>

2021-07-05 20:12:31 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 1210
Content-Type: text/xml; charset="utf-8"
EXT: 
Server: Linux UPnP/1.0 Sonos/63.2-89260 (ZPS21)
Connection: close

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body>
  <u:GetPositionInfoResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
    <Track>1</Track>
    <TrackDuration>0:00:00</TrackDuration>
    <TrackMetaData>&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:r=&quot;urn:schemas-rinconnetworks-com:metadata-1-0/&quot; xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot;&gt;&lt;item id=&quot;-1&quot; parentID=&quot;-1&quot; restricted=&quot;true&quot;&gt;&lt;res protocolInfo=&quot;x-rincon-mp3radio:*:*:*&quot;&gt;x-rincon-mp3radio://http://stream.player.arrow.nl/arrow&lt;/res&gt;&lt;r:streamContent&gt;HERMAN BROOD - NEVER BE CLEVER&lt;/r:streamContent&gt;&lt;dc:title&gt;arrow&lt;/dc:title&gt;&lt;upnp:class&gt;object.item&lt;/upnp:class&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;
    </TrackMetaData>
    <TrackURI>x-rincon-mp3radio://http://stream.player.arrow.nl/arrow</TrackURI>
    <RelTime>0:01:05</RelTime>
    <AbsTime>NOT_IMPLEMENTED</AbsTime>
    <RelCount>2147483647</RelCount>
    <AbsCount>2147483647</AbsCount>
  </u:GetPositionInfoResponse>
</s:Body>
</s:Envelope>

In this case it is a Sonos device (actually, IKEA Tradfri) playing a stream.

StevenLooman commented 3 years ago

I also remember that my Samsung TV only reports (via DLNA/DMR) it is playing something when the stream is played from a DLNA /DMS device. If, for example, the TV is playing something from Netflix it will not report it is playing anything. (Understandable, as the TV probably does not 'know' what the Netflix app is doing.)

So perhaps your device is doing something like this as well. Do you get any information about what it is doing when using TTS?

jacobdmoore commented 3 years ago

Polling appears to be working based on the lack of "Device unavailable" messages. Additionally, if I send TTS a long enough message, the icon in the frontend will glow yellow as such (and that's the only difference as far as I can tell): image

I looked through the logs for the traffic you requested. Please let me know if I missed any info, but I think I got what I needed from the logs. Here's an AVTransport request:

2021-07-05 14:07:32 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 295
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:GetTransportInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID></u:GetTransportInfo></s:Body></s:Envelope>

and the corresponding response:

2021-07-05 14:07:34 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 403
Accept-Ranges: bytes
Content-Type: text/xml; charset="utf-8"
Date: Thu, 31 Jan 2030 23:29:56 GMT
EXT: 
Server: Linux/2.6.34, UPnP/1.0, Portable SDK for UPnP devices/1.6.25
X-User-Agent: redsonic

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body>
<u:GetTransportInfoResponse xmlns:u="urn:upnp-org:serviceId:AVTransport">
<CurrentTransportState>STOPPED</CurrentTransportState>
<CurrentTransportStatus>OK</CurrentTransportStatus>
<CurrentSpeed>1</CurrentSpeed>
</u:GetTransportInfoResponse>
</s:Body> </s:Envelope>

And here's a request for GetPositionInfo (which I've only been able to get by using TTS from Home Assistant):

2021-07-05 14:08:24 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 293
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:GetPositionInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID></u:GetPositionInfo></s:Body></s:Envelope>

And the response:

2021-07-05 14:08:44 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 1242
Accept-Ranges: bytes
Content-Type: text/xml; charset="utf-8"
Date: Thu, 31 Jan 2030 23:31:06 GMT
EXT: 
Server: Linux/2.6.34, UPnP/1.0, Portable SDK for UPnP devices/1.6.25
X-User-Agent: redsonic

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body>
<u:GetPositionInfoResponse xmlns:u="urn:upnp-org:serviceId:AVTransport">
<Track>0</Track>
<TrackDuration>00:00:00</TrackDuration>
<TrackURI>http://192.168.0.236:8123/api/tts_proxy/d595afa5f0a4282342506bc7f1106e6acebff53b_en_-_google_translate.mp3</TrackURI>
<TrackMetaData>&lt;DIDL-Lite xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot; xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns:sec=&quot;http://www.sec.co.kr/&quot;&gt;&lt;item id=&quot;0&quot; parentID=&quot;-1&quot; restricted=&quot;false&quot;&gt;&lt;dc:title&gt;Home Assistant&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem&lt;/upnp:class&gt;&lt;res protocolInfo=&quot;http-get:*:audio/mpeg:*&quot;&gt;http://192.168.0.236:8123/api/tts_proxy/d595afa5f0a4282342506bc7f1106e6acebff53b_en_-_google_translate.mp3&lt;/res&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;</TrackMetaData>
<RelTime>00:00:32</RelTime>
<AbsTime>00:00:32</AbsTime>
<RelCount>2147483647</RelCount>
<AbsCount>2147483647</AbsCount>
</u:GetPositionInfoResponse>
</s:Body> </s:Envelope>
2021-07-05 14:08:54 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 295
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:GetTransportInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID></u:GetTransportInfo></s:Body></s:Envelope>

Note that indeed I have been trying to get info from music playing via DLNA/DMS devices (the Klipsch app or Spotify, which both recognize the player as something to cast to via the same input that TTS plays through). I also tried to play 04 No Rain.mp3 via the Media player: Play media service using Home Assistant, but same problem. Here's the corresponding traffic, which might be useful (I apologize in advance for the perhaps superfluous information!):

2021-07-05 14:09:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr.media_player] Playing media: music, \\192.168.0.236\media\04 No Rain.mp3, {'extra': {}}
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.profiles.dlna] Set transport uri: \\192.168.0.236\media\04 No Rain.mp3
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
HEAD \\192.168.0.236\media\04 No Rain.mp3
GetContentFeatures.dlna.org: 1

2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#SetAVTransportURI"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 888
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:SetAVTransportURI xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID>
<CurrentURI>\\192.168.0.236\media\04 No Rain.mp3</CurrentURI>
<CurrentURIMetaData>&lt;DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:sec="http://www.sec.co.kr/"&gt;&lt;item id="0" parentID="-1" restricted="false"&gt;&lt;dc:title&gt;Home Assistant&lt;/dc:title&gt;&lt;upnp:class&gt;object.item.audioItem&lt;/upnp:class&gt;&lt;res protocolInfo="http-get:*:audio/mpeg:*"&gt;\\192.168.0.236\media\04 No Rain.mp3&lt;/res&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;</CurrentURIMetaData></u:SetAVTransportURI></s:Body></s:Envelope>

2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 262
Accept-Ranges: bytes
Content-Type: text/xml; charset="utf-8"
Date: Thu, 31 Jan 2030 23:31:42 GMT
EXT: 
Server: Linux/2.6.34, UPnP/1.0, Portable SDK for UPnP devices/1.6.25
X-User-Agent: redsonic

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body>
<u:SetAVTransportURIResponse xmlns:u="urn:upnp-org:serviceId:AVTransport"></u:SetAVTransportURIResponse>
</s:Body> </s:Envelope>
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#Play"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 288
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:Play xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID>
<Speed>1</Speed></u:Play></s:Body></s:Envelope>

2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 236
Accept-Ranges: bytes
Content-Type: text/xml; charset="utf-8"
Date: Thu, 31 Jan 2030 23:31:42 GMT
EXT: 
Server: Linux/2.6.34, UPnP/1.0, Portable SDK for UPnP devices/1.6.25
X-User-Agent: redsonic

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body>
<u:PlayResponse xmlns:u="urn:upnp-org:serviceId:AVTransport"></u:PlayResponse>
</s:Body> </s:Envelope>
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
POST http://192.168.0.207:49152/upnp/control/AVTransport1
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo"
Host: 192.168.0.207:49152
Content-Type: text/xml; charset="utf-8"
Content-Length: 295
<?xml version="1.0"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:GetTransportInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID></u:GetTransportInfo></s:Body></s:Envelope>

2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.aiohttp] Received request: <BaseRequest NOTIFY /notify >
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Incoming request:
NOTIFY
Host: 192.168.0.236:8301
Content-Type: text/xml; charset="utf-8"
Content-Length: 1644
NT: upnp:event
NTS: upnp:propchange
SID: uuid:ce41ec9e-7b0b-11f5-be87-996b59e2d8fb
SEQ: 8

<e:propertyset xmlns:e="urn:schemas-upnp-org:event-1-0">
<e:property>
<LastChange>&lt;?xml version=&quot;1.0&quot;?&gt;
&lt;Event xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/AVT/&quot;&gt;
&lt;InstanceID val=&quot;0&quot;&gt;
&lt;A_ARG_TYPE_SeekMode val=&quot;TRACK_NR&quot;&gt;&lt;/A_ARG_TYPE_SeekMode&gt;
&lt;CurrentTrackMetaData val=&quot;&amp;lt;DIDL-Lite xmlns=&amp;quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&amp;quot; xmlns:dc=&amp;quot;http://purl.org/dc/elements/1.1/&amp;quot; xmlns:upnp=&amp;quot;urn:schemas-upnp-org:metadata-1-0/upnp/&amp;quot; xmlns:sec=&amp;quot;http://www.sec.co.kr/&amp;quot;&amp;gt;&amp;lt;item id=&amp;quot;0&amp;quot; parentID=&amp;quot;-1&amp;quot; restricted=&amp;quot;false&amp;quot;&amp;gt;&amp;lt;dc:title&amp;gt;Home Assistant&amp;lt;/dc:title&amp;gt;&amp;lt;upnp:class&amp;gt;object.item.audioItem&amp;lt;/upnp:class&amp;gt;&amp;lt;res protocolInfo=&amp;quot;http-get:*:audio/mpeg:*&amp;quot;&amp;gt;\\192.168.0.236\media\04 No Rain.mp3&amp;lt;/res&amp;gt;&amp;lt;/item&amp;gt;&amp;lt;/DIDL-Lite&amp;gt;&quot;&gt;&lt;/CurrentTrackMetaData&gt;
&lt;CurrentTrackURI val=&quot;\\192.168.0.236\media\04 No Rain.mp3&quot;&gt;&lt;/CurrentTrackURI&gt;
&lt;CurrentTransportActions val=&quot;Stop,Pause,Seek,Next,Previous&quot;&gt;&lt;/CurrentTransportActions&gt;
&lt;NumberOfTracks val=&quot;1&quot;&gt;&lt;/NumberOfTracks&gt;
&lt;TransportState val=&quot;TRANSITIONING&quot;&gt;&lt;/TransportState&gt;
&lt;AVTransportURI val=&quot;\\192.168.0.236\media\04 No Rain.mp3&quot;&gt;&lt;/AVTransportURI&gt;
&lt;/InstanceID&gt;
&lt;/Event&gt;
</LastChange>
</e:property>
</e:propertyset>

2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending response: HTTPStatus.OK
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.aiohttp] NOTIFY response status: HTTPStatus.OK
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Got response:
200
Content-Length: 409
Accept-Ranges: bytes
Content-Type: text/xml; charset="utf-8"
Date: Thu, 31 Jan 2030 23:31:42 GMT
EXT: 
Server: Linux/2.6.34, UPnP/1.0, Portable SDK for UPnP devices/1.6.25
X-User-Agent: redsonic

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body>
<u:GetTransportInfoResponse xmlns:u="urn:upnp-org:serviceId:AVTransport">
<CurrentTransportState>TRANSITIONING</CurrentTransportState>
<CurrentTransportStatus>OK</CurrentTransportStatus>
<CurrentSpeed>1</CurrentSpeed>
</u:GetTransportInfoResponse>
</s:Body> </s:Envelope>
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.aiohttp] Received request: <BaseRequest NOTIFY /notify >
2021-07-05 14:09:20 DEBUG (MainThread) [async_upnp_client.traffic.upnp] Incoming request:
NOTIFY
Host: 192.168.0.236:8301
Content-Type: text/xml; charset="utf-8"
Content-Length: 1514
NT: upnp:event
NTS: upnp:propchange
SID: uuid:ce41ec9e-7b0b-11f5-be87-996b59e2d8fb
SEQ: 9

<e:propertyset xmlns:e="urn:schemas-upnp-org:event-1-0">
<e:property>
<LastChange>&lt;?xml version=&quot;1.0&quot;?&gt;
&lt;Event xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/AVT/&quot;&gt;
&lt;InstanceID val=&quot;0&quot;&gt;
&lt;CurrentTransportActions val=&quot;Play,Stop,Seek,X_DLNA_SeekTime,Next,Previous&quot;&gt;&lt;/CurrentTransportActions&gt;
&lt;TransportState val=&quot;PAUSED_PLAYBACK&quot;&gt;&lt;/TransportState&gt;
&lt;CurrentTrackMetaData val=&quot;&amp;lt;DIDL-Lite xmlns=&amp;quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&amp;quot; xmlns:dc=&amp;quot;http://purl.org/dc/elements/1.1/&amp;quot; xmlns:upnp=&amp;quot;urn:schemas-upnp-org:metadata-1-0/upnp/&amp;quot; xmlns:sec=&amp;quot;http://www.sec.co.kr/&amp;quot;&amp;gt;&amp;lt;item id=&amp;quot;0&amp;quot; parentID=&amp;quot;-1&amp;quot; restricted=&amp;quot;false&amp;quot;&amp;gt;&amp;lt;dc:title&amp;gt;Home Assistant&amp;lt;/dc:title&amp;gt;&amp;lt;upnp:class&amp;gt;object.item.audioItem&amp;lt;/upnp:class&amp;gt;&amp;lt;res protocolInfo=&amp;quot;http-get:*:audio/mpeg:*&amp;quot;&amp;gt;\\192.168.0.236\media\04 No Rain.mp3&amp;lt;/res&amp;gt;&amp;lt;/item&amp;gt;&amp;lt;/DIDL-Lite&amp;gt;&quot;&gt;&lt;/CurrentTrackMetaData&gt;
&lt;CurrentTrackURI val=&quot;\\192.168.0.236\media\04 No Rain.mp3&quot;&gt;&lt;/CurrentTrackURI&gt;
&lt;AVTransportURI val=&quot;\\192.168.0.236\media\04 No Rain.mp3&quot;&gt;&lt;/AVTransportURI&gt;
&lt;/InstanceID&gt;
&lt;/Event&gt;
</LastChange>
</e:property>
</e:propertyset>
StevenLooman commented 3 years ago

Please note that DLNA/DMR and DLNA/DMS are different things. DMR is the Digital Media Renderer (i.e., something that plays media, such as your Klipsch Powergate.) DMS is the Digital Media Server, the device which serves the data to the DMR, which can be a NAS or a regular computer running DMS software. There is also a DMP, Digital Media Player, which connects the DMS and DMR together.

I see that you're trying to play something from your (Windows sharing) network: \\192.168.0.236\media\04 No Rain.mp3. I'm unsure if your device supports playing from a network location. A URL to media on a DMS usually looks something like this: http://192.168.1.2:8200/MediaItems/264.mkv (in this example, some video file served by MiniDLNA on my network.)

My suggestion is to install/enable some DLNA/DMS software. Windows 10 seems to include it out of the box: https://www.minitool.com/news/dlna-server.html (First hit when searching on "windows dlna server", and assuming you're using Windows 10.) Then, use VLC to find the server and get a URL to a music track which you are sharing. See https://www.vlchelp.com/access-media-upnp-dlna/ for some information. Right mouse click on the track and choosing Information gives the Location to the file. Try playing that location via home assistant and see if that works.

jacobdmoore commented 3 years ago

Sorry for the delay, been battling a flu. That does work! Was able to play music through the stereo following those steps. Any further steps you want me to check there, the logging for example?

Now wondering about if it would be possible to show other media streaming through it (e.g., Spotify). Is this the sort of thing where if it's not showing up already, it's likely due to something non-standard on Klipsch's end?

StevenLooman commented 3 years ago

Hope you are alright now! Don't worry about any delays.

Now wondering about if it would be possible to show other media streaming through it (e.g., Spotify). Is this the sort of thing where if it's not showing up already, it's likely due to something non-standard on Klipsch's end?

This is most likely something on Klipsch's end. I think, when you play something from Spotify, another 'app' is started internally. DLNA/DMR is probably another 'app' which runs internally. I can imagine not every app provides information about what it is currently playing via DLNA.

My TV (Samsung) does the same. When starting/playing something via DLNA I can see information about the track/video/... it is playing. When playing something via the Netflix app, or watching TV via cable, the TV reports itself as idle via DLNA. Understandable, why would an app leak information about this? (And even, why would the app provide DLNA functionality at all if it has nothing to do with DLNA?) (To be fair, I was a bit disappointed when I first discovered/realized this, but it is logical...)

On the other hand, Sonos does use the DLNA protocol extensively and reports track data when playing via Spotify, streaming radio stations, TuneIn (radio streaming service) and (of course) DLNA itself.

So it is probably something the device manufacturer chooses. In your case, I think your best bet is to contact Klipsch and ask what their stance on this is?

jacobdmoore commented 3 years ago

Asked Klipsch "Is it possible to retrieve information through DLNA about a currently-playing Spotify track when it is cast from the Spotify app to the Powergate?" Response: "I think this may not be possible, since it’s separate protocols and we don’t forward the information over to the DLNA implementation because it would likely create some broadcast conflicts."

I learned from them that the Spotify casting occurs through Spotify Connect, which I have been able to use to cast Spotify music to the Powergate via HA.

So seems like the end of the road here! With your help on this issue and with Spotify Connect, now I can do most of the things I set out to be able to do via HA with the Powergate. I think the rest comes from me working with the Powergate entity in HA. Thanks so much for your work, Steven!

StevenLooman commented 3 years ago

Great to hear that Klipsch actually responded with a sensible answer and I'm glad that you were able to get what you need through Spotify Connect and have a way forward.