Opened 11 years ago

Closed 10 years ago

Last modified 10 years ago

#11882 closed Bug Report - Hang/Deadlock (fixed)

Attempt to play recording freezes frontend

Reported by: warpme@… Owned by: Jim Stichnoth
Priority: minor Milestone: 0.27.1
Component: MythTV - Video Decoding Version: 0.27-fixes
Severity: medium Keywords:
Cc: Ticket locked: no

Description

Today morning I was pointed by my family that some DVB-S2 HD channels are freezing mythtv. After long investigation (converter positioning check, mplex SID checking, etc) I ended with conclusion that root cause probably lays in kind of change in DVB video stream from satellite.

Interesting is that recordings .mpg files plays ok in VLC/mplayer so I think issue is about mythtv and H.264 stream bits.

I tested problematic recordings in mythtv on ION1 (hw decode with vdpau) and OSX (software decoder) - both freezes. Again - recordings in question are playing OK in VLC/mplayer.

Exemplary rec. file is on my FTP: ​ftp://mirekp:mirekp@warped.homenet.org/test.mpg

I'm on current 0.27-fixes.

Here is log from FE: 

2013-09-28 21:37:49.218018 I  Player(0): Video timing method: USleep with busy wait
2013-09-28 21:37:49.218062 I  Player(0): Display Refresh Rate: 70.067 Video Frame Rate: 25.000
2013-09-28 21:37:49.218089 I  Player(0): SetFrameInterval ps:1 scan:1
2013-09-28 21:37:49.219640 I  playCtx: StartPlaying(): took 0 ms to start player.
2013-09-28 21:37:49.219694 I  TV: Created player.
2013-09-28 21:37:49.219766 I  TV: StartPlayer(0, WatchingVideo, main) -- end ok
2013-09-28 21:37:49.219798 I  TV: Changing from None to WatchingVideo
2013-09-28 21:37:49.229151 I  TV: DrawUnusedRects() -- begin
2013-09-28 21:37:49.229218 I  TV: DrawUnusedRects() -- end
2013-09-28 21:37:49.229405 I  TV: Main UI disabled.
2013-09-28 21:37:49.229461 I  TV: HandleStateChange(0) -- end
2013-09-28 21:37:49.229693 I  TV: tv->Playback() -- end
2013-09-28 21:37:49.229748 I  TV: Entering main playback loop.
2013-09-28 21:37:49.236316 D  ScreenSaverX11Private: ResetTimer -- begin
2013-09-28 21:37:49.236342 D  ScreenSaverX11Private: StopTimer
2013-09-28 21:37:49.238667 D  ScreenSaverX11Private: StartTimer
2013-09-28 21:37:49.238790 D  ScreenSaverX11Private: ResetTimer -- end
2013-09-28 21:37:49.239450 I  Player(0): Waiting for video buffers...
2013-09-28 21:37:49.343062 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.453094 N  Player(0): Waited 213ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.559715 N  Player(0): Waited 320ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.662987 N  Player(0): Waited 423ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.773003 N  Player(0): Waited 533ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.876352 N  Player(0): Waited 637ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:49.983002 N  Player(0): Waited 743ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.089679 N  Player(0): Waited 850ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.192986 N  Player(0): Waited 953ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.299652 N  Player(0): Waited 1060ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.402979 N  Player(0): Waited 1163ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.509637 N  Player(0): Waited 1270ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.612993 N  Player(0): Waited 1373ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.722991 N  Player(0): Waited 1483ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.829644 N  Player(0): Waited 1590ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:50.936349 N  Player(0): Waited 1697ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.042985 N  Player(0): Waited 1803ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.146311 N  Player(0): Waited 1907ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.252977 N  Player(0): Waited 2013ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.356355 N  Player(0): Waited 2117ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.466302 N  Player(0): Waited 2227ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.572995 N  Player(0): Waited 2333ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.679659 N  Player(0): Waited 2440ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.783041 N  Player(0): Waited 2543ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.886336 N  Player(0): Waited 2647ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:51.992983 N  Player(0): Waited 2753ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.096329 N  Player(0): Waited 2857ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.199633 N  Player(0): Waited 2960ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.306310 N  Player(0): Waited 3067ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.409679 N  Player(0): Waited 3170ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.516322 N  Player(0): Waited 3277ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.622979 N  Player(0): Waited 3383ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.729661 N  Player(0): Waited 3490ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.836324 N  Player(0): Waited 3597ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:52.942987 N  Player(0): Waited 3703ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.046310 N  Player(0): Waited 3807ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.152996 N  Player(0): Waited 3913ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.262989 N  Player(0): Waited 4023ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.369648 N  Player(0): Waited 4130ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.476371 N  Player(0): Waited 4237ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.586314 N  Player(0): Waited 4347ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.693020 N  Player(0): Waited 4453ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.799655 N  Player(0): Waited 4560ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:53.902993 N  Player(0): Waited 4663ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:54.006309 N  Player(0): Waited 4767ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:54.112973 N  Player(0): Waited 4873ms for video buffers AAAAAAAAAAAAAA
2013-09-28 21:37:54.166989 D  [mpegts @ 0x7f9893870fc0] PES packet size mismatch
2013-09-28 21:37:54.167040 D  [mpegts @ 0x7f9893870fc0] PES packet size mismatch
2013-09-28 21:37:54.167596 E  decoding error
                        eno: Unknown error 541478725 (541478725)
