uglyned Posted February 13, 2016 Share Posted February 13, 2016 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.pvr07:55:56 T:3944 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED07:55:56 T:10816 NOTICE: Thread DVDPlayer start, auto delete: false07:55:56 T:10816 NOTICE: Creating InputStream07: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.jpg07: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.ts07: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] Link to comment
Tjod Posted February 13, 2016 Share Posted February 13, 2016 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? Link to comment
uglyned Posted February 14, 2016 Author Share Posted February 14, 2016 (edited) 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 February 14, 2016 by uglyned Link to comment
Tjod Posted February 14, 2016 Share Posted February 14, 2016 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. Link to comment
uglyned Posted February 14, 2016 Author Share Posted February 14, 2016 OK that's done. Thanks, I'll let you know. Link to comment
Derrick Posted February 14, 2016 Share Posted February 14, 2016 The controller is pretty useless but I had never problems without deactivating the controller.. Link to comment
uglyned Posted February 18, 2016 Author Share Posted February 18, 2016 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. Link to comment
Tjod Posted February 18, 2016 Share Posted February 18, 2016 I have currently no idea. Link to comment
uglyned Posted March 25, 2016 Author Share Posted March 25, 2016 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. Link to comment
Griga Posted March 25, 2016 Share Posted March 25, 2016 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? Link to comment
uglyned Posted March 25, 2016 Author Share Posted March 25, 2016 Sorry - the ongoing recording. Link to comment
Derrick Posted March 25, 2016 Share Posted March 25, 2016 that's normal. The end time of the stream is the recording time when the stream is started. Link to comment
Griga Posted March 25, 2016 Share Posted March 25, 2016 But the RS shouldn't disable UPnP altogether when encountering this case. Will be checked. Link to comment
Griga Posted March 26, 2016 Share Posted March 26, 2016 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? Link to comment
uglyned Posted February 13, 2017 Author Share Posted February 13, 2017 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 Link to comment
CiNcH Posted February 13, 2017 Share Posted February 13, 2017 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? Link to comment
uglyned Posted February 13, 2017 Author Share Posted February 13, 2017 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. Link to comment
CiNcH Posted February 14, 2017 Share Posted February 14, 2017 OK, I will try to reproduce it and provide some further info to Griga and manül. 1 Link to comment
CiNcH Posted February 15, 2017 Share Posted February 15, 2017 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? Link to comment
Griga Posted February 16, 2017 Share Posted February 16, 2017 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. Link to comment
CiNcH Posted February 16, 2017 Share Posted February 16, 2017 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? Link to comment
uglyned Posted February 17, 2017 Author Share Posted February 17, 2017 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. Link to comment
CiNcH Posted February 17, 2017 Share Posted February 17, 2017 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 artcore debug: processing request item: http://192.168.233.192:8090/upnp/recordings/52, node: null, skip: 0core debug: rebuilding array of current - root Playlistcore debug: rebuild done - 4 items, index 3core debug: starting playback of the new playlist itemcore debug: resyncing on http://192.168.233.192:8090/upnp/recordings/52core debug: http://192.168.233.192:8090/upnp/recordings/52 is at 3core debug: creating new input threadcore debug: Creating an input for 'http://192.168.233.192:8090/upnp/recordings/52'core debug: looking for meta fetcher module matching "any": 1 candidatescore debug: requesting art for http://192.168.233.192:8090/upnp/recordings/52core debug: looking for meta fetcher module matching "any": 1 candidateslua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcherlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcherlua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcherlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcherlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaccore debug: no meta fetcher modules matchedcore debug: no meta fetcher modules matchedcore debug: searching art for http://192.168.233.192:8090/upnp/recordings/52core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52core debug: looking for art finder module matching "any": 2 candidatescore debug: looking for art finder module matching "any": 2 candidateslua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\artlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\artlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luaclua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\artlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\artlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaccore debug: no art finder modules matchedlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaccore debug: looking for meta fetcher module matching "any": 1 candidateslua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcherlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcherlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luaccore 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.luaccore debug: searching art for http://192.168.233.192:8090/upnp/recordings/52core debug: looking for art finder module matching "any": 2 candidateslua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaclua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\artlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\artlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: skipping script (unmatched scope) C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaccore debug: no art finder modules matchedcore debug: looking for meta fetcher module matching "any": 1 candidateslua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\fetcherlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcherlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\fetcher\tvrage.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\02_frenchtv.luaccore debug: using meta fetcher module "lua"core debug: removing module "lua"core debug: searching art for http://192.168.233.192:8090/upnp/recordings/52core debug: looking for art finder module matching "any": 2 candidateslua debug: Trying Lua scripts in C:\Users\iDaNnY\AppData\Roaming\vlc\lua\meta\artlua debug: Trying Lua scripts in C:\Program Files (x86)\VideoLAN\VLC\lua\meta\artlua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaclua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\01_googleimage.luaccore debug: no art finder modules matchedcore 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/52core 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 candidatescore debug: no access_demux modules matchedcore 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 candidateshttp debug: querying proxy for http://192.168.233.192:8090/upnp/recordings/52http debug: no proxyhttp 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.luaccore debug: net: connecting to 192.168.233.192 port 8090lua debug: Trying Lua playlist script C:\Program Files (x86)\VideoLAN\VLC\lua\meta\art\03_lastfm.luaccore debug: no art finder modules matchedcore debug: art not found for http://192.168.233.192:8090/upnp/recordings/52qt4 debug: IM: Setting an inputcore warning: connection timed outhttp error: cannot connect to 192.168.233.192:8090core debug: net: connecting to 192.168.233.192 port 8090core warning: connection timed outaccess_mms error: cannot connect to 192.168.233.192:8090core debug: no access modules matchedcore error: open of `http://192.168.233.192:8090/upnp/recordings/52' failedcore debug: finished inputcore debug: dead inputcore debug: changing item without a request (current 3/4)core debug: nothing to playqt4 debug: IM: Deleting the input Link to comment
CiNcH Posted February 17, 2017 Share Posted February 17, 2017 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. Link to comment
manül Posted February 17, 2017 Share Posted February 17, 2017 (edited) 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 February 17, 2017 by manül 1 Link to comment
CiNcH Posted February 25, 2017 Share Posted February 25, 2017 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... Link to comment
Griga Posted February 26, 2017 Share Posted February 26, 2017 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? Link to comment
heikobihr Posted May 30, 2017 Share Posted May 30, 2017 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 Link to comment
Griga Posted May 30, 2017 Share Posted May 30, 2017 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. Link to comment
Recommended Posts