TV stream stops every day at certain time, certain channel (2 Viewers)

[Schaussi]

Unfortunately, my problem seems not to be solved with the patched dll.
The recorded file of ORF2O HD works fine for the first 10 minutes, then it looks like it skips the local news, after news are finished it works again. Playing the file in Windows Media Player, the file also seems to be damaged after about 10 minutes.
I have recorded ORF1 HD in parallel like you described, this one was recorded fine.

 

[mm1352000]

@Schaussi
Unfortunately your log files are useless to me because of this:
[2015-07-20 17:01:08,019] [Log ] [4 ] [INFO ] - Set loglevel to: Warning

That means I can't see anything.
Please could you set the log level to debug (TV Server configuration, general section), then restart the TV service, and try to reproduce the problem again with the news tonight.

 

[HTPCSourcer]

@mm1352000 ,
Did you notice posting #30?

 

[mm1352000]

Did you notice posting #30?

Ahhh, no sorry I didn't. Apologies for that.
I'm looking at it now. Expect a response in the next 30 minutes or so...

 

[mm1352000]

@HTPC_Sourcer
It looks like I messed up the patch. Sorry again!

In your log files I see channel A's recording start:
[2015-07-20 18:05:00,365] [Log ] [scheduler thread] [DEBUG] - Scheduler: Check recordings for schedule Monsieur Claude und seine Töchter...
[2015-07-20 18:05:00,381] [Log ] [scheduler thread] [INFO ] - Scheduler: Time to record Sky Cinema HD 18:05-18:45 Manuell (Sky Cinema HD)

[collapse]
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 SendPMT version:5 len:94 131
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [DEBUG] - Digital Devices:--> Setting service id 0 for decrypting returned 0
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [DEBUG] - Digital Devices:--> Setting service id 131 for decrypting returned 0
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 cam flags:True
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 SetMpegPidMapping
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:4FF pcr
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:64 pmt
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:20 teletext type:6
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:20 teletext type:6
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:30 type:5
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:4FF video type:H.264
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:4FF video type:H.264
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 pid:503 audio lang:deu type:AC3
[2015-07-20 18:05:01,601] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:503 audio lang:deu type:AC3[/collapse]

Note the 2 entries "Digital Devices: --> ...". The first one is not meant to be there unless the change is dynamic. That's the mistake I made in the patch.

Anyhow, we see the second recording on channel B as well:
[2015-07-20 18:05:03,176] [Log ] [scheduler thread] [DEBUG] - Scheduler: Check recordings for schedule Tammy - Voll abgefahren...
[2015-07-20 18:05:03,176] [Log ] [scheduler thread] [INFO ] - Scheduler: Time to record Sky Cinema+1 HD 18:05-18:45 Manuell (Sky Cinema+1 HD)

[collapse]
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 SendPMT version:8 len:109 134
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [DEBUG] - Digital Devices:--> Setting service id 0 for decrypting returned 0
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [DEBUG] - Digital Devices:--> Setting service id 134 for decrypting returned 0
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 cam flags:True
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 SetMpegPidMapping
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:FF pcr
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:60 pmt
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:20 teletext type:6
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:20 teletext type:6
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:30 type:5
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:FF video type:H.264
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:FF video type:H.264
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:103 audio lang:deu type:AC3
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:103 audio lang:deu type:AC3
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 pid:104 audio lang:eng type:AC3
[2015-07-20 18:05:04,254] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:104 audio lang:eng type:AC3[/collapse]

Your test setup is perfect. All the audio streams as expected, and then the change:
[collapse]
[2015-07-20 18:07:01,476] [Log ] [27 ] [INFO ] - subch:0 OnPMTReceived() pmt:64 ran:True dynamic:True
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - subch:0 SendPmt:83 83 5 7
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - Decode pmt
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - descr1 len:6 9 4 18 33 f8 b6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - descr1 len:6 9 4 9 c4 fb b6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - descr1 len:6 9 4 9 af ff b6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - descr1 len:6 9 4 9 8c fa b6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - Set descriptor data with length 3
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - PROBLEM : descriptor lengths dont match 7 10
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - Set descriptor data with length 3
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - Set descriptor data with length 6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - PROBLEM : descriptor lengths dont match 3 9
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - Set descriptor data with length 6
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - PROBLEM : descriptor lengths dont match 3 9
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - subch:0 SendPMT version:7 len:115 131
[2015-07-20 18:07:01,476] [Log ] [PMT update] [DEBUG] - Digital Devices:--> Setting service id 131 for decrypting returned 0
[2015-07-20 18:07:01,476] [Log ] [PMT update] [INFO ] - subch:0 cam flags:True
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 SetMpegPidMapping
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:4FF pcr
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:64 pmt
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:20 teletext type:6
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 map pid:20 teletext type:6
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:30 type:5
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:4FF video type:H.264
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 map pid:4FF video type:H.264
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:503 audio lang:deu type:AC3
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 map pid:503 audio lang:deu type:AC3
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 pid:504 audio lang:eng type:AC3
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - subch:0 map pid:504 audio lang:eng type:AC3
[2015-07-20 18:07:01,492] [Log ] [PMT update] [INFO ] - SetRecorderPids
[2015-07-20 18:07:01,492] [Log ] [PMT update] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
[2015-07-20 18:07:01,492] [Log ] [27 ] [INFO ] - PID seen - type = Video
[2015-07-20 18:07:01,492] [Log ] [27 ] [DEBUG] - Recorder audioVideoEventHandler Video
[2015-07-20 18:07:01,523] [Log ] [27 ] [INFO ] - PID seen - type = Audio
[2015-07-20 18:07:01,523] [Log ] [27 ] [DEBUG] - Recorder audioVideoEventHandler Audio[/collapse]

This time you can see only one "Digital Devices:--> Setting service id..." entry. There should have been a second one like when the recordings started.

However, your test does give me a lot of hope that a proper patch ( ) will fix the problem. I have hope because the starting of the second recording did not affect the first recording... and with this stupid mistake in the patch, there was a chance that could have happened.

Hopefully the patch that is attached will be the last. I triple checked the code...

 

[HTPCSourcer]

and with this stupid mistake in the patch

Need a lash?

Hopefully the patch that is attached will be the last.

Will test tonight, provided there is some "Making of" or similar, that I can set the target on. Expect the logs tomorrow morning your time.

 

[Stéphane Lenclud]

Are we planning to fix this for 1.13 then?

 

[HTPCSourcer]

Are we planning to fix this for 1.13 then?

Well, let's first see if the new version works in my setup...

We may want to put this into Area 51 first for a broader audience to test for any regression. If no issues OK to add it to 1.13pre.

 

[mm1352000]

Need a lash?

I probably deserve a lashing, yes.
Looking forward to your results...

Are we planning to fix this for 1.13 then?

These days my work is always aimed at TVE 3.5. Anything I learn from these patches will be integrated there. I don't assume anything about a fix for TVE 3. In fact, I don't assume anything until a fix is confirmed. This issue is tricky. It would be easy to introduce a regression that is worse than the original problem.

 

[HTPCSourcer]

Here is your new set of logs for V2 in the following scenario:

Channel 1: watching show "Amerika von oben"
Channel 2: Recording starts at 20:10 - "The Prince"
Channel 3: Recording starts at 20:10 - "Stereo"

1. Regression! The very moment when the recordings start, Channel 1 freezes! No way to get it back on other than stop and restart the channel.
2. At ~+5:15 a new audio channel is added to Channel 2. This new audio stream is successfully decrypted and audible

I don't know if (1) is happening anyway or a regression was introduced with the patch, but I'll keep the lash ready just in case