TV Server Crashes After Recording Ends (3 Viewers)

[georgius]

So... I get to post what I hope is good news. So far... both scenarios of testing Filter #2 from above (with and without MPEG2 parser) worked very well. In fact, there was no noticeable difference between either. The playback worked well. Not a single stutter... and this was indeed on my low power everyday HTPC.

Here's the GPU and CPU stats for each scenario.

With MPEG2 Parser...
- GPU1 pinned at 100% utilization
- GPU2 spiky... 0 or 100% utilization in sporadic spikes
- GPU3 steady utilization roughly around 65%
- 4 CPU cores roughly average around 18% utilization
- MP client was around 10% CPU utilization
- TV Service was consistent around 2-3%


Without MPEG2 Parser...
- GPU1 pinned at 100% utilization
- GPU2 spiky... 0 or 100% utilization in sporadic spikes
- GPU3 steady utilization roughly around 65%
- 4 CPU cores roughly average around 17% utilization
- MP client was around 10% CPU utilization
- TV Service was consistent around 1-2%

I've decided to reintroduce the MPEG2 parser and run with this new filter for everyday use to see if there are any long term impacts. So far I've had pretty good luck on everything I tried to watch in the last 30 minutes or so.

So, it seems that performance problem is solved

 

[Sigpi007]

So, it seems that performance problem is solved

Agreed... In the last 24 hours not a single issue, and at one point I was recording two shows and watching a third live. Performance was great, and CPU fan was running no louder than expected.

 

[Sigpi007]

And... I spoke too fast. But... in all fairness, this may be a separate issue... though its much more severe now than it was before.

When watching TV today, I had one show recording which I was watching LIVE while it was recording (channel 203). Then I tried to change to a separate channel to watch something different (220). When I did that, it crashed the TV server ("unknown error occured") and essentially froze the MP client. I closed the client, confirmed that the TV server had stopped... started it up again and dumped the logs. Will attach below.

THEN... since I had restarted TV server... I entered the MP client again and selected the channel I had wanted to watch (220). Still could not do it. Error returned was "unknown error occured." TV server crashed again.

THEN... I restarted the TV server again. However... this time I chose any channel other that 203 and 220. This time I got "could not create graph" errors for channel 219, and other channels. etc. However, differnce this time was that those errors did not kill the TV server.. Then I dumped those log files and exited the client. I also opened the TV Server config and saw that all tuners were showing up in the config as expected.

FINALLY... I analyzed the current state of the Ceton InfiniTV Eth 6 tuner through its admin interface... and I noticed that tuner #1 and tuner # 5 were listed as "PLAYING". Tuners 2, 3, 4, and 6 were "STOPPED" which means nothing is playing. Tuner 1 was playing channel 203. Tuner 5 was playing 220. So to test a hypothesis... I manually set Tuner #1 status to "STOPPED" in the interface, and then I started the MP Client again. Can't remember if I cycled the TV Server. Anywho... this time I was able to watch channels again.

Long story short... there are a couple things that seem not right.
#1... Something initially caused the TV server to become unstable. Possibly related to watching a recording live and trying to switch away from it.
#2... Even if those 2 tuners (numbers 1 and 5) were locked for use, the TV Server should have tuned using one of the 3 or 4 available tuners. [DOUBLEPOST=1420771017][/DOUBLEPOST]Here are the logs... the MPIPTV filters also had dump files around 300MB each. 2 files. I still have these and can share if needed.[DOUBLEPOST=1420771560][/DOUBLEPOST]And here's an excerpt from the Ceton Logs...

 

[mm1352000]

Hello and thanks for the feedback.

When watching TV today, I had one show recording which I was watching LIVE while it was recording (channel 203). Then I tried to change to a separate channel to watch something different (220). When I did that, it crashed the TV server ("unknown error occured") and essentially froze the MP client. I closed the client, confirmed that the TV server had stopped... started it up again and dumped the logs. Will attach below.

