UPnP notifications not being sent

Have a MythTV related problem? Ask for help from other MythTV users here.

Moderator: Forum Moderators

Post Reply
Steve Hill
Newcomer
Posts: 3
Joined: Fri Jan 02, 2015 5:53 pm
Great Britain

UPnP notifications not being sent

Post by Steve Hill »

Having unsuccessfully tried to get UPnP working in Myth a few years ago under Debian, I'm having another go, this time running the backend under Scientific Linux 7. And unfortunately I'm having no luck at all.

I can see Myth logging that it is sending UPnP notify messages, but tcpdumping the network interface shows that the UPnP packets never get sent onto the network. In fact, as far as I can tell from an strace of the backend, I don't think it's even writing the messages to the socket. I'm completely stumped - everything I've read says that UPnP in Mythbackend should Just Work™, yet I have utterly failed to get it to work on two completely different servers.

Any help would be greatly appreciated. I have attached the backend log below:

Code: Select all

2017-03-17 21:29:01.813889 C  mythbackend version: fixes/0.28 [v28.0-35-g812ec08] www.mythtv.org
2017-03-17 21:29:01.813968 C  Qt version: compile: 5.6.1, runtime: 5.6.1
2017-03-17 21:29:01.813974 N  Enabled verbose msgs:  general upnp
2017-03-17 21:29:01.814001 N  Setting Log Level to LOG_DEBUG
2017-03-17 21:29:01.826005 I  Added logging to the console
2017-03-17 21:29:01.826687 I  Setup Interrupt handler
2017-03-17 21:29:01.826707 I  Setup Terminated handler
2017-03-17 21:29:01.826724 I  Setup Segmentation fault handler
2017-03-17 21:29:01.826736 I  Setup Aborted handler
2017-03-17 21:29:01.826750 I  Setup Bus error handler
2017-03-17 21:29:01.826762 I  Setup Floating point exception handler
2017-03-17 21:29:01.826785 I  Setup Illegal instruction handler
2017-03-17 21:29:01.826806 I  Setup Real-time signal 0 handler
2017-03-17 21:29:01.826825 I  Setup Hangup handler
2017-03-17 21:29:01.826969 N  Using runtime prefix = /usr
2017-03-17 21:29:01.826975 N  Using configuration directory = /var/lib/mythtv/.mythtv
2017-03-17 21:29:01.826983 D  appbindir      = /usr/bin/
2017-03-17 21:29:01.826991 D  sharedir       = /usr/share/mythtv/
2017-03-17 21:29:01.826995 D  libdir         = /usr/lib64/mythtv/
2017-03-17 21:29:01.827002 D  themedir       = /usr/share/mythtv/themes/
2017-03-17 21:29:01.827006 D  pluginsdir     = /usr/lib64/mythtv/plugins/
2017-03-17 21:29:01.827012 D  translationsdir= /usr/share/mythtv/i18n/
2017-03-17 21:29:01.827016 D  filtersdir     = /usr/lib64/mythtv/filters/
2017-03-17 21:29:01.827237 I  Assumed character encoding: en_GB.utf8
2017-03-17 21:29:01.827250 W  This application expects to be running a locale that specifies a UTF-8 codeset, and many features may behave improperly with your current language settings. Please set the LC_ALL or LC_CTYPE, and LANG variable(s) in the environment in which this program is executed to include a UTF-8 codeset (such as 'en_US.UTF-8').
2017-03-17 21:29:01.828661 N  Empty LocalHostName.
2017-03-17 21:29:01.828683 I  Using localhost value of lyra.nexusuk.org
2017-03-17 21:29:01.828743 I  DefaultUPnP() - No default UPnP backend
2017-03-17 21:29:01.845520 D  FindDatabase() - Success!
2017-03-17 21:29:01.852406 N  Setting QT default locale to en_GB
2017-03-17 21:29:01.852464 I  Current locale en_GB
2017-03-17 21:29:01.853187 N  Reading locale defaults from /usr/share/mythtv//locales/en_gb.xml
2017-03-17 21:29:01.866720 E  Error Loading en_gb translation for module mythfrontend
2017-03-17 21:29:01.879466 I  Current MythTV Schema Version (DBSchemaVer): 1344
2017-03-17 21:29:01.879950 E  Error Loading en_gb translation for module mythfrontend
2017-03-17 21:29:01.882887 D  Adding IPv4 loopback to address list.
2017-03-17 21:29:01.882905 D  Adding IPv6 loopback to address list.
2017-03-17 21:29:01.882962 D  Adding link-local 'fe80::4ecc:6aff:fe4f:ea59%trunk' to address list.
2017-03-17 21:29:01.883002 D  Skipping address: [2a00:1940:103:1:4ecc:6aff:fe4f:ea59]
2017-03-17 21:29:01.883011 D  Adding link-local 'fe80::ac25:27ff:fe4e:fd4c%br-trunk' to address list.
2017-03-17 21:29:01.883025 D  Adding BackendServerIP to address list.
2017-03-17 21:29:01.883030 D  Adding BackendServerIP6 to address list.
2017-03-17 21:29:01.883040 D  Adding link-local 'fe80::fc54:ff:fee8:40c%vnet0' to address list.
2017-03-17 21:29:01.884430 N  MythBackend: Starting up as the master server.
2017-03-17 21:29:06.844471 I  Found 52 distinct programid authorities
2017-03-17 21:29:06.845586 I  New static DB connectionSchedCon
2017-03-17 21:29:06.847255 D  LogClean Run window between 82800 - 129600.
2017-03-17 21:29:06.847333 I  Registering HouseKeeperTask 'LogClean'.
2017-03-17 21:29:06.848021 D  DBCleanup Run window between 82800 - 129600.
2017-03-17 21:29:06.848051 I  Registering HouseKeeperTask 'DBCleanup'.
2017-03-17 21:29:06.848776 D  ThemeUpdateNotifications Run window between 82800 - 129600.
2017-03-17 21:29:06.848807 I  Registering HouseKeeperTask 'ThemeUpdateNotifications'.
2017-03-17 21:29:06.849558 D  RecordedArtworkUpdate Run window between 82800 - 129600.
2017-03-17 21:29:06.849587 I  Registering HouseKeeperTask 'RecordedArtworkUpdate'.
2017-03-17 21:29:06.850314 D  MythFillDB Run window between 82800 - 129600.
2017-03-17 21:29:06.856294 D  MythFillDB Run window between 82800 - 129600.
2017-03-17 21:29:06.856331 I  Registering HouseKeeperTask 'MythFillDB'.
2017-03-17 21:29:06.859378 D  JobQueueRecover Run window between 82800 - 129600.
2017-03-17 21:29:06.859394 I  Registering HouseKeeperTask 'JobQueueRecover'.
2017-03-17 21:29:06.859496 I  Registering HouseKeeperTask 'HardwareProfiler'.
2017-03-17 21:29:06.860255 D  ThemeUpdateNotifications Run window between 78663 - 129600.
2017-03-17 21:29:06.860328 D  DBCleanup Run window between 65403 - 129600.
2017-03-17 21:29:06.860396 D  JobQueueRecover Run window between 43200 - 100484.
2017-03-17 21:29:06.860464 D  LogClean Run window between 77283 - 129600.
2017-03-17 21:29:06.862626 I  Queueing HouseKeeperTask 'RecordedArtworkUpdate'.
2017-03-17 21:29:06.862640 I  Starting HouseKeeper.
2017-03-17 21:29:06.863539 D  UPnp - Constructor
2017-03-17 21:29:06.863552 I  MediaServer(): Begin
2017-03-17 21:29:06.863565 I  MediaServer(): End
2017-03-17 21:29:06.863579 I  MediaServer::Init(): Begin
2017-03-17 21:29:06.944307 I  Listening on TCP 127.0.0.1:6544
2017-03-17 21:29:06.944457 I  Listening on TCP 192.168.3.2:6544
2017-03-17 21:29:06.944539 I  Listening on TCP [::1]:6544
2017-03-17 21:29:06.945979 I  Listening on TCP [fe80::4ecc:6aff:fe4f:ea59%trunk]:6544
2017-03-17 21:29:06.946196 I  Listening on TCP [fe80::ac25:27ff:fe4e:fd4c%br-trunk]:6544
2017-03-17 21:29:06.946277 I  Listening on TCP [2a00:1940:103:3::2]:6544
2017-03-17 21:29:06.946397 I  Listening on TCP [fe80::fc54:ff:fee8:40c%vnet0]:6544
2017-03-17 21:29:06.946496 I  Listening on TCP 127.0.0.1:6554
2017-03-17 21:29:06.946557 I  Listening on TCP 192.168.3.2:6554
2017-03-17 21:29:06.946620 I  Listening on TCP [::1]:6554
2017-03-17 21:29:06.946743 I  Listening on TCP [fe80::4ecc:6aff:fe4f:ea59%trunk]:6554
2017-03-17 21:29:06.946868 I  Listening on TCP [fe80::ac25:27ff:fe4e:fd4c%br-trunk]:6554
2017-03-17 21:29:06.946939 I  Listening on TCP [2a00:1940:103:3::2]:6554
2017-03-17 21:29:06.947055 I  Listening on TCP [fe80::fc54:ff:fee8:40c%vnet0]:6554
2017-03-17 21:29:06.947298 I  Listening on TCP 127.0.0.1:6549
2017-03-17 21:29:06.947391 I  Listening on TCP 192.168.3.2:6549
2017-03-17 21:29:06.947457 I  Listening on TCP [::1]:6549
2017-03-17 21:29:06.947585 I  Listening on TCP [fe80::4ecc:6aff:fe4f:ea59%trunk]:6549
2017-03-17 21:29:06.947717 I  Listening on TCP [fe80::ac25:27ff:fe4e:fd4c%br-trunk]:6549
2017-03-17 21:29:06.947791 I  Listening on TCP [2a00:1940:103:3::2]:6549
2017-03-17 21:29:06.947911 I  Listening on TCP [fe80::fc54:ff:fee8:40c%vnet0]:6549
2017-03-17 21:29:06.949319 I  MediaServer: Loading UPnp Description /usr/share/mythtv/devicemaster.xml
2017-03-17 21:29:06.949442 I  MediaServer: Registering Http Server Extensions.
2017-03-17 21:29:06.952969 D  UPnp::Initialize - Begin
2017-03-17 21:29:06.954347 D  UPnp::Initialize - End
2017-03-17 21:29:06.954701 I  MediaServer: Registering MS_MediaReceiverRegistrar Service.
2017-03-17 21:29:06.955977 I  MediaServer: Registering ConnnectionManager Service.
2017-03-17 21:29:06.956056 I  MediaServer: Registering ContentDirectory Service.
2017-03-17 21:29:06.956204 I  MediaServer: Registering UPnpCDSTv Extension
2017-03-17 21:29:06.957141 I  MediaServer: Registering UPnpCDSMusic Extension
2017-03-17 21:29:06.957189 I  MediaServer: Registering UPnpCDSVideo Extension
2017-03-17 21:29:06.957227 D  UPnp::Start - Enabling SSDP Notifications
2017-03-17 21:29:06.957306 N  Starting up SSDP Thread...
2017-03-17 21:29:06.960669 I  SSDP Thread Starting soon
2017-03-17 21:29:06.960692 I  SSDP::EnableNotifications() - creating new task
2017-03-17 21:29:06.962014 I  SSDP::EnableNotifications() - sending NTS_byebye
2017-03-17 21:29:06.962519 E  LookupUDN()- bad device type '', not enough tokens
2017-03-17 21:29:06.962698 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : upnp:rootdevice : uuid:::upnp:rootdevice
2017-03-17 21:29:06.962993 I  SSDP::Run - SSDP Thread Started.
2017-03-17 21:29:07.777284 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : uuid: : uuid:
2017-03-17 21:29:08.571933 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 :  : uuid:::
2017-03-17 21:29:09.536339 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
2017-03-17 21:29:09.882057 I  Reschedule requested for MATCH 0 0 0 - SchedulerInit
2017-03-17 21:29:10.126689 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:3 : uuid:::urn:schemas-upnp-org:service:ConnectionManager:3
2017-03-17 21:29:10.335139 I  Scheduled 97 items in 0.4 = 0.09 match + 0.16 check + 0.18 place
2017-03-17 21:29:10.359616 I  Scheduler: Seem to be woken up by USER
2017-03-17 21:29:10.744211 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:4 : uuid:::urn:schemas-upnp-org:service:ContentDirectory:4
2017-03-17 21:29:11.651672 I  SSDP::EnableNotifications() - sending NTS_alive
2017-03-17 21:29:11.651747 I  Starting TaskQueue Thread...
2017-03-17 21:29:11.652037 I  TaskQueue Thread Started.
2017-03-17 21:29:11.652225 I  SSDP::EnableNotifications() - Task added to UPnP queue
2017-03-17 21:29:11.652249 D  UPnp::Start - Returning
2017-03-17 21:29:11.652773 I  TaskQueue Thread Running.
2017-03-17 21:29:11.653600 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : upnp:rootdevice : uuid:::upnp:rootdevice
2017-03-17 21:29:11.697431 I  MediaServer::Init(): End
2017-03-17 21:29:11.697462 I  Main::Registering HttpStatus Extension
2017-03-17 21:29:11.704300 I  Listening on TCP 127.0.0.1:6543
2017-03-17 21:29:11.704593 I  Listening on TCP 192.168.3.2:6543
2017-03-17 21:29:11.704884 I  Listening on TCP [::1]:6543
2017-03-17 21:29:11.705589 I  Listening on TCP [fe80::4ecc:6aff:fe4f:ea59%trunk]:6543
2017-03-17 21:29:11.706287 I  Listening on TCP [fe80::ac25:27ff:fe4e:fd4c%br-trunk]:6543
2017-03-17 21:29:11.706603 I  Listening on TCP [2a00:1940:103:3::2]:6543
2017-03-17 21:29:11.707581 I  Listening on TCP [fe80::fc54:ff:fee8:40c%vnet0]:6543
2017-03-17 21:29:11.721545 N  AutoExpire: CalcParams(): Max required Free Space: 10.0 GB w/freq: 15 min
2017-03-17 21:29:12.531681 I  Bonjour: Service registration complete: name 'Mythbackend on lyra.nexusuk.org' type '_mythbackend._tcp.' domain: 'local.'
2017-03-17 21:29:12.582214 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : uuid: : uuid:
2017-03-17 21:29:12.876706 I  MainServer: MainServer::ANN Frontend
2017-03-17 21:29:12.876793 I  MainServer: adding: krikkit.nexusuk.org(136e800) as a client (events: 0)
2017-03-17 21:29:12.880352 I  BackendContext: Frontend 'krikkit.nexusuk.org' connected.
2017-03-17 21:29:12.886400 I  MainServer: MainServer::ANN Monitor
2017-03-17 21:29:12.886519 I  MainServer: adding: krikkit.nexusuk.org(1358a10) as a client (events: 1)
2017-03-17 21:29:13.444644 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 :  : uuid:::
2017-03-17 21:29:14.383837 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
2017-03-17 21:29:15.258922 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:3 : uuid:::urn:schemas-upnp-org:service:ConnectionManager:3
2017-03-17 21:29:15.770908 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:4 : uuid:::urn:schemas-upnp-org:service:ContentDirectory:4
2017-03-17 21:29:31.091068 C  Received Interrupt: Code 128, PID 0, UID 0, Value 0x00000000
2017-03-17 21:29:31.100017 N  MythBackend exiting
2017-03-17 21:29:31.118681 I  Bonjour: De-registering service '_mythbackend._tcp.' on 'Mythbackend on lyra.nexusuk.org'
2017-03-17 21:29:31.122601 D  UPnp - Destructor
2017-03-17 21:29:31.122638 I  UPnp::CleanUp() - disabling SSDP notifications
2017-03-17 21:29:31.127048 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : upnp:rootdevice : uuid:::upnp:rootdevice
2017-03-17 21:29:31.878244 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : uuid: : uuid:
2017-03-17 21:29:32.978689 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 :  : uuid:::
2017-03-17 21:29:33.771297 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
2017-03-17 21:29:34.572840 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ConnectionManager:3 : uuid:::urn:schemas-upnp-org:service:ConnectionManager:3
2017-03-17 21:29:35.426818 I  UPnpNotifyTask::SendNotifyMsg : 239.255.255.250:1900 : urn:schemas-upnp-org:service:ContentDirectory:4 : uuid:::urn:schemas-upnp-org:service:ContentDirectory:4
2017-03-17 21:29:37.091705 I  Waiting for threads to exit.
Post Reply