2013-09-28 21:37:54.172967 I  waiting for no video frames 0
2013-09-28 21:37:54.172995 I  HasReachedEof() at framesPlayed=1 totalFrames=6950
2013-09-28 21:37:54.173037 I  AOBase: Pause 1
2013-09-28 21:37:54.182913 I  AOBase: OutputAudioLoop: audio paused
2013-09-28 21:37:54.243196 E  decoding error
                        eno: Unknown error 541478725 (541478725)
2013-09-28 21:37:54.249432 I  TV: HandleStateChange(0) -- begin
2013-09-28 21:37:54.249489 I  TV: Attempting to change from WatchingVideo to None
2013-09-28 21:37:54.249614 I  TV: StopStuff() for player ctx 0 -- begin
2013-09-28 21:37:54.249675 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- begin
2013-09-28 21:37:54.249880 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- end
2013-09-28 21:37:54.249936 I  Player(0): StopPlaying - begin
2013-09-28 21:37:54.259595 I  Player(0): Decoder thread exiting.
2013-09-28 21:37:54.259785 I  Player(0): Exited decoder loop.
2013-09-28 21:37:54.260268 D  Closing PAT Filter: pid=0x0
2013-09-28 21:37:54.260323 D  Closing PMT Filter: pid=0x446
2013-09-28 21:37:54.274414 I  VidOutVDPAU: DiscardFrames(1)
2013-09-28 21:37:54.274491 I  VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAA
2013-09-28 21:37:54.274530 I  VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAA -- done
2013-09-28 21:37:54.274559 I  VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAA -- done()
2013-09-28 21:37:54.290938 W  MythPainter: 39 images not yet de-allocated.
2013-09-28 21:37:54.290994 I  VDPAU Painter: Clearing VDPAU painter cache.
2013-09-28 21:37:54.337083 I  AOBase: Killing AudioOutputDSP
2013-09-28 21:37:54.383462 I  AOBase: OutputAudioLoop: Stop Event
2013-09-28 21:37:54.383485 I  AOBase: kickoffOutputAudioLoop exiting
2013-09-28 21:37:54.385133 I  Player(0): StopPlaying - end

Attachments (6)

be.log​ (170.6 KB) - added by warpme@… 11 years ago.
BE.log fro recording on bad channel
fe.log​ (179.2 KB) - added by warpme@… 11 years ago.
FE.lg from playing bad channel
mythtvgitdiff-master-AVD-SPS.txt​ (624 bytes) - added by blm-ubunet@… 10 years ago.
H264 must start with SPS
seektable-before​ (5.9 KB) - added by warpme@… 10 years ago.
seektable with comment7 patch before mythcommflag rebuild
seektable-after​ (174.0 KB) - added by warpme@… 10 years ago.
seektable with comment7 patch after mythcommflag rebuild
11882-require_SPS_for_state_change.patch​ (529 bytes) - added by jpoet 10 years ago.

Download all attachments as: .zip

Change History (29)

comment:1 Changed 11 years ago by warpme@…

I do some more tests with playback of bad recordings. Generally - I can play them in LiveTV rec group. First playback attempt is with 10-15sec of black screen + prompt about at "keep or delete", but next attempts are giving proper playback.

For testing - is this only LiveTV problem - I scheduled manual recording on bad channel.

Backend correctly starts recording. File size grows and previewgen gives correct preview. Starting playback on on-going recording hangs frontend. FE log shows tons of: 

2013-10-01 10:18:33.777596 I Player(0): Waited 10ms for decoder lock
2013-10-01 10:18:33.794258 I Player(0): Waited 10ms for decoder lock
2013-10-01 10:18:33.810924 I Player(0): Waited 10ms for decoder lock
2013-10-01 10:18:33.830931 I Player(0): Waited 10ms for decoder lock

Hang is repeatable so it looks like there is something wrong with recorder as recorder with on-going recording repeatably hangs player.

However when recording finishes - I can play recording - but again: first playback after 10sec of black screen exits with usual prompt about at "keep or delete". Next playbacks are OK. Cut editor works OK on such recording. Whole playback behaviour is exactly similar to LiveTV playback issues described at beginning of this update.

So it looks like for those bad channels recorder produces specific recording and this recording: -hangs player when recording is ongoing -when recording ends, playback attempt gives 10sec black screen+expit prompt at first playback attempt -next playbacks attempts are becomes OK

I hope some merciful dev soul will look at is as pressure from users constantly grows :-(

Changed 11 years ago by warpme@…

Attachment: be.log​ added

BE.log fro recording on bad channel

Changed 11 years ago by warpme@…

Attachment: fe.log​ added

FE.lg from playing bad channel

comment:3 in reply to:  2 Changed 11 years ago by warpme@…

Hi, For having analysis easier, I dump mpeg structure analysis for .mpeg files done under Elecard StreamEye?:

​http://warped.homenet.org/tvphd-bad/23205_20131008183000.txt.zip ​http://warped.homenet.org/tvphd-bad/8027_20131008182300.txt.zip ​http://warped.homenet.org/tvphd-bad/8032_20131008183400.txt.zip ​http://warped.homenet.org/bbchd-bad/11593_20131008184500.txt.zip ​http://warped.homenet.org/bbchd-bad/23715_20131008184900.txt.zip ​http://warped.homenet.org/bbchd-bad/8035_20131008184200.txt.zip

Hope it helps!

PS: Again TRACN not allows to put such number of links. PS2: Jim - thx for previous http fixes :-) [hhttp changed to http by stichnot]

Last edited 11 years ago by Jim Stichnoth (previous) (diff)

comment:4 Changed 11 years ago by Jim Stichnoth