Looks like the IPTV/URL source filter cause TV service to crash when you tried to start watching 220 CSNHD at 19:57:25:
[collapse]"1/8/2015 7:57:52 PM";".NET Runtime";"(0)";"Error";"Application: TVService.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: exception code c0000005, exception address 54B1DC89
";"1026"
"1/8/2015 7:57:53 PM";"Application Error";"Application Crashing Events";"Error";"Faulting application name: TVService.exe, version: 1.10.0.0, time stamp: 0x548c1072 Faulting module name: MPUrlSourceSplitter.ax, version: 0.0.0.0, time stamp: 0x54aa406b Exception code: 0xc0000005 Fault offset: 0x0000dc89 Faulting process id: 0xdc4 Faulting application start time: 0x01d02b2ecef4504e Faulting application path: C:\Program Files (x86)\Team MediaPortal\MediaPortal TV Server\TVService.exe Faulting module path: C:\Program Files (x86)\Team MediaPortal\MediaPortal TV Server\MPUrlSourceSplitter\MPUrlSourceSplitter.ax Report Id: ebab1056-97a2-11e4-8c7a-1078d2329f27";"1000"
"1/8/2015 7:58:23 PM";"Windows Error Reporting";"(0)";"Information";"Fault bucket , type 0 Event Name: APPCRASH Response: Not available Cab Id: 0 Problem signature: P1: TVService.exe P2: 1.10.0.0 P3: 548c1072 P4: MPUrlSourceSplitter.ax P5: 0.0.0.0 P6: 54aa406b P7: c0000005 P8: 0000dc89 P9: P10: Attached files: C:\Windows\Temp\WER51D8.tmp.appcompat.txt C:\Windows\Temp\WER6F09.tmp.WERInternalMetadata.xml C:\Windows\Temp\WER6F29.tmp.hdmp C:\Windows\Temp\WER8B13.tmp.mdmp These files may be available here: C:\ProgramData\Microsoft\Windows\WER\ReportQueue\AppCrash_TVService.exe_2d986b4f398e36c26ceac2284cdfd145d01fcb_cab_0da88d04 Analysis symbol: Rechecking for solution: 0 Report Id: ebab1056-97a2-11e4-8c7a-1078d2329f27 Report Status: 4";"1001"
"1/8/2015 7:58:31 PM";"Windows Error Reporting";"(0)";"Information";"Fault bucket , type 0 Event Name: APPCRASH Response: Not available Cab Id: 0 Problem signature: P1: TVService.exe P2: 1.10.0.0 P3: 548c1072 P4: MPUrlSourceSplitter.ax P5: 0.0.0.0 P6: 54aa406b P7: c0000005 P8: 0000dc89 P9: P10: Attached files: C:\Windows\Temp\WER51D8.tmp.appcompat.txt C:\Windows\Temp\WER6F09.tmp.WERInternalMetadata.xml C:\Windows\Temp\WER6F29.tmp.hdmp C:\Windows\Temp\WER8B13.tmp.mdmp These files may be available here: C:\ProgramData\Microsoft\Windows\WER\ReportArchive\AppCrash_TVService.exe_2d986b4f398e36c26ceac2284cdfd145d01fcb_12ccde2f Analysis symbol: Rechecking for solution: 0 Report Id: ebab1056-97a2-11e4-8c7a-1078d2329f27 Report Status: 1";"1001"[/collapse]

MediaPortal froze because it was waiting for TV Server to tell it whether tuning was successful or not.

THEN... since I had restarted TV server... I entered the MP client again and selected the channel I had wanted to watch (220). Still could not do it. Error returned was "unknown error occured." TV server crashed again.

Unfortunately your MP logs are at error level, so it is a bit hard to follow this. However, I don't see the second TV Server crash that you refer to.

THEN... I restarted the TV server again. However... this time I chose any channel other that 203 and 220. This time I got "could not create graph" errors for channel 219, and other channels. etc. However, differnce this time was that those errors did not kill the TV server.. Then I dumped those log files and exited the client. I also opened the TV Server config and saw that all tuners were showing up in the config as expected.

I'm not seeing this in the logs. Maybe this happened in the log gap between 8 and 8:10 PM? BTW, it would be helpful to specify times if you could. Saves guess work.

FINALLY... I analyzed the current state of the Ceton InfiniTV Eth 6 tuner through its admin interface... and I noticed that tuner #1 and tuner # 5 were listed as "PLAYING". Tuners 2, 3, 4, and 6 were "STOPPED" which means nothing is playing. Tuner 1 was playing channel 203. Tuner 5 was playing 220. So to test a hypothesis... I manually set Tuner #1 status to "STOPPED" in the interface, and then I started the MP Client again. Can't remember if I cycled the TV Server. Anywho... this time I was able to watch channels again.

It is entirely possible that tuners would be left in "inconsistent states" after a TV Server crash. Especially a crash involving tuning.

