[mythtv-users] Accessing Mythbackend via UPNP

Fri Feb 13 22:31:16 UTC 2015

On 13/02/15 19:58, David Hampton wrote:
> On Fri, 2015-02-13 at 17:25 +0000, John Pilkington wrote:
>> On 13/02/15 15:43, David Hampton wrote:
>>> Hi,
>>>
>>> I'm trying to use UPNP for the first time, and am unable to locate my
>>> myth backend via the UPNP protocol.  When I run wireshark on my local
>>> machine I see frequent MDNS and SSDP messages from a file server, but I
>>> only ever see an occasional MDNS message from the myth backend.  I tried
>>> enabling upnp logging (-v none,upnp --loglevel debug) on the backend,
>>> and myth believes its sending SSDP notification messages, but wireshark
>>> never sees those messages hit the wire.  Here a log excerpt from a
>>> startup with only upnp logging enabled:
>>>
>>> 2015-02-12 23:07:04.750213 I  SSDP::EnableNotifications() - sending NTS_byebye
>>> 2015-02-12 23:07:04.750269 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : upnp:rootdevice : uuid:::upnp:rootdevice
>>> 2015-02-12 23:07:04.903074 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : uuid: : uuid:
>>> 2015-02-12 23:07:04.923967 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 :  : uuid:::
>>> 2015-02-12 23:07:05.010700 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1 : uuid:::urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1
>>> 2015-02-12 23:07:05.026723 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:1 : uuid:::urn:schemas-upnp-org:service:ConnectionManager:1
>>> 2015-02-12 23:07:05.101670 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:1 : uuid:::urn:schemas-upnp-org:service:ContentDirectory:1
>>> 2015-02-12 23:07:05.111431 I  SSDP::EnableNotifications() - sending NTS_alive
>>> 2015-02-12 23:07:05.111446 I  Starting TaskQueue Thread...
>>> 2015-02-12 23:07:05.111554 I  TaskQueue Thread Started.
>>> 2015-02-12 23:07:05.111565 I  SSDP::EnableNotifications() - Task added to UPnP queue
>>> 2015-02-12 23:07:05.111570 D  UPnp::Start - Returning
>>> 2015-02-12 23:07:05.111841 I  TaskQueue Thread Running.
>>> 2015-02-12 23:07:05.111942 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : upnp:rootdevice : uuid:::upnp:rootdevice
>>> 2015-02-12 23:07:05.123822 I  MediaServer:Init:End
>>> 2015-02-12 23:07:05.167536 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : uuid: : uuid:
>>> 2015-02-12 23:07:05.286496 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 :  : uuid:::
>>> 2015-02-12 23:07:05.439684 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1 : uuid:::urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1
>>> 2015-02-12 23:07:05.481091 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:1 : uuid:::urn:schemas-upnp-org:service:ConnectionManager:1
>>> 2015-02-12 23:07:05.534329 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:1 : uuid:::urn:schemas-upnp-org:service:ContentDirectory:1
>>>
>>> Comparing these to messages from my file server, these messages are all
>>> missing the actual UUID value.  I poked around, but I don't see where
>>> this is defined.  I do see the following message when searching other
>>> myth log files with normal logging enabled:
>>>
>>> 2015-02-09 02:22:54.860839 E [12434/12434] CoreContext upnputil.cpp:51
>>> (LookupUDN) - LookupUDN()- bad device type '', not enough tokens
>>>
>>> Looking at the LookupUDN function it appears to be aborting before
>>> generating and saving a UDN for the device, because the device type is
>>> NULL.  The question now is why is the device type null?  I think I'm on
>>> the right track, but I haven't chased it back further than this.  It
>>> seems like maybe I'm missing something in my configuration?  This is a
>>> backend that was installed sometime in 2007 and has been upgraded over
>>> the years, so its entirely possible something may have gotten dropped or
>>> left out along the way.
>>>
>>> Any help would be appreciated.  TIA.
>>>
>>> David
>> You don't say what your real client will be.
>
> Right now I'm using BubbleUPnP on my cell phone to see if I can see the
> backend.  The phone does see my QNAP NAS as a server, but not mythtv.
> Short term I want to use BubbleUPnP to play music and videos from the
> backend on my Sony receiver.  Long term I want to use a Control4 system
> to do the same.
>
>> I find (with a
>> few-days-old master) that the myth debug messages during normal use are
>> now quite rare, but on powering up/down my tv I see stuff like this:

<snip>
> I do see messages like this in the myth logs from other devices on the
> network when I have upnp debugging enabled.
>
>> I suppose you have seen this
>>
>> https://www.mythtv.org/wiki/UPnP
>>
>> particularly the 'Troubleshooting' bit?
>
> Yes, thanks.  I've run through those troubleshooting hints.  My backend
> is using address 192.168.42.10, and there are entries in the settings
> table for MusicLocation (/export/apollo/music, my NAS) and
> VideoStartupDir (/video/dvds).  The ethernet on that system has
> multicast addresses present for 224.0.0.1, 224.0.0.251(MDNS) and
> 239.255.255.250(SSDP/UPNP).  (BTW, I do see the backend show up in an
> MDNS listing on another machine.)  I've checked that the firewall allows
> UDP:1900, TCP:6543 and TCP:6544 on input.  I have seen mythbackend log
> UPNP messages from other devices, so I know that it is able to receive
> messages on UDP:1900.  In my googling I came across the
> fetch-mythtv-upnp.sh script and installed it.  I can use that script to
> pull information from the backend, so that verifies that TCP:6544 is
> open and working.  There are no firewall rules that would prevent
> output.
>
>> I don't know how useful this might be, but an example from the wild may
>> help.
>
> I appreciate the response.  Do you (or anyone else) have a log of the
> UPNP messages that the backend sends at startup?  (I had to enable upnp
> logging to see them.)  I'd like to compare that to the output from my
> system.  I find it extremely odd that my logs show no uuid value in the
> messages that are sent, and that those messages never seem to hit the
> wire.
>
> Thanks.
>
> David
>
Here's a sample that gets repeated  at ~30 minute intervals on an idle 
but running system.  Yes, it has a rootdevice uuid.  Hope it helps!

21:18:58.059423 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 
: upnp:rootdevice : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::upnp:rootdevice
2015-02-13 21:18:58.437220 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : uuid:98edc01b-8634-403b-9f2b-e7a64881013c : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c
2015-02-13 21:18:59.015373 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : urn:schemas-upnp-org:device:MediaServer:4 : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::urn:schemas-upnp-org:device:MediaServer:4
2015-02-13 21:18:59.812409 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : 
urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1 : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::urn:microsoft.com:service:X_MS_MediaReceiverRegistrar:1
2015-02-13 21:19:00.167971 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:3 
: 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::urn:schemas-upnp-org:service:ConnectionManager:3
2015-02-13 21:19:00.844220 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:4 : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::urn:schemas-upnp-org:service:ContentDirectory:4
2015-02-13 21:19:01.541066 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : uuid:6ee05d25-2b91-42ea-a5fa-255152b24ee9 : 
uuid:6ee05d25-2b91-42ea-a5fa-255152b24ee9
2015-02-13 21:19:02.002068 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : urn:schemas-mythtv-org:device:MasterMediaServer:1 
: 
uuid:6ee05d25-2b91-42ea-a5fa-255152b24ee9::urn:schemas-mythtv-org:device:MasterMediaServer:1
2015-02-13 21:42:05.876472 I  SSDP Cache adding USN: 
uuid:upnp-InternetGatewayDevice-1_0-a021b746f5eb Location 
http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.886308 I  SSDP Cache adding USN: 
uuid:upnp-InternetGatewayDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:device:InternetGatewayDevice:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.896290 I  SSDP Cache adding USN: 
uuid:upnp-InternetGatewayDevice-1_0-a021b746f5eb::upnp:rootdevice 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.906256 I  SSDP Cache adding USN: 
uuid:upnp-WANDevice-1_0-a021b746f5eb Location 
http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.916256 I  SSDP Cache adding USN: 
uuid:upnp-WANDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:device:WANDevice:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.926242 I  SSDP Cache adding USN: 
uuid:upnp-WANConnectionDevice-1_0-a021b746f5eb Location 
http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.936319 I  SSDP Cache adding USN: 
uuid:upnp-WANConnectionDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:device:WANConnectionDevice:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.946312 I  SSDP Cache adding USN: 
uuid:upnp-InternetGatewayDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:service:Layer3Forwarding:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.956303 I  SSDP Cache adding USN: 
uuid:upnp-WANDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:42:05.966295 I  SSDP Cache adding USN: 
uuid:upnp-WANConnectionDevice-1_0-a021b746f5eb::urn:schemas-upnp-org:service:WANIPConnection:1 
Location http://192.168.0.1:80/RootDevice.xml
2015-02-13 21:49:02.465038 I  UPnpNotifyTask::SendNotifyMsg : 
239.255.255.250:1900 : upnp:rootdevice : 
uuid:98edc01b-8634-403b-9f2b-e7a64881013c::upnp:rootdevice