[confirm] MPEG2 discontinuities and dropped frames (1 Viewer)

twemperor

MP Donator
  • Premium Supporter
  • March 10, 2010
    103
    28
    Home Country
    United States of America United States of America
    MediaPortal Version: 1.2.0.0
    MediaPortal Skin: StreamedMP
    Windows Version: XP Service Pack 3
    CPU Type: Core 2 Duo 2.4Ghz
    HDD:
    Memory:
    Motherboard:
    Video Card: ATI 1650 Pro
    Video Card Driver:
    Sound Card:
    Sound Card AC3:
    Sound Card Driver:
    1. TV Card: ATI 650 Theatre Pro
    1. TV Card Type: ATSC / NTSC
    1. TV Card Driver:
    2. TV Card: Avermedia m780
    2. TV Card Type: ATSC/NTSC
    2. TV Card Driver:
    3. TV Card:
    3. TV Card Type:
    3. TV Card Driver:
    4. TV Card:
    4. TV Card Type:
    4. TV Card Driver:
    MPEG2 Video Codec: Intervideo
    MPEG2 Audio Codec: Intervideo
    h.264 Video Codec: Arcsoft
    Satelite/CableTV Provider: DirecTV
    HTPC Case:
    Cooling:
    Power Supply:
    Remote:
    TV:
    TV - HTPC Connection:

    I just upgraded to 1.2 (perhaps I need a clean install? I'll try that tomorrow) and playback for any SD MPEG2 has a *lot* of dropped frames. Oddly, HD MPEG2 is better (upscaling? but original aspect ratio has no effect) and H.264 is perfect.

    I've attached logs with all the late B frames. I'll try a few other things and report back. I tried a few different codecs, but this worked great in 1.1.2.
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Hi twemperor

    It does seem like a codec issue. Are you talking about MPEG 2 TV or MPEG 2 video files? If files, what file extensions?
     

    twemperor

    MP Donator
  • Premium Supporter
  • March 10, 2010
    103
    28
    Home Country
    United States of America United States of America
    I'm talking about TV files (.ts), both files recorded with 1.1.2 and 1.2. It seemed like a codec issue, but I've tried a number of codecs that all worked in 1.1.2. It makes me wonder if there is something just different enough in 1.2, and if anyone else sees it.
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Okay, so you're changing the "MPEG 2 Video decoder" setting under "TV Codecs" (ie. you're *not* changing the "video codecs" setting)?

    Based on the codecs that I see installed on your client I'd be recommending you stick with either FFDShow or Intervideo. Make sure you use the codecs in pairs - in other words, if you use the FFDShow decoder for MPEG 2 video then it is highly recommended that you use the FFDShow decoder for audio too. If you really get stuck you could try the "MPC-MPEG-2 Video Decoder (Gabest)" with the "MPC - MPA Decoder Filter"...
     

    twemperor

    MP Donator
  • Premium Supporter
  • March 10, 2010
    103
    28
    Home Country
    United States of America United States of America
    Yes, I use the codecs in pairs- but I have the problem with either TV or videos (I suppose the codecs are picked by file extension, not plugin?). I did a fresh install of 1.2 beta- no plugins at all and I have the same behavior. The same videos play great in VLC, for example. I even used graphedit to confirm my codecs.

    Edit: I thought that it was only SD MPEG2, but the playback also drops frames in HD (just not as often), which is weird. I dropped back to 1.1.2 (fresh install, no plugins, video only). Video playback was great, like normal. FFDShow is the codec in both installations. Logs attached.
     

    infinite.loop

    Retired Team Member
  • Premium Supporter
  • December 26, 2004
    16,163
    4,133
    127.0.0.1
    Home Country
    Austria Austria
    Yes, I use the codecs in pairs- but I have the problem with either TV or videos
    Please have a look at the note in "MediaPortal Configuration -> Codecs and Renderer -> Video Codecs"

    It explains that for playback of *.ts files inside Video, codecs as configured for Television will be used.

    Could you upload a sample of such a recording somewhere so we can have a look?
     

    twemperor

    MP Donator
  • Premium Supporter
  • March 10, 2010
    103
    28
    Home Country
    United States of America United States of America
    I will post the beginning of one of my test video files when I get home later tonight. In the mean time, I wanted to highlight what I thought was odd in the log files. Specifically, the drastically different number in discontinuities detected in the tsreader log.

    In 1.1.2 (smooth playback), some discontinuity is detected without dropping frames. The log reports:

    Code:
    01-05-2011 22:24:40.270 [f74]  MPEG I-FRAME found 0.970000 
    01-05-2011 22:24:40.270 [f74]  MPEG First '0' frame found. 0.936000 
    01-05-2011 22:24:40.676 [f74]Audio Samples : 8, First : 0.111, Last : 1.231
    01-05-2011 22:24:40.676 [f74]Video Samples : 55, First : 0.936, Last : 1.871
    01-05-2011 22:24:40.676 [f74]Compensation : ( Rnd : 0 mS ) Audio pts ahead Video Pts ( Recover skipping Audio ) ....
    01-05-2011 22:24:40.676 [f74]aud:Compensation:0.936, Clock on start 0.000 m_rtStart:0 
    01-05-2011 22:24:40.676 [1548]vid:set discontinuity
    01-05-2011 22:24:40.676 [1548]Vid/Ref : 0.970, Late I-frame(02), Compensated = 0.034 ( 0.034 A/V buffers=01/55), Clk : 0.000000, State 1
    01-05-2011 22:24:40.676 [f74]aud:set discontinuity
    01-05-2011 22:24:40.676 [f74]Aud/Ref : 1.071, Late              Compensated = 0.135 ( 0.135 A/V buffers=02/55), Clk : 0.000000, State 1
    01-05-2011 22:24:40.676 [1548]Vid/Ref : 0.936, Late B-frame(00), Compensated = 0.000 ( 0.000 A/V buffers=01/54), Clk : 0.000000, State 1
    01-05-2011 22:24:40.692 [f74]Aud/Ref : 1.231, Late              Compensated = 0.295 ( 0.295 A/V buffers=01/53), Clk : 0.000000, State 1
    01-05-2011 22:24:40.692 [1548]Vid/Ref : 0.953, Late B-frame(01), Compensated = 0.017 ( 0.017 A/V buffers=00/54), Clk : 0.000000, State 1
    01-05-2011 22:24:40.692 [1548]Vid/Ref : 1.020, Late P-frame(05), Compensated = 0.084 ( 0.084 A/V buffers=00/54), Clk : 0.000000, State 1
    01-05-2011 22:24:40.692 [1548]Vid/Ref : 0.986, Late B-frame(03), Compensated = 0.050 ( 0.050 A/V buffers=00/55), Clk : 0.000000, State 1
    01-05-2011 22:24:40.707 [f74]Aud/Ref : 1.391, Late              Compensated = 0.455 ( 0.455 A/V buffers=01/61), Clk : 0.000000, State 1
    01-05-2011 22:24:40.723 [f74]Aud/Ref : 1.551, Late              Compensated = 0.615 ( 0.615 A/V buffers=01/70), Clk : 0.000000, State 1
    01-05-2011 22:24:40.739 [1548]Vid/Ref : 1.003, Late B-frame(04), Compensated = 0.067 ( 0.067 A/V buffers=00/70), Clk : 0.000000, State 1
    01-05-2011 22:24:40.770 [f74]Aud/Ref : 1.711, Late              Compensated = 0.775 ( 0.775 A/V buffers=01/79), Clk : 0.000000, State 1
    01-05-2011 22:24:40.801 [14e4]CTsReaderFilter::Run(132427.52) state 1 seeking 0
    01-05-2011 22:24:40.801 [14e4]CTsReaderFilter::Run(132427.52) state 2 -->done
    01-05-2011 22:24:40.832 [1548]Vid/Ref : 1.070, Late P-frame(08), Compensated = 0.134 ( 0.106 A/V buffers=00/79), Clk : 0.028000, State 2
    01-05-2011 22:24:40.848 [1548]Vid/Ref : 1.036, Late B-frame(06), Compensated = 0.100 ( 0.052 A/V buffers=00/78), Clk : 0.048000, State 2
    01-05-2011 22:24:40.864 [1548]Vid/Ref : 1.053, Late B-frame(07), Compensated = 0.117 ( 0.065 A/V buffers=00/77), Clk : 0.052000, State 2
    01-05-2011 22:24:40.879 [1548]Vid/Ref : 1.120, Late P-frame(11), Compensated = 0.184 ( 0.113 A/V buffers=00/76), Clk : 0.071000, State 2
    01-05-2011 22:24:40.910 [1548]Vid/Ref : 1.087, Late B-frame(09), Compensated = 0.151 ( 0.044 A/V buffers=00/75), Clk : 0.107000, State 2
    01-05-2011 22:24:40.926 [1548]Vid/Ref : 1.103, Late B-frame(10), Compensated = 0.167 ( 0.041 A/V buffers=00/74), Clk : 0.126000, State 2
    01-05-2011 22:24:40.942 [1548]Vid/Ref : 1.170, Late P-frame(14), Compensated = 0.234 ( 0.104 A/V buffers=00/73), Clk : 0.130000, State 2
    01-05-2011 22:24:40.942 [1548]Vid/Ref : 1.137, Late B-frame(12), Compensated = 0.201 ( 0.071 A/V buffers=00/72), Clk : 0.130000, State 2
    01-05-2011 22:24:40.973 [1548]Vid/Ref : 1.153, Late B-frame(13), Compensated = 0.217 ( 0.047 A/V buffers=00/77), Clk : 0.170000, State 2
    01-05-2011 22:24:40.973 [f74]Aud/Ref : 1.871, Late              Compensated = 0.935 ( 0.765 A/V buffers=01/77), Clk : 0.170000, State 2
    01-05-2011 22:24:40.989 [1548]Vid/Ref : 1.220, Late P-frame(17), Compensated = 0.284 ( 0.096 A/V buffers=00/76), Clk : 0.188500, State 2
    01-05-2011 22:24:41.004 [1548]Vid/Ref : 1.187, Late B-frame(15), Compensated = 0.251 ( 0.044 A/V buffers=00/75), Clk : 0.207500, State 2

    I don't know if it's relevant, but it goes to state 1 first.

    Whereas in 1.2 Beta, there are a lot more discontinuities and goes to state 2 first:

    Code:
    30-04-2011 21:25:18.020 [768]  MPEG I-FRAME found 0.970000 
    30-04-2011 21:25:18.020 [768]  MPEG First '0' frame found. 0.936000 
    30-04-2011 21:25:18.410 [768]Audio Samples : 8, First : 0.111, Last : 1.231
    30-04-2011 21:25:18.410 [768]Video Samples : 55, First : 0.936, Last : 1.871
    30-04-2011 21:25:18.410 [768]Compensation : ( Rnd : 0 mS ) Audio pts ahead Video Pts ( Recover skipping Audio ) ....
    30-04-2011 21:25:18.410 [768]aud:Compensation:0.344, Clock on start 0.592 m_rtStart:0 
    30-04-2011 21:25:18.410 [768]aud:set discontinuity
    30-04-2011 21:25:18.410 [768]Aud/Ref : 1.071, Late              Compensated = 0.727 ( 0.135 A/V buffers=02/55), Clk : 0.592000, State 2
    30-04-2011 21:25:18.410 [fd0]vid:set discontinuity
    30-04-2011 21:25:18.410 [fd0]Vid/Ref : 0.970, Late I-frame(02), Compensated = 0.626 ( 0.030 A/V buffers=01/55), Clk : 0.596000, State 2
    30-04-2011 21:25:18.520 [768]Aud/Ref : 1.231, Late              Compensated = 0.887 ( 0.193 A/V buffers=01/54), Clk : 0.694000, State 2
    30-04-2011 21:25:18.582 [fd0]Vid/Ref : 0.936, Late B-frame(00), Compensated = 0.592 ( -0.179 A/V buffers=00/65), Clk : 0.770917, State 2
    30-04-2011 21:25:18.582 [fd0]Vid/Ref : 0.953, Late B-frame(01), Compensated = 0.609 ( -0.162 A/V buffers=00/64), Clk : 0.770917, State 2
    30-04-2011 21:25:18.582 [768]Aud/Ref : 1.391, Late              Compensated = 1.047 ( 0.276 A/V buffers=01/64), Clk : 0.770917, State 2
    30-04-2011 21:25:18.582 [fd0]Vid/Ref : 1.020, Late P-frame(05), Compensated = 0.676 ( -0.095 A/V buffers=00/63), Clk : 0.770917, State 2
    30-04-2011 21:25:18.582 [fd0]Vid/Ref : 0.986, Late B-frame(03), Compensated = 0.642 ( -0.129 A/V buffers=00/62), Clk : 0.770917, State 2
    30-04-2011 21:25:18.614 [768]Aud/Ref : 1.551, Late              Compensated = 1.207 ( 0.416 A/V buffers=01/70), Clk : 0.791250, State 2
    30-04-2011 21:25:18.629 [768]Aud/Ref : 1.711, Late              Compensated = 1.367 ( 0.552 A/V buffers=01/80), Clk : 0.814667, State 2
    30-04-2011 21:25:18.660 [768]Aud/Ref : 1.871, Late              Compensated = 1.527 ( 0.677 A/V buffers=01/86), Clk : 0.850042, State 2

    I skipped in the video a couple of times to try a few different places in my test, and frames were always dropped. You can see in the log that it always goes to state 2.

    Code:
    30-04-2011 21:25:21.895 [17b0]CTsReaderFilter::Pause() - IsTimeShifting = 0 - state = 2
    30-04-2011 21:25:21.895 [17b0]CTsReaderFilter::Pause() - END - state = 1
    30-04-2011 21:25:21.895 [17b0]CTsReaderFilter::--SeekStart()-- LiveTv : 0, TimeShifting: 0 63.395 ( Abs 63.395000 / 3655.356934 ), OnZap: 0, Force 0, ForceRC 0, Media changing 0
    30-04-2011 21:25:21.910 [17b0]demux:flush audio
    30-04-2011 21:25:21.910 [17b0]demux:flush video
    30-04-2011 21:25:21.910 [17b0]CTsReaderFilter::  Seek-> 63.395000/3655.356000
    30-04-2011 21:25:21.910 [17b0]seek to 63.395000 filepos:494c798 pid:30
    30-04-2011 21:25:22.176 [17b0] stop seek: 63.479137 at 53503a3 - target: 63.395000, diff: 0.084137
    30-04-2011 21:25:22.176 [768]aud:OnThreadStartPlay(63.395000) 1.00
    30-04-2011 21:25:22.176 [17b0]vid: SetStart, m_rtStart 63.395000
    30-04-2011 21:25:22.176 [fd0]vid:OnThreadStartPlay(63.395000) 1.00 0
    30-04-2011 21:25:22.176 [17b0]vid: UpdateFromSeek, m_rtStart 63.395000, m_dRateSeeking 1.000000
    30-04-2011 21:25:22.176 [17b0]CTsReaderFilter::--SeekStart()-- No new seek 63.395000 ( Abs 63.395000 / 3655.356934 ) - Stream compensated: 0, OnZap: 0, Force 0, Media changing: 0
    30-04-2011 21:25:22.176 [17b0]CTsReaderFilter::--SeekStart()-- No new seek 63.395000 ( Abs 63.395000 / 3655.356934 ) - Stream compensated: 0, OnZap: 0, Force 0, Media changing: 0
    30-04-2011 21:25:22.176 [17b0]CTsReaderFilter::Run(42468.90) state 1 seeking 0
    30-04-2011 21:25:22.176 [17b0]CTsReaderFilter::Run(42468.90) state 2 -->done
    30-04-2011 21:25:22.223 [768]  MPEG I-FRAME found 64.283000 
    30-04-2011 21:25:22.223 [768]  MPEG First '0' frame found. 64.250000 
    30-04-2011 21:25:22.598 [768]Audio Samples : 7, First : 63.631, Last : 64.591
    30-04-2011 21:25:22.598 [768]Video Samples : 61, First : 64.250, Last : 65.251
    30-04-2011 21:25:22.598 [768]Compensation : ( Rnd : 0 mS ) Audio pts ahead Video Pts ( Recover skipping Audio ) ....
    30-04-2011 21:25:22.598 [768]aud:Compensation:0.450, Clock on start 0.404 m_rtStart:63395 
    30-04-2011 21:25:22.614 [768]aud:set discontinuity
    30-04-2011 21:25:22.614 [768]Aud/Ref : 64.271, Late              Compensated = 0.425 ( 0.002 A/V buffers=03/61), Clk : 0.423000, State 2
    30-04-2011 21:25:22.614 [fd0]vid:set discontinuity
    30-04-2011 21:25:22.614 [fd0]Vid/Ref : 64.283, Late I-frame(02), Compensated = 0.437 ( 0.014 A/V buffers=02/61), Clk : 0.423000, State 2
    30-04-2011 21:25:22.629 [fd0]Vid/Ref : 64.250, Late B-frame(00), Compensated = 0.404 ( -0.034 A/V buffers=01/60), Clk : 0.438000, State 2
    30-04-2011 21:25:22.629 [fd0]Vid/Ref : 64.266, Late B-frame(01), Compensated = 0.420 ( -0.018 A/V buffers=01/59), Clk : 0.438000, State 2
    30-04-2011 21:25:22.629 [768]Aud/Ref : 64.431, Late              Compensated = 0.585 ( 0.147 A/V buffers=02/60), Clk : 0.438000, State 2
    30-04-2011 21:25:22.629 [fd0]Vid/Ref : 64.333, Late P-frame(05), Compensated = 0.487 ( 0.049 A/V buffers=01/58), Clk : 0.438000, State 2
    30-04-2011 21:25:22.629 [fd0]Vid/Ref : 64.300, Late B-frame(03), Compensated = 0.454 ( 0.021 A/V buffers=01/57), Clk : 0.433000, State 2
    30-04-2011 21:25:22.645 [768]Aud/Ref : 64.591, Late              Compensated = 0.745 ( 0.296 A/V buffers=01/56), Clk : 0.449000, State 2
    30-04-2011 21:25:22.645 [fd0]Vid/Ref : 64.316, Late B-frame(04), Compensated = 0.470 ( 0.021 A/V buffers=00/56), Clk : 0.449000, State 2
    30-04-2011 21:25:22.676 [768]Aud/Ref : 64.751, Late              Compensated = 0.905 ( 0.422 A/V buffers=01/62), Clk : 0.483208, State 2

    Except at the very end, it goes to state 1.

    Code:
    30-04-2011 21:25:58.004 [17b0]CTsReaderFilter::Pause() - IsTimeShifting = 0 - state = 2
    30-04-2011 21:25:58.004 [17b0]CTsReaderFilter::Pause() - END - state = 1
    30-04-2011 21:25:58.020 [fd0]Vid/Ref : 99.468, Late P-frame(29), Compensated = 35.622 ( -0.126 A/V buffers=00/126), Clk : 35.747665, State 1
    30-04-2011 21:25:58.020 [fd0]Vid/Ref : 99.435, Late B-frame(27), Compensated = 35.589 ( -0.159 A/V buffers=00/125), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.451, Late B-frame(28), Compensated = 35.605 ( -0.143 A/V buffers=00/124), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.518, Late P-frame(32), Compensated = 35.672 ( -0.076 A/V buffers=00/123), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.485, Late B-frame(30), Compensated = 35.639 ( -0.109 A/V buffers=00/122), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.502, Late B-frame(31), Compensated = 35.656 ( -0.092 A/V buffers=00/121), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.568, Late P-frame(35), Compensated = 35.722 ( -0.026 A/V buffers=00/120), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [17b0]CTsReaderFilter::Stop()
    30-04-2011 21:25:58.035 [a54]CTsReaderFilter::ThreadProc stopped()
    30-04-2011 21:25:58.035 [17b0]CTsReaderFilter::Stop()  -stop source
    30-04-2011 21:25:58.035 [fd0]Vid/Ref : 99.535, Late B-frame(33), Compensated = 35.689 ( -0.059 A/V buffers=00/119), Clk : 35.747665, State 1
    30-04-2011 21:25:58.035 [17b0]CTsReaderFilter::Stop()  -stop source done

    Which, if this is the end, I don't know what it's doing (two threads?). Here's what 1.1.2 did at the end of playback:

    Code:
    01-05-2011 22:24:52.879 [a0c]CTsReaderFilter::Pause() - IsTimeShifting = 0 - state = 2
    01-05-2011 22:24:52.879 [a0c]CTsReaderFilter::Pause() - END - state = 1
    01-05-2011 22:24:52.895 [a0c]CTsReaderFilter::Stop()
    01-05-2011 22:24:52.895 [e40]CTsReaderFilter::ThreadProc stopped()
    01-05-2011 22:24:52.895 [a0c]CTsReaderFilter::Stop()  -stop source

    I'm clearly not an expert in this code, or I would try to debug it myself. I just wanted to highlight in the logs what I thought was weird. These are both playbacks of the same video file, using the videos plugin with MediaPortal in full debug mode (no skin, no plugins). I'm sorry the codecs happened to be different for these runs, but I tried several codecs (a set from which I know all work in 1.1.2). It kind of looks like the starting clock is off and it never fully compensates.

    Edit: attached ~18s of test video.
     

    tourettes

    Retired Team Member
  • Premium Supporter
  • January 7, 2005
    17,301
    4,800
    TsReader wont ever drop frames - what you are seeing is that TSReader is patching the timestamps to keep A/V sync after startup or seek. If there is no visible difference in the video playback itself then you should just ignore those really verbose log lines that TsReader writes.
     

    twemperor

    MP Donator
  • Premium Supporter
  • March 10, 2010
    103
    28
    Home Country
    United States of America United States of America
    TsReader wont ever drop frames - what you are seeing is that TSReader is patching the timestamps to keep A/V sync after startup or seek. If there is no visible difference in the video playback itself then you should just ignore those really verbose log lines that TsReader writes.

    Well, I am seeing very visible difference, ~40% dropped frames. In looking through the logs, this is the only other difference I can find and I'm trying to correlate. This may be an unimportant difference, but it's correlated.
     

    infinite.loop

    Retired Team Member
  • Premium Supporter
  • December 26, 2004
    16,163
    4,133
    127.0.0.1
    Home Country
    Austria Austria
    TsReader wont ever drop frames - what you are seeing is that TSReader is patching the timestamps to keep A/V sync after startup or seek. If there is no visible difference in the video playback itself then you should just ignore those really verbose log lines that TsReader writes.

    Well, I am seeing very visible difference, ~40% dropped frames. In looking through the logs, this is the only other difference I can find and I'm trying to correlate. This may be an unimportant difference, but it's correlated.
    Does the framerate of the content you play match the freq. of your display?
    i.e. 25fps - 50 Hz or 30fps - 60 Hz.

    with 25fps on 60Hz you will have many dropped frames. that is normal.
     

    Users who are viewing this thread

    Top Bottom