TV Server will not use tuners that it thinks might be being used by other software/processes. In particular with CableCARD tuners: TV Server checks if a tuner is playing before attempting to "build the graph" (load the tuner) and/or tune, and if the tuner is playing it won't complete the load/tune process. It looks like this in the logs:
[collapse]
[2015-01-08 20:11:20,197] [Log ] [20 ] [DEBUG] - DRI CC: PrepareForConnection, connection ID = 0, AV transport ID = 0
[2015-01-08 20:11:20,289] [Log ] [20 ] [INFO ] - DRI CC: remove source filter
[2015-01-08 20:11:20,853] [Log ] [20 ] [INFO ] - Info.: UPnPServerController: GENA disabled for IP endpoint '192.168.1.122'
[2015-01-08 20:11:20,858] [Log ] [20 ] [ERROR] - Exception :TvLibrary.TvExceptionGraphBuildingFailed: DRI CC: tuner appears to be in use
at TvLibrary.Implementations.Dri.TunerDri.BuildGraph()
at TvLibrary.Implementations.Dri.TunerDri.BeforeTune(IChannel channel)
at TvLibrary.Implementations.DVB.TvCardATSC.Tune(Int32 subChannelId, IChannel channel)
[2015-01-08 20:11:20,872] [Log ] [20 ] [ERROR] - Exception :TvLibrary.TvExceptionGraphBuildingFailed: DRI CC: tuner appears to be in use
at TvLibrary.Implementations.Dri.TunerDri.BuildGraph()
at TvLibrary.Implementations.Dri.TunerDri.BeforeTune(IChannel channel)
at TvLibrary.Implementations.DVB.TvCardATSC.Tune(Int32 subChannelId, IChannel channel)
at TvService.CardTuner.Tune(IUser& user, IChannel channel, Int32 idChannel)
[/collapse]

Unfortunately there is no way for TV Server to know that the tuners were playing because a previous instance of TV Server told them to start, and that the previous instance of TV Server crashed before it had a chance to stop the tuners. In other words, TV Server can't bring the tuners back under control until you manually stop them as you did.

#1... Something initially caused the TV server to become unstable. Possibly related to watching a recording live and trying to switch away from it.

As far as I can see that "something" seems to be the IPTV filter. I think that fact that it happened while you were trying to switch away from a recording is entirely coincidental.

#2... Even if those 2 tuners (numbers 1 and 5) were locked for use, the TV Server should have tuned using one of the 3 or 4 available tuners.

I agree... and as far as I can see, TV Server did tune using other available tuners wherever possible. Note that I don't know of any Ceton tuner locking implementation. The only scenario where TV Server will not attempt to use a Ceton tuner is the self-imposed limitation described above.

Regards (and thanks again!),
mm

 

[mm1352000]

