Jump to content
uglyned

Recording Service stops streaming uPNP

Recommended Posts

uglyned

I posted on another thread but I think that's slightly different so thought I'd start a new one.

 

Symptoms - RS had been working fine. Last night we were watching a TV program in Kodi, streamed from RS, and half way through, the program just froze and eventually stopped. When I try to watch any program now, in Kodi, it won't play. I get errors like below in the Kodi log.

 

I don't have a Windows PC that can run DVBViewer. I tried to run it on the server, but it doesn't have any codecs installed so gave output errors. I suspect it would have worked OK though. You may be able to tell from the logs.

 

This error with uPnP streaming happens every few days. Streaming via uPnP is not possible from any device I test from once it breaks. Including the uPnP renderer in the RS web interface.

 

I've just stopped and started the reocrding service and the uPnP streaming is working again.

 

Your support tool says 'OLE FEHLER 8004100E' when I run it from the DVBViewer program folder. If you let me know what files you want I'll package them up manually.

 

07:55:56 T:3944 NOTICE: DVDPlayer: Opening: pvr://recordings/active/Dickensian/Dickensian, TV (BBC One HD), 20160212_203000.pvr
07:55:56 T:3944 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
07:55:56 T:10816 NOTICE: Thread DVDPlayer start, auto delete: false
07:55:56 T:10816 NOTICE: Creating InputStream
07:56:05 T:4304 ERROR: CCurlFile::Stat - Failed: Timeout was reached(28) for http://USERNAME:PASSWORD@192.168.5.2:8090/upnp/thumbnails/video/580173653_SM.jpg
07:56:16 T:10816 ERROR: CCurlFile::FillBuffer - Failed: Timeout was reached(28)
07:56:16 T:10816 ERROR: CCurlFile::Open failed with code 0 for http://USERNAME:PASSWORD@192.168.5.2:8090/upnp/recordings/352.ts
07:56:16 T:10816 ERROR: XFILE::CFileCache::Open - failed to open source <http://USERNAME:PASSWORD@192.168.5.2:8090/upnp/recordings/352.ts>
07:56:16 T:10816 ERROR: CDVDPlayer::OpenInputStream - error opening [pvr://recordings/active/Dickensian/Dickensian, TV (BBC One HD), 20160212_203000.pvr]

Share this post


Link to post
Tjod

Are you using a Reverse Proxy for the streams?

 

Because the RS doesn't asks for a password for streams.

 

In future versions this will change for transcoded streams on the web interface port.

 

Which windows version is running on the server (for the supporttool error)?

 

Post the configuration folder svcdebug.log (if it doesn't contain passwords, in a normal configuration it should not) and the Config\service.xml and svchardware.xml.

 

If you can't watch in Kodi: Is the web interface working?

And streaming in the web interface?

Share this post


Link to post
uglyned

Thanks for posting. No, no reverse proxy or anything like that.

 

I'm using the Kodi DVBViewer TV plugin but it streams via uPNP. The default uPNP source in Kodi stops working too.

 

And yes, the RS web interface uPnp streaming also stops working. But the web interface itself is fine, responsive, and the service continues to operate correctly, make recordings etc I believe that RTSP continues to work OK too, but would need to test more to confirm that 100%.

 

In the logs, I believe the uPNP stopped working just before 21:00 on Friday 12. There was a recording going at the time so I didn't restart the service, and then restarted the service early on Saturday 13. The service has worked fine since then, including uPNP.

 

Running Windows Server 2012 R2.

service.xml

svcdebug.log

svchardware.xml

Edited by uglyned

Share this post


Link to post
Tjod

Disable in the settings Web/UPnP "UPnP controller" this function can cause problems.

 

If you get the problem without that function we can investigate further.

Share this post


Link to post
uglyned

OK that's done. Thanks, I'll let you know.

Share this post


Link to post
Derrick

The controller is pretty useless but I had never problems without deactivating the controller..

Share this post


Link to post
uglyned

Derrick was right sadly.

 

Despite turning the renderer off and restarting the service (I ensured it was off by going to the uPNP control page on the web interface aand ensured it was no longer available) the RS uPNP streaming failed again yesterday.

 

I haven't restarted the service yet in case there's anything you want me to test. Everything else about the RS works - the web interface is responsive. it continues to record TV absolutely correctly.

 

Also, I set the DVBViewer plugin in Kodi to stream live TV using RTSP and now live TV and live radio stream from the RS fine. But recordings still don't play.

 

From uPNP clients I can still browse the RS folder structure, recordings etc, it just times out when trying to stream whatever I select.

 

With it being Windows Sevrer, it's on all the time. There's no power management, it doesn't go to sleep when not in use, it's on, running, 24/7.

Share this post


Link to post
Tjod

I have currently no idea.

Share this post


Link to post
uglyned

I might have started noticing a pattern with this.

 

Say a TV show starts at 21:00 and RS starfs recording it.

 

I then start watching it at 21:15 via uPNP in KODI. It starts fine.

 

At 21:30 the streaming will suddenly stop. KODI will return to the recordings list. I can still browse them, refresh them but I can no longer stream them. Selecting one just causes KODI to think for a while and eventually give up. No uPNP streams are available to any other clients either.

 

So I think if I start watching a show that is currently recording, it starts OK but comes to an abrupt stop at the point the recording was at when I started watching it.

 

I then have to restart RS before I can watch anything else via uPNP.

Share this post


Link to post
Griga
I then start watching it at 21:15 via uPNP in KODI. It starts fine.

 

What is "it"? The live stream or the ongoing recording?

Share this post


Link to post
uglyned

Sorry - the ongoing recording.

Share this post


Link to post
Derrick

that's normal. The end time of the stream is the recording time when the stream is started.

Share this post


Link to post
Griga

But the RS shouldn't disable UPnP altogether when encountering this case. Will be checked.

Share this post


Link to post
Griga

Checked. No problem here. I've started a recording in the RS, then tried UPnP playback with

 

- DVBViewer Pro as client -> almost unusable because it tries to get a video thumbnail that doesn't exist and somehow gets stuck on it -> Christian has to look after it. The RS is not affected, however.

 

- TransEdit as client (after retrieving the URL by right-clicking the item in the DVBViewer Pro -> Playback -> UPnP Window -> Copy URL). Analyzer & video stop after some time (as expected), but the RS is still able to deliver another already finished recording.

 

- VLC -> View -> Playlist -> Local Network -> Universal Plug'n'Play as client. It stops playback after some time and automatically continues with the next recording in the list. No problem whatsoever.

 

So I don't know... maybe the client behaviour is involved somehow?

Share this post


Link to post
uglyned

This is still an issue in 1.33.0 and onwards. I can now reliably recreate the issue.

 

Install RS 1.33.whatever the latest is

 

Install Kodi on a different PC, keep default skin (this is important)

 

Set up TV in Kodi - DVBViewer PVR Client and enable TV

 

Watch a recording - it will fail to play and the whole RS UPnP server will no longer respond to Kodi (possibly to other UPnP clients too)

 

Kodi will still stream RTSP channels from RS if configured that way.

 

--------

 

Some observations -

 

If you change the skin (I use Transparency) the error will not appear every time but will eventually still appear anyway

 

Restarting the DVBViewer service will fix the issue temporarily, until the next

Share this post


Link to post
CiNcH

Which version of Kodi?

 

How do you try to play recordings? Via PVR Add-on? So from TV menu or Video/Movies menu where you added the RS UPnP source?

Share this post


Link to post
uglyned

Which version of Kodi?

 

How do you try to play recordings? Via PVR Add-on? So from TV menu or Video/Movies menu where you added the RS UPnP source?

 

I have the same thing with Kodi (OpenELEC) on a NUC and Kodi v16 for Windows.

 

I set up the PVR with the DVBViewer client, group recordings by series then view them through TV -> Recordings.

 

However, after the attempt to view a recording has failed through TV, it doesn't work through a UPnP source connected to DVBViewer RS either.

Share this post


Link to post
CiNcH

OK, I will try to reproduce it and provide some further info to Griga and manül.

  • Like 1

Share this post


Link to post
CiNcH

I know I have seen this issue many times before and it was somehow triggered when playing recordings via the PVR add-on. In this case, the add-on is responsible for playback. It reads the recordings.html from the RS and generates the URLs (serverURL + id). When selecting a recording for playback, the add-on opens the respective generated URL and hands the stream to the "Kodi playback engine".

 

I could not get in the bad state anymore. But I know that when I am in that state, the conventional UPnP also does not work anymore, e.g. by playing a hand generated URL (serverURL + id) in VLC or via Movies/Videos menu in Kodi, accessing the DVBViewer Media Server's UPnP media listings.

 

Do you have a safe way to get into this bad state? Playback of recordings randomly stops for you which triggers the issue (it shouldn't stop actually)? Or when playback stops at the end of a recording? Or is it just ongoing recordings?

 

BTW, there is an issue with ongoing recordings, see here. @manül will fix it eventually. Is this your problem?

Share this post


Link to post
Griga

Well, playback of ongoing recordings doesn't need much explaining. (...) Kodis file/url wrappers don't recognize filesize changes. So I need to close+reopen the file stream every x seconds. Otherwise the size will be read on startup and the playback will stop after the initial size is reached.


 
When DVBViewer plays a RS recording that it receives via a HTTP 1.1 keep-alive connection it uses the HEAD Method for getting an up-to-date HTTP Header from the Media Server and checking the content-length entry every 5 seconds (only applies to playback with DVBViewer Filter). Maybe that's a better strategy than opening and closing the stream repeatedly.
 
Additionally DVBViewer stops updating if two subsequents reads yield the same content-length.
 
Within the RS the Media Stream Server is responsible for delivery (default port 8090, see Options -> Web/UPnP page). UPnP specific mechanisms are not involved. I wonder if it can block the whole RS if the client does not respond anymore without having closed the connection properly. Maybe the timeout values have to be checked.

Share this post


Link to post
CiNcH

Thanks for looking into it.

The way I got to create the UPnP servi9ce falling into the bad state consistently was to use the latest version of RS and use the default Confluence skin in Kodi.

For some reason the Confluence skin makes the problem occur every time, whereas with other skins it happens less frequently.

I have no idea why!


 
So how do you reprocude the issue? Just start playback of a recording? A finished one or an ongoing one? Does it start? Does it break up?

Share this post


Link to post
uglyned
16 hours ago, CiNcH said:

 


 
So how do you reprocude the issue? Just start playback of a recording? A finished one or an ongoing one? Does it start? Does it break up?

 

Hi,

 

I've been able to consistently reproduce the issue using Kodi 16 with the default Confluence skin. I don't know why, but that skin causes the issue much mroe than others. It still happens with others, just not as oftern.

 

And using RS 1.33.latest.

 

So get TV set up and the plugin configured. I have recordings grouped by series.

 

Then go to TV -> Recordings and select a recording.

 

For me, the recording never appears. I just get a 'working' for a few seconds then that disappears, leaving the recordings list still visible.

 

From that point, the UPnP on the recording service is effectively broken. I can't connect to it at all.

 

If I configure the PVR plugin to receive live TV over RTSP, this still works.

 

Thanks for looking into it.

Share this post


Link to post
CiNcH

Good to know that you can reproduce it that easily. For me it is not that easy. Sometimes happens over night it seems. Media Stream Server is in a bad state then. Others wouldn't even connect anymore, as shown in the attached VLC log.

 

I currently don't know how to reliably get in that state. I am using a Kodi L build on an Android TV. Yesterday I restarted the TV and uninstalled some apps. It survived the night. It might very well be that someone does something that the Media Server does not like. Or it just randomly happens when playing any media from any client. We need to keep investigating.

 

 

core debug: adding item `http://192.168.233.192:8090/upnp/recordings/52' ( http://192.168.233.192:8090/upnp/recordings/52 )

core debug: meta ok for (null), need to fetch art

core debug: processing request item: http://192.168.233.192:8090/upnp/recordings/52, node: null, skip: 0

core debug: rebuilding array of current - root Playlist

core debug: rebuild done - 4 items, index 3

core debug: starting playback of the new playlist item

core debug: resyncing on http://192.168.233.192:8090/upnp/recordings/52

core debug: http://192.168.233.192:8090/upnp/recordings/52 is at 3

core debug: creating new input thread

core debug: Creating an input for 'http://192.168.233.192:8090/upnp/recordings/52'

core debug: looking for meta fetcher module matching "any": 1 candidates

core debug: requesting art for http://192.168.233.192:8090/upnp/recordings/52

core debug: looking for meta fetcher module matching "any": 1 candidates

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcher

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcher

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

core debug: no meta fetcher modules matched

core debug: no meta fetcher modules matched

core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52

core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52

core debug: looking for art finder module matching "any": 2 candidates

core debug: looking for art finder module matching "any": 2 candidates

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\art

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\art

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

core debug: no art finder modules matched

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

core debug: looking for meta fetcher module matching "any": 1 candidates

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcher

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

core debug: using meta fetcher module "lua"

core debug: removing module "lua"

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52

core debug: looking for art finder module matching "any": 2 candidates

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\art

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

core debug: no art finder modules matched

core debug: looking for meta fetcher module matching "any": 1 candidates

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcher

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

core debug: using meta fetcher module "lua"

core debug: removing module "lua"

core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52

core debug: looking for art finder module matching "any": 2 candidates

lua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\art

lua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luac

core debug: no art finder modules matched

core debug: using timeshift granularity of 50 MiB, in path 'C:\Users\iDaNnY\AppData\Local\Temp'

core debug: art not found for http://192.168.233.192:8090/upnp/recordings/52

core debug: `http://192.168.233.192:8090/upnp/recordings/52' gives access `http' demux `' path `192.168.233.192:8090/upnp/recordings/52'

core debug: specified demux `any'

core debug: creating demux: access='http' demux='any' location='192.168.233.192:8090/upnp/recordings/52' file='\\192.168.233.192:8090\upnp\recordings\52'

core debug: looking for access_demux module matching "http": 12 candidates

core debug: no access_demux modules matched

core debug: creating access 'http' location='192.168.233.192:8090/upnp/recordings/52', path='\\192.168.233.192:8090\upnp\recordings\52'

core debug: looking for access module matching "http": 21 candidates

http debug: querying proxy for http://192.168.233.192:8090/upnp/recordings/52

http debug: no proxy

http debug: http: server='192.168.233.192' port=8090 file='/upnp/recordings/52'

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac

core debug: net: connecting to 192.168.233.192 port 8090

lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luac

core debug: no art finder modules matched

core debug: art not found for http://192.168.233.192:8090/upnp/recordings/52

qt4 debug: IM: Setting an input

core warning: connection timed out

http error: cannot connect to 192.168.233.192:8090

core debug: net: connecting to 192.168.233.192 port 8090

core warning: connection timed out

access_mms error: cannot connect to 192.168.233.192:8090

core debug: no access modules matched

core error: open of `http://192.168.233.192:8090/upnp/recordings/52' failed

core debug: finished input

core debug: dead input

core debug: changing item without a request (current 3/4)

core debug: nothing to play

qt4 debug: IM: Deleting the input

Share this post


Link to post
CiNcH
Quote

If I configure the PVR plugin to receive live TV over RTSP, this still works.

 

We might have different problems after all anyway. I can still use live TV even with RTSP being disabled. As of Krypton, RTSP is not supported anymore anyway. The difference is that live TV goes via the Live Stream Server. This one still works in my case. Only the Media Stream Server is broken for me.

Share this post


Link to post
manül
7 hours ago, uglyned said:

For me, the recording never appears. I just get a 'working' for a few seconds then that disappears, leaving the recordings list still visible.

Sounds like a bug in den UPNP server anyway. Try to download the transport stream using curl or similar tools and see if the server is actually sending something.

 

Edit: Just a wild guess: Maybe Confluence is somehow triggering a deadlock in the UPNP server. For example by refreshing the drive space more often, but I'm not sure this is actually possible for a skin. A full debug log would at least show all http requests.

Edited by manül
  • Like 1

Share this post


Link to post
CiNcH

Griga found several issues in the Media Stream Server (which we could verify via extended debug logging) and applied workarounds which fixed the hangups for me. So the issues will eventually get fixed ;) . That's probably enough information for now. Griga can still add more if he likes to...

Share this post


Link to post
Griga

In the meantime I've re-written parts of the media stream server. Unfortunately I could never reproduce the issue. However, it should be fixed now, and I hope I didn't introduce new ones ;)

 

@uglyned: Do you want to beta-test it?

Share this post


Link to post
heikobihr
Am 26.2.2017 um 12:48 schrieb Griga:

@uglyned: Do you want to beta-test it?

Are there any news regarding a beta version?

 

I suffer from the same problem with RS (now 1.33.2.0) and (kodi now 17.3) for a long time, too.

After restart of RS, upnp streaming usually works for 1 to 2 days, but then RS stops responding to requests to its Media Streamserver port.

 

RS' web interface allows to download a .m3u file to play a recording in VLC, for example. VLC runs into a timeout, when opening the URL found in the .m3u file. Opening the URL in a browser results in a timeout, too.

If I change the port of the URL from Media Streamserver port (8090) to web interface port (8089), VLC successfully receives the recording from RS.

 

Regards

Heiko

Share this post


Link to post
Griga
On 11.4.2017 at 5:35 PM, hackbart said:

Fix: Media Stream Server: Access violations under certain timing conditions that disabled the (UPnP) delivery of files and recordings completely until a Media Server restart.

 

You are a bit late. I can't offer beta or test versions regarding this issue anymore. It has been fixed in the DVBViewer Media Server. You can order it here.

Share this post


Link to post

×
×
  • Create New...