Milestone: unknown → 0.27.1
Owner: set to Jim Stichnoth
Status: new → accepted

This patch "fixes" playback for at least the first 3 samples (other 3 not yet tested): 

diff --git a/mythtv/libs/libmythtv/avformatdecoder.cpp b/mythtv/libs/libmythtv/avformatdecoder.cpp
index 3a42b40..1db6e68 100644
--- a/mythtv/libs/libmythtv/avformatdecoder.cpp
+++ b/mythtv/libs/libmythtv/avformatdecoder.cpp
@@ -3281,7 +3281,7 @@ bool AvFormatDecoder::PreProcessVideoPacket(AVStream *curstream, AVPacket *pkt)
         }
     }
 
-    if (framesRead == 0 && !justAfterChange &&
+    if (false && framesRead == 0 && !justAfterChange &&
         !(pkt->flags & AV_PKT_FLAG_KEY))
     {
         av_free_packet(pkt);

This suggests a difference in the way our libmythtv/mpeg/H264Parser.cpp identifies keyframes, compared to the combination of libmythtv/avformatdecoder.cpp and external/FFmpeg/libavcodec/h264_parser.c.

comment:5 Changed 10 years ago by warpme@…

Jim, Sorry for long silence - I was out of home for last 4 days. Thx You look into this bug. I applied patch on current 0.27-fixes and it looks following:

-all bad channels are working but only if I tune to them from good channels.

-tuning from 1 bad channel to another bad channel gives error on fronted "video frame buffering failed too many times". Pls see attached log from fe. Error is the same for: jumping between channels within the same mplex or between channels from one bad mplex to another bad mplex. 

2013-10-22 19:30:30.321637 W RingBuf(myth://192.168.1.254:6543/8035_20131022173027.mpg): Not starting read ahead thread, already running
2013-10-22 19:30:30.331514 N Player(5): Forcing decode extra audio option on (Video method requires it).
2013-10-22 19:30:31.102640 I AFD: codec AC3 has 2 channels
2013-10-22 19:30:31.103581 I AFD: Opened codec 0x7fdea84d6f40, id(AC3) type(Audio)
2013-10-22 19:30:31.103642 I AFD: codec AC3 has 6 channels
2013-10-22 19:30:31.104535 I AFD: Opened codec 0x7fdf0a83e8e0, id(AC3) type(Audio)
2013-10-22 19:30:31.104667 I AFD: Opened codec 0x7fdf09573680, id(DVB_SUBTITLE) type(Subtitle)
2013-10-22 19:30:31.110565 I AFD: Opened codec 0x7fdf09bcc780, id(H264) type(Video)
2013-10-22 19:30:31.578660 I msg: On known multiplex...
2013-10-22 19:30:31.580951 I msg: On known multiplex...
2013-10-22 19:30:31.981558 N Player(5): Waited 109ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:32.094864 N Player(5): Waited 222ms for video buffers LAAAFDLDDLALAAAL
2013-10-22 19:30:32.198209 N Player(5): Waited 326ms for video buffers AALLFDADDLAALALA
2013-10-22 19:30:32.308225 N Player(5): Waited 436ms for video buffers ALAAFDLDDAALLAAL
2013-10-22 19:30:32.418283 N Player(5): Waited 546ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:32.528236 N Player(5): Waited 656ms for video buffers AAAAFDLDDLAALALL
2013-10-22 19:30:32.638239 N Player(5): Waited 766ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:32.741554 N Player(5): Waited 869ms for video buffers LLALFDLDDAAAAALL
2013-10-22 19:30:32.851547 N Player(5): Waited 979ms for video buffers ALAAFDADDALLLLAA
2013-10-22 19:30:32.961647 N Player(5): Waited 1089ms for video buffers LAAAFDLDDLLLAAAL
2013-10-22 19:30:33.071556 N Player(5): Waited 1199ms for video buffers AAALFDADDLAALALA
2013-10-22 19:30:33.181486 N Player(5): Waited 1309ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:33.284810 N Player(5): Waited 1412ms for video buffers LLAAFDADDALLAALA
2013-10-22 19:30:33.394840 N Player(5): Waited 1522ms for video buffers AAAAFDLDDALALALL
2013-10-22 19:30:33.498155 N Player(5): Waited 1626ms for video buffers ALALFDLDDLALLAAA
2013-10-22 19:30:33.608151 N Player(5): Waited 1736ms for video buffers LAALFDADDAAAALLL
2013-10-22 19:30:33.721477 N Player(5): Waited 1849ms for video buffers ALAAFDADDLLALALL
2013-10-22 19:30:33.824811 N Player(5): Waited 1952ms for video buffers LAAAFDLDDALLLAAA
2013-10-22 19:30:33.928156 N Player(5): Waited 2056ms for video buffers LAAAFDLDDLAAALLA
2013-10-22 19:30:34.038187 N Player(5): Waited 2166ms for video buffers AAALFDADDALALALL
2013-10-22 19:30:34.148147 N Player(5): Waited 2276ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:34.251489 N Player(5): Waited 2379ms for video buffers LLLAFDADDAALAAAL
2013-10-22 19:30:34.354816 N Player(5): Waited 2482ms for video buffers LLAAFDADDLLLAAAA
2013-10-22 19:30:34.464813 N Player(5): Waited 2592ms for video buffers LLAAFDADDALAALLA
2013-10-22 19:30:34.568197 N Player(5): Waited 2696ms for video buffers AAAAFDLDDALALALL
2013-10-22 19:30:34.671475 N Player(5): Waited 2799ms for video buffers AAAAFDLDDLALLLAA
2013-10-22 19:30:34.781466 N Player(5): Waited 2909ms for video buffers AAAAFDLDDLALLLAA
2013-10-22 19:30:34.884838 N Player(5): Waited 3012ms for video buffers LALLFDADDLALAAAA
2013-10-22 19:30:34.994818 N Player(5): Waited 3122ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:35.104802 N Player(5): Waited 3232ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:35.214811 N Player(5): Waited 3342ms for video buffers LLAAFDADDAAALALL
2013-10-22 19:30:35.318140 N Player(5): Waited 3446ms for video buffers ALAAFDADDALLLLAA
2013-10-22 19:30:35.421483 N Player(5): Waited 3549ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:35.531463 N Player(5): Waited 3659ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:35.641475 N Player(5): Waited 3769ms for video buffers LAAAFDLDDLLLAAAL
2013-10-22 19:30:35.751476 N Player(5): Waited 3879ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:35.854810 N Player(5): Waited 3982ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:35.964838 N Player(5): Waited 4092ms for video buffers AALLFDADDLAALALA
2013-10-22 19:30:36.068189 N Player(5): Waited 4196ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:36.171470 N Player(5): Waited 4299ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:36.281476 N Player(5): Waited 4409ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:36.391469 N Player(5): Waited 4519ms for video buffers AAAAFDLDDALALALL
2013-10-22 19:30:36.501475 N Player(5): Waited 4629ms for video buffers AAAAFDLDDLAALALL
2013-10-22 19:30:36.611475 N Player(5): Waited 4739ms for video buffers LALLFDADDLALAAAA
2013-10-22 19:30:36.721472 N Player(5): Waited 4849ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:36.831490 N Player(5): Waited 4959ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:36.941474 N Player(5): Waited 5069ms for video buffers LAALFDADDALLAAAL
2013-10-22 19:30:37.051529 N Player(5): Waited 5179ms for video buffers ALLAFDADDAAALALL
2013-10-22 19:30:37.161471 N Player(5): Waited 5289ms for video buffers ALAAFDADDLAALALL
2013-10-22 19:30:37.271481 N Player(5): Waited 5399ms for video buffers ALAAFDADDALLLLAA
2013-10-22 19:30:37.381477 N Player(5): Waited 5509ms for video buffers LAAAFDLDDALLAAAL
2013-10-22 19:30:37.491471 N Player(5): Waited 5619ms for video buffers LAAAFDLDDALLAAAL
2013-10-22 19:30:37.601467 N Player(5): Waited 5729ms for video buffers LAAAFDLDDALLAAAL
2013-10-22 19:30:37.711478 N Player(5): Waited 5839ms for video buffers LAAAFDLDDLAAALLA
2013-10-22 19:30:37.821500 N Player(5): Waited 5949ms for video buffers AAALFDADDLLALALL
2013-10-22 19:30:37.931478 N Player(5): Waited 6059ms for video buffers AAALFDADDAALLLAL
2013-10-22 19:30:38.041484 N Player(5): Waited 6169ms for video buffers LLAAFDADDLALAAAL
2013-10-22 19:30:38.144806 N Player(5): Waited 6272ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:38.248144 N Player(5): Waited 6376ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:38.358142 N Player(5): Waited 6486ms for video buffers AAAAFDLDDLAALALL
2013-10-22 19:30:38.468138 N Player(5): Waited 6596ms for video buffers AAAAFDLDDLAALALL
2013-10-22 19:30:38.578134 N Player(5): Waited 6706ms for video buffers AAAAFDLDDLAALALL
2013-10-22 19:30:38.688140 N Player(5): Waited 6816ms for video buffers LALLFDADDLALAAAA
2013-10-22 19:30:38.791469 N Player(5): Waited 6919ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:38.894816 N Player(5): Waited 7022ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:39.004800 N Player(5): Waited 7132ms for video buffers ALLAFDADDAAALALL
2013-10-22 19:30:39.114815 N Player(5): Waited 7242ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:39.224799 N Player(5): Waited 7352ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:39.334808 N Player(5): Waited 7462ms for video buffers LAAAFDLDDALLAAAL
2013-10-22 19:30:39.444813 N Player(5): Waited 7572ms for video buffers LAAAFDLDDLLLAAAL
2013-10-22 19:30:39.554810 N Player(5): Waited 7682ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:39.664805 N Player(5): Waited 7792ms for video buffers AAALFDADDAALLALL
2013-10-22 19:30:39.774805 N Player(5): Waited 7902ms for video buffers AAALFDADDAALLAAL
2013-10-22 19:30:39.884817 N Player(5): Waited 8012ms for video buffers AAALFDADDAALLLAL
2013-10-22 19:30:39.988136 N Player(5): Waited 8116ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:40.091472 N Player(5): Waited 8219ms for video buffers LLAAFDADDALAAALA
2013-10-22 19:30:40.201483 N Player(5): Waited 8329ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:40.311473 N Player(5): Waited 8439ms for video buffers AAAAFDLDDLALLALA
2013-10-22 19:30:40.421474 N Player(5): Waited 8549ms for video buffers AAAAFDLDDLALLALA
2013-10-22 19:30:40.531478 N Player(5): Waited 8659ms for video buffers AAAAFDLDDLALLALA
2013-10-22 19:30:40.641466 N Player(5): Waited 8769ms for video buffers AAAAFDLDDLALLALA
2013-10-22 19:30:40.751463 N Player(5): Waited 8879ms for video buffers LAALFDADDLALAAAA
2013-10-22 19:30:40.861492 N Player(5): Waited 8989ms for video buffers LAALFDADDAAAAALL
2013-10-22 19:30:40.964812 N Player(5): Waited 9092ms for video buffers ALAAFDADDLLALALL
2013-10-22 19:30:41.074805 N Player(5): Waited 9202ms for video buffers ALAAFDADDALLLLAA
2013-10-22 19:30:41.184800 N Player(5): Waited 9312ms for video buffers LAAAFDLDDALLAAAL
2013-10-22 19:30:41.294804 N Player(5): Waited 9422ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:41.404801 N Player(5): Waited 9532ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:41.511480 N Player(5): Waited 9639ms for video buffers AAALFDADDAALLALL
2013-10-22 19:30:41.621472 N Player(5): Waited 9749ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:41.731468 N Player(5): Waited 9859ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:41.841463 N Player(5): Waited 9969ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:41.951519 N Player(5): Waited 10079ms for video buffers LLLAFDADDAALAAAL
2013-10-22 19:30:42.061477 N Player(5): Waited 10189ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:42.171476 N Player(5): Waited 10299ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:42.281477 N Player(5): Waited 10409ms for video buffers LAALFDLDDALAAALA
2013-10-22 19:30:42.391495 N Player(5): Waited 10519ms for video buffers AAAAFDLDDLALLLAA
2013-10-22 19:30:42.501468 N Player(5): Waited 10629ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:42.611460 N Player(5): Waited 10739ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:42.721474 N Player(5): Waited 10849ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:42.824813 N Player(5): Waited 10952ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:42.934803 N Player(5): Waited 11062ms for video buffers ALAAFDADDLAALALL
2013-10-22 19:30:43.044826 N Player(5): Waited 11172ms for video buffers ALALFDLDDALLLAAA
2013-10-22 19:30:43.154794 N Player(5): Waited 11282ms for video buffers ALALFDLDDALLLAAA
2013-10-22 19:30:43.258142 N Player(5): Waited 11386ms for video buffers LAAAFDLDDLLLAAAL
2013-10-22 19:30:43.368136 N Player(5): Waited 11496ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:43.481489 N Player(5): Waited 11609ms for video buffers AALLFDADDLAALALA
2013-10-22 19:30:43.591466 N Player(5): Waited 11719ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:43.701471 N Player(5): Waited 11829ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:43.804809 N Player(5): Waited 11932ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:43.914807 N Player(5): Waited 12042ms for video buffers LLAAFDADDAALAAAL
2013-10-22 19:30:44.024800 N Player(5): Waited 12152ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:44.128127 N Player(5): Waited 12256ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:44.238149 N Player(5): Waited 12366ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:44.348133 N Player(5): Waited 12476ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:44.458149 N Player(5): Waited 12586ms for video buffers LAALFDADDLALLAAA
2013-10-22 19:30:44.568139 N Player(5): Waited 12696ms for video buffers LAALFDADDAAAALLL
2013-10-22 19:30:44.678133 N Player(5): Waited 12806ms for video buffers LAALFDADDAAAALLL
2013-10-22 19:30:44.788151 N Player(5): Waited 12916ms for video buffers ALLAFDADDAAALALL
2013-10-22 19:30:44.891489 N Player(5): Waited 13019ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:45.001471 N Player(5): Waited 13129ms for video buffers AAALFDLDDALLLAAA
2013-10-22 19:30:45.111518 N Player(5): Waited 13239ms for video buffers LAAAFDLDDLAAALLA
2013-10-22 19:30:45.221467 N Player(5): Waited 13349ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:45.331459 N Player(5): Waited 13459ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:45.441469 N Player(5): Waited 13569ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:45.551474 N Player(5): Waited 13679ms for video buffers AALLFDADDLAALALA
2013-10-22 19:30:45.661493 N Player(5): Waited 13789ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:45.764831 N Player(5): Waited 13892ms for video buffers LLAAFDADDLLLAAAL
2013-10-22 19:30:45.874814 N Player(5): Waited 14002ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:45.984804 N Player(5): Waited 14112ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:46.088164 N Player(5): Waited 14216ms for video buffers AAAAFDLDDALALALA
2013-10-22 19:30:46.198141 N Player(5): Waited 14326ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:46.308140 N Player(5): Waited 14436ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:46.418157 N Player(5): Waited 14546ms for video buffers LAALFDADDAAAALLL
2013-10-22 19:30:46.528139 N Player(5): Waited 14656ms for video buffers LAALFDLDDAAAAALL
2013-10-22 19:30:46.631469 N Player(5): Waited 14759ms for video buffers ALAAFDADDLLALALL
2013-10-22 19:30:46.741473 N Player(5): Waited 14869ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:46.851476 N Player(5): Waited 14979ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:46.961473 N Player(5): Waited 15089ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:47.064828 N Player(5): Waited 15192ms for video buffers LAAAFDLDDALLLAAA
2013-10-22 19:30:47.168152 N Player(5): Waited 15296ms for video buffers LAAAFDLDDLALAAAL
2013-10-22 19:30:47.278150 N Player(5): Waited 15406ms for video buffers LAAAFDLDDLALAAAL
2013-10-22 19:30:47.381477 N Player(5): Waited 15509ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:47.491481 N Player(5): Waited 15619ms for video buffers AAALFDADDALALALL
2013-10-22 19:30:47.594819 N Player(5): Waited 15722ms for video buffers LLLAFDADDAALAAAL
2013-10-22 19:30:47.698135 N Player(5): Waited 15826ms for video buffers LLAAFDADDLLLAAAA
2013-10-22 19:30:47.808163 N Player(5): Waited 15936ms for video buffers LLAAFDADDALAALLA
2013-10-22 19:30:47.918141 N Player(5): Waited 16046ms for video buffers AAAAFDLDDLLALALL
2013-10-22 19:30:48.021469 N Player(5): Waited 16149ms for video buffers AAAAFDLDDLLALALL
2013-10-22 19:30:48.131465 N Player(5): Waited 16259ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:48.241472 N Player(5): Waited 16369ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:48.344829 N Player(5): Waited 16472ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:48.448151 N Player(5): Waited 16576ms for video buffers LLAAFDLDDAAAAALL
2013-10-22 19:30:48.561474 N Player(5): Waited 16689ms for video buffers LLAAFDLDDAAAAALL
2013-10-22 19:30:48.664829 N Player(5): Waited 16792ms for video buffers ALAAFDADDALLLAAA
2013-10-22 19:30:48.768132 N Player(5): Waited 16896ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:48.874815 N Player(5): Waited 17002ms for video buffers LALAFDLDDALLAAAA
2013-10-22 19:30:48.984794 N Player(5): Waited 17112ms for video buffers LAAAFDLDDLLLAAAL
2013-10-22 19:30:49.094830 N Player(5): Waited 17222ms for video buffers LAALFDADDLAALALA
2013-10-22 19:30:49.198137 N Player(5): Waited 17326ms for video buffers AAALFDADDLLALALA
2013-10-22 19:30:49.304814 N Player(5): Waited 17432ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:49.414809 N Player(5): Waited 17542ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:49.524812 N Player(5): Waited 17652ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:49.634797 N Player(5): Waited 17762ms for video buffers AAALFDLDDAALLAAL
2013-10-22 19:30:49.738147 N Player(5): Waited 17866ms for video buffers LLAAFDADDALLAALA
2013-10-22 19:30:49.841472 N Player(5): Waited 17969ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:49.944816 N Player(5): Waited 18072ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:50.054794 N Player(5): Waited 18182ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:50.158138 N Player(5): Waited 18286ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:50.268132 N Player(5): Waited 18396ms for video buffers ALAAFDLDDLALLAAA
2013-10-22 19:30:50.378151 N Player(5): Waited 18506ms for video buffers LAALFDADDLLLAAAA
2013-10-22 19:30:50.481465 N Player(5): Waited 18609ms for video buffers LAALFDADDAAAAALL
2013-10-22 19:30:50.591475 N Player(5): Waited 18719ms for video buffers ALAAFDADDLAALALL
2013-10-22 19:30:50.701470 N Player(5): Waited 18829ms for video buffers ALALFDADDALLLAAA
2013-10-22 19:30:50.811470 N Player(5): Waited 18939ms for video buffers LAAAFDLDDALLLAAA
2013-10-22 19:30:50.921474 N Player(5): Waited 19049ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:51.031471 N Player(5): Waited 19159ms for video buffers LLAAFDLDDLAAAALA
2013-10-22 19:30:51.134816 N Player(5): Waited 19262ms for video buffers AAALFDADDLLALALL
2013-10-22 19:30:51.244806 N Player(5): Waited 19372ms for video buffers AAALFDADDAALLALL
2013-10-22 19:30:51.354808 N Player(5): Waited 19482ms for video buffers AAALFDADDAALLALL
2013-10-22 19:30:51.468142 N Player(5): Waited 19596ms for video buffers AAALFDADDAALLALL
2013-10-22 19:30:51.574820 N Player(5): Waited 19702ms for video buffers LLLAFDADDAALAAAL
2013-10-22 19:30:51.678167 N Player(5): Waited 19806ms for video buffers LLALFDADDALAAALA
2013-10-22 19:30:51.788132 N Player(5): Waited 19916ms for video buffers AALAFDLDDALALALA
2013-10-22 19:30:51.881452 E Player(5): Waited too long for decoder to fill video buffers. Exiting..
2013-10-22 19:30:52.079238 I TV: Attempting to change from WatchingLiveTV to None
2013-10-22 19:30:52.181442 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.284751 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.388096 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.494759 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.598090 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.701426 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.804749 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:52.908094 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.011419 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.114759 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.218084 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.321424 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.424835 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.528091 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.631428 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.734754 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.838094 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:53.941431 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.044757 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.148096 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.251419 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.354756 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.458095 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.561422 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.664755 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.768082 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.871434 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:54.974760 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.078094 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.181431 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.284756 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.388097 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.491472 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.594751 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.698079 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.801439 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:55.904770 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.008094 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.111417 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.214745 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.318081 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.421413 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.524753 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.628081 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.731413 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.834758 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:56.938078 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.041418 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.144759 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.248086 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.351411 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.454893 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.558086 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.661428 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.764746 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.868083 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:57.971418 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.074753 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.178090 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.281413 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.384744 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.488125 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.591422 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.694749 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.798091 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:58.901420 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.004754 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.108078 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.211421 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.314754 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.418151 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.521429 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.624748 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.728078 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.831422 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:30:59.934749 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.038079 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.141421 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.244749 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.348076 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.451427 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.554751 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.658079 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.761410 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.864754 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:00.968080 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.071410 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.178084 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.281414 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.384746 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.488096 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.591418 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.694744 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.798080 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:01.901414 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.004744 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.108096 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.211419 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.314744 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.418098 W Player(5): Waited 100ms for decoder to pause
2013-10-22 19:31:02.450748 W MythPainter: 29 images not yet de-allocated.
2013-10-22 19:31:02.450806 I VDPAU Painter: Clearing VDPAU painter cache.
2013-10-22 19:31:02.872130 I TV: Changing from WatchingLiveTV to None
2013-10-22 19:31:02.872671 I TV: Exiting main playback loop.
2013-10-22 19:31:02.912949 I TV: Attempting to change from None to WatchingLiveTV
2013-10-22 19:31:02.913095 I MythCoreContext: Connecting to backend server: 192.168.1.254:6543 (try 1 of 1)
2013-10-22 19:31:02.956337 N TV: Spawning LiveTV Recorder -- begin
2013-10-22 19:31:03.014313 N TV: Spawning LiveTV Recorder -- end
2013-10-22 19:31:03.023070 I TV: playbackURL(myth://192.168.1.254:6543/13102_20131022173102.mpg) cardtype(DUMMY)
2013-10-22 19:31:03.051038 E TV: LiveTV not successfully started
2013-10-22 19:31:03.051613 I TV: Main UI disabled.
2013-10-22 19:31:03.051638 I TV: Entering main playback loop.
2013-10-22 19:31:03.054166 I TV: Exiting main playback loop.
2013-10-22 19:31:03.082749 N Resuming idle timer

Changed 10 years ago by blm-ubunet@…

Attachment: mythtvgitdiff-master-AVD-SPS.txt​ added

H264 must start with SPS

comment:6 Changed 10 years ago by blm-ubunet@…

H264 decoding requires SPS first, just like mpeg2 requires SEQ header. SPS is also one type of keyframe.

The attached patch plays one of sample bad recordings in my Videos folder.... You might need my other H264Parser patches to get this to work..

comment:7 in reply to:  6 Changed 10 years ago by Jim Stichnoth

Replying to blm-ubunet@…:

H264 decoding requires SPS first, just like mpeg2 requires SEQ header. SPS is also one type of keyframe.

If this is true, isn't the following patch more appropriate? 

diff --git a/mythtv/libs/libmythtv/avformatdecoder.cpp b/mythtv/libs/libmythtv/avformatdecoder.cpp
index 3a42b40..e9af99b 100644
--- a/mythtv/libs/libmythtv/avformatdecoder.cpp
+++ b/mythtv/libs/libmythtv/avformatdecoder.cpp
@@ -3152,7 +3152,8 @@ int AvFormatDecoder::H264PreProcessPkt(AVStream *stream, AVPacket *pkt)
                 if (m_h264_parser->onFrameStart())
                     ++num_frames;
 
-                if (!m_h264_parser->onKeyFrameStart())
+                if (!m_h264_parser->onKeyFrameStart() &&
+                    !m_h264_parser->seen_SPS())
                     continue;
             }
             else

comment:8 Changed 10 years ago by blm-ubunet@…

Disclaimer: I'm not a s/w eng..

Yes, I think so..If you want to count the un-decodable frames before SPS.

All frames before any SPS are junk unless you want to fake the missing data just to play <2 sec of video in the incorrect resolution etc..

To me, onKeyFrameStart() sort-of implies you can start decoding & you can't.

Other comment: The code above this that starts with:.. " crude NAL unit vs Annex B detection."...looks like the fossilised remains of a prev era ??.

Thanks.

comment:9 Changed 10 years ago by warpme@…

@blm-ubunet, Thx for patch. I already give evening of test with this patch and results are very good.

Quick summary:

  • all channels works OK for all combinations (good->bad; bad->bad)
  • 1..2sec. audio stuttering right after channel change almost gone (was on 10channels, now is on 2..3)
  • seektable before and after commflag --rebuild are almost identical. For difference see below.

  • 1 per 10-15 channel changes I have jumpy looped picture from previous channel.

Thx for this.

Now I'm building BE/FE with ​http://code.mythtv.org/trac/ticket/11882#comment:7 and see how it goes.

before --rebuild: 

+--------+---------------------+------+----------+------+
| chanid | starttime           | mark | offset   | type |
+--------+---------------------+------+----------+------+
|   8035 | 2013-10-27 09:47:52 |    0 |        0 |    9 |
|   8035 | 2013-10-27 09:47:52 |    0 |        0 |   33 |
|   8035 | 2013-10-27 09:47:52 |   12 |   571896 |    9 |

after rebuild: 

+--------+---------------------+------+----------+------+
| chanid | starttime           | mark | offset   | type |
+--------+---------------------+------+----------+------+
|   8035 | 2013-10-27 09:47:52 |    0 |        0 |    9 |
|   8035 | 2013-10-27 09:47:52 |   12 |   571896 |    9 |

Thx again.

comment:10 Changed 10 years ago by warpme@…

Jim, I do some tests with patch from ​http://code.mythtv.org/trac/ticket/11882#comment:7. All channels works OK but this patch compared to blm-ubunet gives high discrepancy for seektable before/after mythcommflag rebuild (before 98 rows, after 3065 rows). Both seektables are attached to ticket.

Changed 10 years ago by warpme@…

Attachment: seektable-before​ added

seektable with comment7 patch before mythcommflag rebuild

Changed 10 years ago by warpme@…

Attachment: seektable-after​ added

seektable with comment7 patch after mythcommflag rebuild

comment:11 Changed 10 years ago by blm-ubunet@…

@ comment #7 This is a better match ?? 

diff --git a/mythtv/libs/libmythtv/avformatdecoder.cpp
b/mythtv/libs/libmythtv/avformatdecoder.cpp
index 3a42b40..e9af99b 100644
--- a/mythtv/libs/libmythtv/avformatdecoder.cpp
+++ b/mythtv/libs/libmythtv/avformatdecoder.cpp
@@ -3152,7 +3152,8 @@ int AvFormatDecoder::H264PreProcessPkt(AVStream
*stream, AVPacket *pkt)
if (m_h264_parser->onFrameStart())
++num_frames;

- if (!m_h264_parser->onKeyFrameStart())
+ if (!m_h264_parser->onKeyFrameStart() || !m_h264_parser->seen_SPS())
     continue;
}
else

SPS indicates keyframe but opposite is not spec requirement.

Above always allows code path to "continue;" with condition seen_SPS()=false. h264_parser->seen_SPS() is a semaphore set (true) at the first & any SPS in stream. As in comment #7 .. the 1st keyframe without any SPS seen (False && True = False) would not lead to "continue;" but drop right thru'..

But I think this & comment #7 is a confusing obfuscation c.f. my original patch file.

comment:12 Changed 10 years ago by blm-ubunet@…

Rewriting comment #11...

In reply to the code fragment in comment #7: This code is possibly a better functional match to the original patch file ?? 

insert code from comment #11

The SPS NAL-type indicates keyframe but the opposite case is not implied in the H264 spec.

The above comment #11 code fragment allows the code path to branch to "continue;" with condition seen_SPS()=false. The semaphore h264_parser->seen_SPS() is set (true) at the first & any SPS in the current stream.

The code execution path as per comment #7 with the conditions of keyframe & no SPS seen results in (False && True = False) which incorrectly drops right thru'.

The variable num_frames could be used to allow a maximum limit exit condition.

comment:13 Changed 10 years ago by Jim Stichnoth

Sorry for the noise - I made comment:7 because the patch mythtvgitdiff-master-AVD-SPS.txt​ made no difference in the playback of the samples provided. (Maybe it works when it's applied to both recording and playback?)

comment:14 Changed 10 years ago by jpoet

I like blm-ubunet's patch in comment 11. warpme, does it work for you?

comment:15 in reply to:  13 Changed 10 years ago by blm-ubunet@…

Replying to stichnot:

Sorry for the noise - I made comment:7 because the patch mythtvgitdiff-master-AVD-SPS.txt​ made no difference in the playback of the samples provided. (Maybe it works when it's applied to both recording and playback?)

Here on my "production" system, the original patch mythgitdiff-master-AVD-SPS.txt plays a sample of 5 of the bad recordings from the OP. I didn't feel the need to download them all & the OP had indicated success. I didn't re-record them, just stuck them in Videos. I did not use -O FFMPEGTS=1.

The patch has no problem playing my new & old recordings (AVC over FTA dvb-t) & H264 video samples from UK (dvb-t2), Italy, Poland & US (hdpvr) etc collected from various tickets..

I do have public & private patches in dtvrecorder & H264Parser etc but don't see that having an effect.

There is certainly no problem with playback startup delay/time..

The alternative code/patch suggested in comment #11 has not been tested here beyond a playback test of my old recordings on another box.

comment:16 Changed 10 years ago by jpoet

warpme, please try 11882-require_SPS_for_state_change.patch when you get chance.

Changed 10 years ago by jpoet

Attachment: 11882-require_SPS_for_state_change.patch​ added

comment:17 Changed 10 years ago by warpme@…

FYI: I do some tests with code from comment11. All channels works OK and seektables before/after --rebuild are thesame except 1 additional line like described in by me in comment9. I'll do test with comment16 code soon and will give feedback. Thx for Your work!

comment:18 Changed 10 years ago by warpme@…

@jpoet, I do tests with comment16 patch. All channels works OK, seek tables are in-sync (except 1 line difference like in comment9), jump fwd/rew during playback is fast and reliable (no pixelizations), editing recordings is OK (no pixelization). Thx!!!

comment:19 Changed 10 years ago by Jim Stichnoth

Quick comment on the one-line seektable difference. It makes no difference whether the entry {type=33 mark=0 offset=0} is present. That entry indicates that the timestamp at frame 0 is 0ms, and this default is used if not explicitly there. I believe that the recorder and mythcommflag --rebuild are inconsistent about whether that entry is generated.

comment:20 Changed 10 years ago by jpoet

blm-ubunet, do you have any thoughts on 11882-require_SPS_for_state_change.patch ? Making the SPS check in H264Parser means that dtvrecorder benefits as well.

comment:21 Changed 10 years ago by John Poet <jpoet@…>

Resolution: → fixed
Status: accepted → closed

In 306f9fc004d52e87defca84f8c33616ef0e00485/mythtv:

H264Parser: Only enter the "state changed" state if we have seen a SPS.

Fixes #11882
May help or solve #11886

comment:22 Changed 10 years ago by jpoet

blm-ubunet, thank you for identifying the cause of this problem. warpme, thank you for your patience and for all of the testing.

comment:23 Changed 10 years ago by John Poet <jpoet@…>

In 4f9f78f55a0c7cb5b3c6ed1d5ae43e88f5b40e50/mythtv:

H264Parser: Only enter the "state changed" state if we have seen a SPS.

Fixes #11882
May help or solve #11886

(cherry picked from commit 306f9fc004d52e87defca84f8c33616ef0e00485)

Note: See TracTickets for help on using tickets.