MP2 - V2.1 [MP2-594] Occasionally no picture when changing channels (1 Viewer)

[morpheus_xx]

@Owlsroost I could reproduce this error and collected log files. Could you take a look at tsreader.log and have a guess what is happening here, please?

As summary:
Tuning started on "NDR HD", then one channel change to "PHOENIX HD". Timeshifting works well, but on client side the TsReader logs a timeout. The result is as described here: a black screen, no video, but OSD and channel switching are still working. Stopping playback and re-tune works as well.

Note: both channels are free-to-air, so an influence by CAM is out of question (I don't even have one anymore )

Edit: my first investigation lead to media type change callback timing out. But I added logging on Client side and callback is not executed?!

Next I checked TsReader interfaces and stumbled upon differences in interface signature:

vs. C# side (this is same in MP1+MP2!)

Logs attached

@HTPCSourcer could you add this to jira, please?

 

[morpheus_xx]

Any other @Developers can help?

 

[morpheus_xx]

I think I have found it, but it is not clear why it happens.

The issue seems to be related to audio stream selection on zapping. C# side looks like:
[2017-01-23 19:01:03,713] [46621 ] [107 ] [DEBUG] - SubtitleRenderer: RESET
[2017-01-23 19:01:03,718] [46626 ] [107 ] [DEBUG] - Stream TsReader|0: MajorType 73647561-0000-0010-8000-00aa00389b71; Name deu; PWDGroup: 1; LCID: 3079
[2017-01-23 19:01:03,723] [46631 ] [107 ] [DEBUG] - Stream TsReader|1: MajorType 73647561-0000-0010-8000-00aa00389b71; Name mis; PWDGroup: 1; LCID: 0
[2017-01-23 19:01:03,727] [46635 ] [107 ] [DEBUG] - Stream TsReader|2: MajorType 73647561-0000-0010-8000-00aa00389b71; Name deu; PWDGroup: 1; LCID: 3079
[2017-01-23 19:01:03,749] [46657 ] [107 ] [DEBUG] - MpcStreamInfoHandler: Enable stream 'No subtitles'
[2017-01-23 19:01:03,752] [46660 ] [107 ] [DEBUG] - StreamInfoHandler: Enable stream 'deu (AC3 6ch)'
[2017-01-23 19:01:03,758] [46666 ] [107 ] [DEBUG] - LiveTvPlayer: End zapping

TsReader looks like:
[2017-01-23 19:01:03,705] [17000048] [ e78] - CTsReaderFilter::--SeekPreStart()-- No new seek 16.409000 ( Abs 16.409000 / 16.409323 ) - isSamePosn: 1, OnZap: 0, Force 0, Media changing: 0
[2017-01-23 19:01:03,705] [17000048] [1b70] - CTsReaderFilter:: ForcePosnUpdate: 16.409 s
[2017-01-23 19:01:03,753] [17000048] [ e78] - SetAudioStream : 2
[2017-01-23 19:01:03,753] [17000048] [ e78] - Old Audio 3, New Audio 129
[2017-01-23 19:01:03,753] [17000048] [ e78] - SetAudioStream : SetMediaChanging(true)
[2017-01-23 19:01:03,753] [17000048] [ e78] - demux:Wait for media format change:1
[2017-01-23 19:01:03,753] [17000048] [ e78] - demux:Wait for Audio stream selection :0
[2017-01-23 19:01:04,302] [17000048] [1740] - OnNewChannel: New channel found (PAT/PMT/SDT changed)
[2017-01-23 19:01:04,302] [17000048] [1740] - pcr pid: 0x 30
[2017-01-23 19:01:04,302] [17000048] [1740] - pmt pid: 0x 20
[2017-01-23 19:01:04,302] [17000048] [1740] - Video pid: 0x 30 type: H264 (0x1b) DescriptorData: 0x 0
[2017-01-23 19:01:04,302] [17000048] [1740] - Audio pid: 0x 40 type: MPEG1 - audio (0x 3) language: deu
[2017-01-23 19:01:04,302] [17000048] [1740] - Audio pid: 0x 41 type: MPEG1 - audio (0x 3) language: mul
[2017-01-23 19:01:04,307] [17000048] [1740] - OnNewChannel: Video media type changed. SetMediaChanging(true)...
[2017-01-23 19:01:04,308] [17000048] [1740] - OnNewChannel: OnRequestAudioChange()
[2017-01-23 19:01:04,308] [17000048] [1740] - demux:Wait for Audio stream selection :1
[2017-01-23 19:01:04,313] [17000048] [1740] - SetAudioStream : 2
[2017-01-23 19:01:04,313] [17000048] [1740] - SetAudioStream out of range! Max: 2 <-- This I have added, so TsReader only knows about 2 streams at this time, not 3
[2017-01-23 19:01:04,314] [17000048] [1740] - CTsReaderFilter::OnGraphRebuild 3
[2017-01-23 19:01:04,314] [17000048] [1740] - demux:Wait for media format change:0
[2017-01-23 19:01:04,314] [17000048] [1740] - OnNewChannel: New Audio stream type = 0x81
[2017-01-23 19:01:04,314] [17000048] [1740] - CDeMultiplexer::ThreadProc - Flush
[2017-01-23 19:01:04,314] [17000048] [1740] - demux:Flush(), clearAVready = 1, isMidStream = 0
[2017-01-23 19:01:09,311] [17000048] [1ab4] - demux: Alert: Wait for Audio stream selection cancelled on 5 secs timeout

 

[HTPCSourcer]

Are you getting the missing AC3 stream at the tswriter side?

 

[Owlsroost]

Did the previous channel have an AC3 stream?
e.g.

[2017-01-23 17:02:30,553] [2ad59608] [1f2c] - demux:Wait for Audio stream selection :0
[2017-01-23 17:02:31,018] [2ad59608] [1010] - OnNewChannel: New channel found (PAT/PMT/SDT changed)
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  pcr      pid: 0x  30
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  pmt      pid: 0x  20
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  Video    pid: 0x  30 type: H264 (0x1b) DescriptorData: 0x 0
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  Audio    pid: 0x  40 type: MPEG1 - audio (0x 3) language: deu
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  Audio    pid: 0x  41 type: MPEG1 - audio (0x 3) language: mis
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  Audio    pid: 0x  42 type: AC3 (0x81) language: deu
[2017-01-23 17:02:31,018] [2ad59608] [1010] -  Subtitle pid: 0x  50 type: DVB subtitle 2 (0x 6) language: deu

...zaps to:

[2017-01-23 17:02:42,866] [2ad59608] [1010] - OnNewChannel: New channel found (PAT/PMT/SDT changed)
[2017-01-23 17:02:42,866] [2ad59608] [1010] -  pcr      pid: 0x  30
[2017-01-23 17:02:42,866] [2ad59608] [1010] -  pmt      pid: 0x  20
[2017-01-23 17:02:42,866] [2ad59608] [1010] -  Video    pid: 0x  30 type: H264 (0x1b) DescriptorData: 0x 0
[2017-01-23 17:02:42,866] [2ad59608] [1010] -  Audio    pid: 0x  40 type: MPEG1 - audio (0x 3) language: deu
[2017-01-23 17:02:42,866] [2ad59608] [1010] -  Audio    pid: 0x  41 type: MPEG1 - audio (0x 3) language: mul

...so is something not getting updated or cleared down at the zap, so it thinks the 3rd (AC3) audio stream is still available?

 

[morpheus_xx]

Yes, I just found the cause: inside TsReader callback there was only a "non forced" stream refresh, so the changed audio streams where not correctly updated.

I could fix this now, will create a branch soon.

Additionally I added "MPEG Audio Decoder" to blacklist, as it was preferred during graph rebuild and was causing other issues.

What do you think about the interface mismatch in first post? I changed C# return codes also to "void" instead of "int".

 

[Owlsroost]

What do you think about the interface mismatch in first post? I changed C# return codes also to "void" instead of "int".

'void' is correct for TsReader, so I assume the C# code should match it. I'll raise a Jira for MP1 to get the C# code changed.

SetMediaPosition() is redundant (it's just an empty method - it did something in very old versions of TsReader), so feel free to not call it