Actually, regarding the second crash...
I do see application event log entries at 8:04:
[collapse]
"1/8/2015 8:04:16 PM";".NET Runtime";"(0)";"Error";"Application: TVService.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: exception code c0000005, exception address 61BDDC89
";"1026"
"1/8/2015 8:04:16 PM";"Application Error";"Application Crashing Events";"Error";"Faulting application name: TVService.exe, version: 1.10.0.0, time stamp: 0x548c1072 Faulting module name: MPUrlSourceSplitter.ax, version: 0.0.0.0, time stamp: 0x54aa406b Exception code: 0xc0000005 Fault offset: 0x0000dc89 Faulting process id: 0x11f4 Faulting application start time: 0x01d02baffffac06e Faulting application path: C:\Program Files (x86)\Team MediaPortal\MediaPortal TV Server\TVService.exe Faulting module path: C:\Program Files (x86)\Team MediaPortal\MediaPortal TV Server\MPUrlSourceSplitter\MPUrlSourceSplitter.ax Report Id: d01cf476-97a3-11e4-8c7a-1078d2329f27";"1000"
"1/8/2015 8:04:23 PM";"Windows Error Reporting";"(0)";"Information";"Fault bucket , type 0 Event Name: APPCRASH Response: Not available Cab Id: 0 Problem signature: P1: TVService.exe P2: 1.10.0.0 P3: 548c1072 P4: MPUrlSourceSplitter.ax P5: 0.0.0.0 P6: 54aa406b P7: c0000005 P8: 0000dc89 P9: P10: Attached files: C:\Windows\Temp\WER2156.tmp.appcompat.txt C:\Windows\Temp\WER2241.tmp.WERInternalMetadata.xml C:\Windows\Temp\WER2252.tmp.hdmp C:\Windows\Temp\WER3A74.tmp.mdmp These files may be available here: C:\ProgramData\Microsoft\Windows\WER\ReportQueue\AppCrash_TVService.exe_2d986b4f398e36c26ceac2284cdfd145d01fcb_cab_066e3c55 Analysis symbol: Rechecking for solution: 0 Report Id: d01cf476-97a3-11e4-8c7a-1078d2329f27 Report Status: 4";"1001"
"1/8/2015 8:04:25 PM";"Windows Error Reporting";"(0)";"Information";"Fault bucket , type 0 Event Name: APPCRASH Response: Not available Cab Id: 0 Problem signature: P1: TVService.exe P2: 1.10.0.0 P3: 548c1072 P4: MPUrlSourceSplitter.ax P5: 0.0.0.0 P6: 54aa406b P7: c0000005 P8: 0000dc89 P9: P10: Attached files: C:\Windows\Temp\WER2156.tmp.appcompat.txt C:\Windows\Temp\WER2241.tmp.WERInternalMetadata.xml C:\Windows\Temp\WER2252.tmp.hdmp C:\Windows\Temp\WER3A74.tmp.mdmp These files may be available here: C:\ProgramData\Microsoft\Windows\WER\ReportArchive\AppCrash_TVService.exe_2d986b4f398e36c26ceac2284cdfd145d01fcb_0956453b Analysis symbol: Rechecking for solution: 0 Report Id: d01cf476-97a3-11e4-8c7a-1078d2329f27 Report Status: 1";"1001"
[/collapse]

(Another access violation crash apparently triggered by the IPTV filter.)
However, the corresponding MP and TV Server logs are missing.

 

[Sebastiii]

I remember that i have add try/catch on tvservice part to avoid crash when IPTV return some kind of error code based on @georgius help. For sure, it solve some crash (i think it's the one when IPTV can't tune, so when the stream is already there on one tuner or something).

But the other error c0000005 is surely from filter side.

So i would say, we have 2 differents crash here (not 100% sure) but i think

 

[georgius]

I remember that i have add try/catch on tvservice part to avoid crash when IPTV return some kind of error code based on @georgius help. For sure, it solve some crash (i think it's the one when IPTV can't tune, so when the stream is already there on one tuner or something).

But the other error c0000005 is surely from filter side.

So i would say, we have 2 differents crash here (not 100% sure) but i think

It's TV service bug:

08-01-2015 19:57:32.233 [ cd4] [{EDB9A0D1-F42E-4CC2-92B8-9A326F99B339}] [Info]    MPUrlSourceSplitter: Load(): End, Fail, result: 0xFFFFFFE0

Filter returned error and TV service is not checking HRESULT from Load() method.

 

[georgius]

Here are the logs... the MPIPTV filters also had dump files around 300MB each. 2 files. I still have these and can share if needed.

You can delete them.

 

[mm1352000]

Filter returned error and TV service is not checking HRESULT from Load() method.

Ahhh, but what is the filter trying to do when the Load() method is called? From the log it seems like the filter is starting to try to receive the stream. Surely that should not happen until the graph is started (IMediaControl.Run())?

[edit: To be clear, in other words the TV service is not expecting any error from the load method unless the URL format is somehow wrong... which seems not to be the case here, so why would the filter return an error?]

[edit2: Also, what does the HRESULT code mean?]

 

[georgius]

Filter returned error and TV service is not checking HRESULT from Load() method.

Ahhh, but what is the filter trying to do when the Load() method is called? From the log it seems like the filter is starting to try to receive the stream. Surely that should not happen until the graph is started (IMediaControl.Run())?

Filter is starting to receive stream. Because no data received within specified timeout (1500 ms for RTSP), it returned error.

[edit: To be clear, in other words the TV service is not expecting any error from the load method unless the URL format is somehow wrong... which seems not to be the case here, so why would the filter return an error?]

If error happens, filter returns error (if it can't handle it). The most common case is no data received within specified timeout or can't open connection.

[edit2: Also, what does the HRESULT code mean?]

-32 (0xFFFFFFE0) is defined as E_CONNECTION_LOST_CANNOT_REOPEN, but while opening connection it means that no data are received within specified timeout.