Opened 12 years ago
Closed 11 years ago
Last modified 11 years ago
#11435 closed Bug Report - General (fixed)
recordedseek as recorded differs from mythcommflag
| Reported by: | Owned by: | jpoet | |
|---|---|---|---|
| Priority: | minor | Milestone: | 0.27 |
| Component: | MythTV - Recording | Version: | Master Head |
| Severity: | low | Keywords: | H264 recordedseek |
| Cc: | Ticket locked: | no |
Description
V dirty 0.26+fixes patched with all recent H264 related commits. The latest H264 commits (latest month) have resulted in very slow playback seeking & odd cut-list editor behaviour; looks to be playing sequences of frames for each keyframe.
mythcommflag --rebuild fixes seek "slowness" & cut-list editor problem.
The mythcommflag rebuild seektable is very different to "as recorded"
Attachments (19)
Change History (63)
Changed 12 years ago by
| Attachment: | seektable-rebuildmythcommflag.txt added |
|---|
Changed 12 years ago by
| Attachment: | seektable-recorded.txt added |
|---|
comment:1 Changed 12 years ago by
| Status: | new → infoneeded_new |
|---|---|
| Version: | Master Head → 0.26-fixes |
I have a suspicion that "garbage" frames at the beginning of the recording are being parsed and processed by the recorder but ignored by the player/ffmpeg until the first keyframe is seen.
Could you attach the seektable for such a recording, before and after running "mythcommflag --rebuild"?
select * from recordedseek where chanid=<my_chanid> and starttime=<my_starttime> order by mark, type;
This may be a dup of #11328.
Changed 12 years ago by
| Attachment: | ffprobe-rearranged.txt added |
|---|
ffprobe of recording, sorted in spreadsheet etc
comment:2 Changed 12 years ago by
The prev attached files were made with "select * from recordedseek where type in (33,9) and chanid=1003 and starttime=20130303020100 order by mark;"
Your cmd shows nothing diff/new at beginning of the same recording after running mythcommflag.
I have added some processed ffprobe info from the very start of the same recording. (real ffmpeg git 15 Feb 2013).
The recorded seek entry does not point at any ffprobe packet offset. mythcommflag gets one pkt offset match at coded_pict 24.
comment:3 Changed 12 years ago by
Sorry, I didn't notice that you had already attached the seektables.
Could you make the first ~50MB of the recording available for download and analysis? (Or any such problematic recording, along with the corresponding seektable produced by the recorder.)
comment:4 Changed 12 years ago by
All my recordings have similar issue (worse with HD ones). Slow seeking is like using a IR remote c.f. keyboard.
Using older kernel but with recent build of v4l-dvb.
ffprobe finds one extra keyframe at beginning & has this error parsing file: "[mpegts @ 0x27d86e0] PES packet size mismatch"
packet,video,0,11174706245,124163.402722,11174688245,124163.202722,1800,0.020000,N/A,N/A,129815,376,K packet,video,0,11174792645,124164.362722,11174774645,124164.162722,1800,0.020000,N/A,N/A,114004,1232340,K packet,video,0,11174879045,124165.322722,11174861045,124165.122722,1800,0.020000,N/A,N/A,114868,2533112,K packet,video,0,11175008645,124166.762722,11174990645,124166.562722,1800,0.020000,N/A,N/A,101747,4627620,K packet,video,0,11175095045,124167.722722,11175077045,124167.522722,1800,0.020000,N/A,N/A,122790,5889100,K
comment:5 Changed 12 years ago by
link to sample first 50MB http://d01.megashares.com/dl/7P3CVS7/part1.mpg
Cut from recording with: dd if=1003_20130303020100.mpg of=part1.mpg bs=1024 count=50000
comment:6 Changed 12 years ago by
Just to be clear, you are running 0.26 fixes 3944ca9a ? What is your source? BBC?
Personally, to get acceptable seeks performance with HD-PVR material I have to effectively turn "accurate" seeking off as illustrated with the attached patch.
Changed 12 years ago by
| Attachment: | InaccurateSeek.patch added |
|---|
comment:7 Changed 12 years ago by
0.26+fixes + (manually) patched with every H264/dvb related commit from master.. (Mr Stichnot has been busy).
Source is dvb-t H264 1080i50 & 576i50 and a range of datarates..
Seeking (playback) is okay/usable after seektable rebuild, not as lightening fast as couple months ago.. Seeking (cutlist ed) is very good after seektable rebuild. Haven't checked the (key)frame cutting accuracy yet..
The sample HD-PVR recordings that I have (sourced from around here), play okay/fine after cleaning up the beginning. Recent commits should have fixed the beginnings. Processing with ffmpeg requires extended "-analyzeduration" period.
Thanks for the interest & the patch..
comment:8 Changed 12 years ago by
To reiterate jpoet's question, please attach the output of "mythfrontend --version". If it's possible for you to enumerate the set of commits from Master that you have cherry-picked, that would also be helpful. We would especially like to know if you have all the commits related to #11328.
comment:9 Changed 12 years ago by
Version: Don't place to much weight by version.txt attachment.
Commits: Any & every commit with your name from Dec last.. Definitely commits around/related 11328.
There is no list of commits used. I only have a couple of private code mods, if myth breaks I give up & start again. git diff against 0.26+fixes (3 Jan 2013) is 382K..
Another (cosmetic?) observation: The repeated execution of mythcommflag --rebuild causes the "progress" percentage display to go 20,000%. First time is okay (100%)..maybe I missed that code commit..
Jpoet: Tried with "kInaccuracyDefault = 0.2;"; bit faster maybe, but --rebuild seektable still wins..
This is a minor issue & I thought the slow seeking problem would be common but if you guys have matching seektables for H264 recordings & mythcommflag --rebuild, I'll live with slow seeking, it is still better than all other players.
Changed 12 years ago by
| Attachment: | version.txt added |
|---|
Potentially misleading mythfrontend --version info
comment:10 Changed 12 years ago by
Forget about "fixing" this ticket, please just close it invalid..
I only ask you to do one thing: check your recorded seektable against mythcommflag --rebuild for your H264 recordings.
comment:11 Changed 12 years ago by
| Owner: | changed from danielk to Jim Stichnoth |
|---|
I appreciate your efforts in tracking and evaluating this issue.
At your request, I'll close the ticket, as it's clearly going to be very tough to reproduce and validate your setup.
Currently in Master, in my tests of various HD-PVR and HDHR recordings, the keyframe numbers, file positions, and timestamps are pretty much exact matches, except for occasional keyframe entries that are missing from either the recorder or mythcommflag.
If you find a chance to try out Master, I would appreciate hearing whether the same holds for your recordings.
comment:12 Changed 12 years ago by
| Resolution: | → Works for me |
|---|---|
| Status: | infoneeded_new → closed |
comment:13 Changed 12 years ago by
HD-PVR etc are all old-school IDR H264..
The root cause of the problem is a bug in H264Parser.cpp when detecting "keyframe" in AVC.
The meat of the change is this line 1065..
au_contains_keyframe_message = (recovery_frame_cnt >= 0);
I'm still not (yet) getting exact agreement with ffprobe (very close) but there are no completely wrong values as before & seeking is better. The exact definition of "keyframe offset" w.r.t AVC sliced refresh is unclear (to me).
comment:14 Changed 12 years ago by
After attempting to study this: http://www.itu.int/rec/T-REC-H.264-201201-I/en and reference H264 decoder: http://iphome.hhi.de/suehring/tml/ I went thru' H264Parser line by line trying to align to spec & reference decoder when I got lost..
I think the premise that the recording starts on keyframe is wrong, that first GOP is not decode-able without SPS/PPS. Had to make changes to dtvrecorder.cpp to sync to SPS. A small change to mpeg2 code was required because of common code (with H264). H264Parser signals (outputs) I-frame or sliced refresh AVC.
I can not test H264 I-frame or mpeg2 video recording.
Tested with H264-AVC OTA broadcast & playback using VDPAU & OpenGL. As the H264Parser is reused by avformatdecoder, I checked that HD-PVR & HDHR samples play okay. My HD-PVR samples include 11159 (60p) & 50p..
Playback seeking is very good & cutlist editor faultless.
I don't think recording sync to SPS is the perfect solution but it is better than sync to keyframe/AU. My coding style is naive/simple & there are a few unused variables.
A git diff to master is possble in a week or so but for now diff files only.. Thanks for your help..
ps: ignore the previous comment about "au_contains_keyframe_message" being wrong..
Changed 12 years ago by
| Attachment: | diff-H264Parser.cpp.txt added |
|---|
diff patch against git master (1 week ago) H264Parser.cpp
Changed 12 years ago by
| Attachment: | diff-H264Parser.h.txt added |
|---|
diff patch against git master (1 week ago) H264Parser.h
Changed 12 years ago by
| Attachment: | diff-dtvrecorder.cpp.txt added |
|---|
diff patch against git master (1 week ago) dtvrecorder.cpp
comment:15 Changed 12 years ago by
Just FYI: I just want to confirm v.good results with blm-ubunet patches. By curiosity I back-ported them to 0-26-fixes, and for me so far they are 100% success. So: I don't have issues with seek table discrepancy in recorder vs commflag --rebuild (#11470); so far (after 1 day of tests) all seems to be working OK (H.264/MPEG2 LiveTV, movies); LiveTV channel switches are almost fast as fastest I had (fastest are without http://code.mythtv.org/cgit/mythtv/commit/?id=e54b9b6fd635df024f81c1d2f33956996c95c379); playback seeking & cutlist editor are also seems to be fastest & without negative effects (beside cutlist seeking pixelizations at very beginning of recording); on many LiveTV channels program transitions now are now hard to notice at all.
comment:16 Changed 12 years ago by
| Resolution: | Works for me |
|---|---|
| Status: | closed → new |
comment:17 Changed 12 years ago by
For what it's worth..Attached "git diff" to master branch...
- change to avformatdecoder.cpp not required.
- Not tested with real tuner just "demo recorder from file" & VDPAU playback.
- duration seems wrong. (same as before)
- Result on master is inconclusive as master branch is unproven (here).
comment:18 Changed 12 years ago by
@blm-ubunet, thx for Your's really nice/interesting work with this ticket. Just FYI: for 60+ TV channels (approx. 40 are H264 HD) I have excellent results - except single 1 channel. This particular channel gives me cycle of few sec of good screen, next few sec. black screen, next few sec. of total mess and again fes sec of good screen). If You are interested in details/debugging - pls PM me at warpme(at)o2.pl. Thx
comment:19 Changed 12 years ago by
Small additional mod to un-break/block audio only & no-audio-no-video streams. Tested audio only streams work on 0.26+fixes with no regression to video streams.
A fresh "git diff" to master branch attached..
Changed 12 years ago by
| Attachment: | git_diff.txt added |
|---|
fresh git diff to master with non-video stream unblocked.
comment:20 Changed 12 years ago by
fix to my patch to play "warpme's" problem file..The file video has profile_idc=100 & that tested the scaling list code changes..
Changed 12 years ago by
| Attachment: | git_diff.2.txt added |
|---|
git diff to master..fix for warpme problem recording
comment:21 Changed 12 years ago by
| Owner: | changed from Jim Stichnoth to jpoet |
|---|---|
| Status: | new → accepted |
I have not tried to run this patch yet, but in general the git_diff.2.txt patch looks good. I believe it breaks back-to-back recording processing, though.
For back-to-back recordings, we don't actually shut down reading from the capture device, we just switch writing to a new ringbuffer. The new ringbuffer should start on a payload with a keyframe (and SPS?). To accomplish this we need to start buffering at the beginning of each payload until we know if that payload contains a keyframe (or SPS?). As soon as I have time to work out what changes need made to fix back-to-back recordings, I will see about getting this committed.
blm, thank you for taking the time to sift through the H.264 documentation and enhance myth's decoder. Please also note that using pre-increment of variables is always preferred over post-increment, unless there is a specific reason to use post-increment.
comment:22 Changed 12 years ago by
Glad to be able to contribute. Sorry I failed to realise the cost of post-inc & as there are no "continue" in the for loops..pre-inc is better.
I have been running back-to-back recordings (with 2 min extra on ends) just fine..
I have tweaked the patch a little.. H264:
- was not honouring the SEQ start flag; always waited for seen_SPS.
- parser has pre-increments
MPEG2: Reading H262 standard...recordings should start on a sequence header.
- setup same logic as H264.
IMO the dtvrecorder logic is much clearer & could still be reduced a bit more..
All my H264 samples still play okay inc 16:9 -> 4:3 transitions. Have not tested mpeg2 video recording.
I'll have to try with demo/dummy recorder from the one mpeg2 file I have or find a willing tester..
Changed 12 years ago by
| Attachment: | git_diff3.txt added |
|---|
git diff to master ; added some mpeg2 video changes etc
comment:23 Changed 12 years ago by
I'm not sure this is a valid method but.. Tested patch "git_diff3.txt" with mpeg2 video recording via the "demo test recorder" dummy recorder.
I used the "CheeseSlices?" de-interlacing test-track Slicies_MPEG2_PAL_1080i_25.ts (33 sec) & recorded for 10 min. Playback (mpeg2 vdpau) is seamless, seeking is fine, cut-list nav/seeking is fine.
comment:24 Changed 12 years ago by
Hi, FYI: in my case git_diff3.txt has little regression over previous patches: program transitions on H264 channels now have pixelizations, while in previous versions were smooth. Also i have impression more channels now have exactly 15sec delay between program transitions (t.b.c.)
comment:25 Changed 12 years ago by
You have to have "Wait SEQ start" set in the backend DVB tuner setup.. The additional change to H264 patch is to honour that setting.
All my samples. including your problem file, play fine.
Can you please find & check that setting ? Do you have any mpeg2video sources ?
comment:26 Changed 12 years ago by
Well - looking on "dvb_wait_for_seqstart" on DB level I have set to 1 for all tuners. Regarding mpeg2video - yes. I have over 20+ DVB SD (mpeg2) TV channels.
comment:27 Changed 12 years ago by
I could well have made a typo.. My production system is 0.26+fixes. Git master is on another.. So to make the git-diff file there are several unreliable steps involving copying & "diff" & editing. I did a simple playback only check on master.
comment:28 Changed 12 years ago by
Oh - well - I'm on 0.26-fixes ad well :-)))). All Your's patches I backported to 0.26. After backporting I'm visually comparing source and backport - so I don't believe issue is in my backporting process. May You pls attach here last patch version for 0.26-fixes ?
Changed 12 years ago by
| Attachment: | git-diff4-cleaned.txt added |
|---|
git diff to master. Rearranged reset of _seen_sps so that only occurs with payload start & is similar to PES_sync.
comment:29 Changed 12 years ago by
git-diff4 solves problem with H264 pixelizations. Generally H264 channels are recording/playing perfectly now. However MPEG2 recording seems to be completely broken. MPEG2 playback is OK with nice and fast seeks/jumps. MPEG2 recording starts 15-30sec then there is few flashes on screen, audio is completely gurgles and soon playback hangs. Pls find log from backend for MPEG2 channel LiveTV:
2013-04-17 10:29:22.310027 I Getting next free recorder after : -1 2013-04-17 10:29:22.310039 I Checking card 1. Best card so far -1 2013-04-17 10:29:22.311085 I Checking card 2. Best card so far 1 2013-04-17 10:29:22.311810 I Checking card 3. Best card so far 1 2013-04-17 10:29:22.312836 I Checking card 4. Best card so far 1 2013-04-17 10:29:22.313784 I Checking card 5. Best card so far 1 2013-04-17 10:29:22.314655 I Checking card 6. Best card so far 5 2013-04-17 10:29:22.315588 I Checking card 7. Best card so far 5 2013-04-17 10:29:22.316569 I Checking card 8. Best card so far 5 2013-04-17 10:29:22.317537 I Checking card 9. Best card so far 5 2013-04-17 10:29:22.318310 I Checking card 10. Best card so far 9 2013-04-17 10:29:22.321752 I Checking card 18. Best card so far 17 2013-04-17 10:29:22.322134 I Checking card 19. Best card so far 17 2013-04-17 10:29:22.322630 I Checking card 20. Best card so far 17 2013-04-17 10:29:22.323023 I Best card is 17 2013-04-17 10:29:22.328387 I MainServer::ANN Playback 2013-04-17 10:29:22.328394 I adding: FE-Devel as a client (events: 0) 2013-04-17 10:29:22.369821 I TVRec(17): Found channel (44) on current card(17). 2013-04-17 10:29:22.381836 I TVRec(17): Changing from None to WatchingLiveTV 2013-04-17 10:29:22.381857 I TVRec(17): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady, 2013-04-17 10:29:22.381871 I TVRec(17): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,) 2013-04-17 10:29:22.381884 I ChannelBase(17): Looking for startchannel '44' on input 'DVBInput' 2013-04-17 10:29:22.384702 I ChannelBase(17): Found startchannel '44' on input 'DVBInput' 2013-04-17 10:29:22.385421 I TVRec(17): HW Tuner: 17->17 2013-04-17 10:29:22.385435 I TVRec(17): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady, 2013-04-17 10:29:22.385445 I TVRec(17): No recorder yet, calling TuningFrequency 2013-04-17 10:29:22.385778 I DVBChan(17:/dev/dvb/adapter8/frontend0): Opening DVB channel 2013-04-17 10:29:22.385786 I DTVChan(/dev/dvb/adapter8/frontend0): SetChannelByString(44): 2013-04-17 10:29:22.387968 I DVBChan(17:/dev/dvb/adapter8/frontend0): 11158000 qpsk a auto auto a a auto a v fec: 5/6 msys: DVB-S rolloff: 0.35 2013-04-17 10:29:22.388035 I DVBChan(17:/dev/dvb/adapter8/frontend0): Old Params: 11158000 qpsk a auto auto a a auto a v fec: 5/6 msys: DVB-S rolloff: 0.35 New Params: 11158000 qpsk a auto auto a a auto a v fec: 5/6 msys: DVB-S rolloff: 0.35 2013-04-17 10:29:22.388043 I DVBChan(17:/dev/dvb/adapter8/frontend0): Tune(): Frequency tuning successful. 2013-04-17 10:29:22.388047 I DTVChan(/dev/dvb/adapter8/frontend0): SetChannelByString(44): success 2013-04-17 10:29:22.388058 I TVRec(17): CreateLiveTVRingBuffer(44) 2013-04-17 10:29:22.388563 I TVRec(17): GetProgramRingBufferForLiveTV() 2013-04-17 10:29:22.390288 N AutoExpire: CalcParams(): Max required Free Space: 17.0 GB w/freq: 14 min 2013-04-17 10:29:22.416668 I TVRec(17): StartedRecording(21109_2013-04-17T08:29:22Z) fn(/myth/tv/21109_20130417082922.mpg) 2013-04-17 10:29:22.418716 I Chain: Appended@0 '21109_20130417082922' 2013-04-17 10:29:22.419895 I TVRec(17): Starting Signal Monitor 2013-04-17 10:29:22.419907 I TVRec(17): SetupSignalMonitor(1, 1) 2013-04-17 10:29:22.419916 I DVBChan(17:/dev/dvb/adapter8/frontend0): Opening DVB channel 2013-04-17 10:29:22.423066 I DVBSM(/dev/dvb/adapter8/frontend0): Can measure Signal Strength 2013-04-17 10:29:22.427909 I DVBSM(/dev/dvb/adapter8/frontend0): Can measure S/N 2013-04-17 10:29:22.430091 I DVBSM(/dev/dvb/adapter8/frontend0): Can measure Bit Error Rate 2013-04-17 10:29:22.433490 I DVBSM(/dev/dvb/adapter8/frontend0): Can count Uncorrected Blocks 2013-04-17 10:29:22.433508 I DVBSM(/dev/dvb/adapter8/frontend0): DVBSignalMonitor::ctor initial flags Seen() Match() Wait(Sig,SNR,BER,UB,) 2013-04-17 10:29:22.433535 I TVRec(17): Signal monitor successfully created 2013-04-17 10:29:22.433541 I TVRec(17): Setting up table monitoring. 2013-04-17 10:29:22.434649 I Using profile 'Live TV' to record 2013-04-17 10:29:22.434667 I TVRec(17): MPEG program number: 13109 2013-04-17 10:29:22.434684 I DTVSM(/dev/dvb/adapter8/frontend0)::SetProgramNumber(13109): 2013-04-17 10:29:22.434701 I TVRec(17): Successfully set up MPEG table monitoring. 2013-04-17 10:29:22.439067 I TVRec(17): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady, 2013-04-17 10:29:22.439079 I TVRec(17): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady, 2013-04-17 10:29:22.439086 I TVRec(17): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady, 2013-04-17 10:29:22.439094 I TVRec(17): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.439097 I DummyDTVRecorder -- started 2013-04-17 10:29:22.439104 I TVRec(17): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.439111 I TVRec(17): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.439117 I TVRec(17): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.439179 I TVRec(17): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.452663 I DVBSM(/dev/dvb/adapter8/frontend0): Signal Locked 2013-04-17 10:29:22.452682 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- begin 2013-04-17 10:29:22.452687 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- locked 2013-04-17 10:29:22.452771 I DVBSH(/dev/dvb/adapter8/frontend0): run(): begin 2013-04-17 10:29:22.453399 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): begin 2013-04-17 10:29:22.453446 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x0 2013-04-17 10:29:22.453564 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x1 2013-04-17 10:29:22.495207 I CreatePATSingleProgram() 2013-04-17 10:29:22.495215 I PAT in input stream 2013-04-17 10:29:22.495262 I Program Association Section PSIP tableID(0x0) length(69) extension(0x3390) version(0) current(1) section(0) last_section(0) tsid(13200) programCount(15) program number 0 has PID 0x0010 program number 13101 has PID 0x0021 program number 13102 has PID 0x0022 program number 13103 has PID 0x0023 program number 13104 has PID 0x0024 program number 13105 has PID 0x0025 program number 13106 has PID 0x0026 program number 13107 has PID 0x0027 program number 13108 has PID 0x0028 program number 13109 has PID 0x0029 program number 13110 has PID 0x002a program number 13122 has PID 0x0032 program number 13126 has PID 0x0036 program number 13129 has PID 0x0039 program number 13139 has PID 0x0043 2013-04-17 10:29:22.495266 I desired_program(13109) pid(0x29) 2013-04-17 10:29:22.495286 I pmt_pid(0x29) 2013-04-17 10:29:22.495288 I PAT for output stream 2013-04-17 10:29:22.495303 I Program Association Section PSIP tableID(0x0) length(13) extension(0x3390) version(0) current(1) section(0) last_section(0) tsid(13200) programCount(1) program number 1 has PID 0x0029 2013-04-17 10:29:22.495371 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x29 2013-04-17 10:29:22.495628 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x83 2013-04-17 10:29:22.495803 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x86 2013-04-17 10:29:22.496004 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x1ffe 2013-04-17 10:29:22.552851 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- end 2013-04-17 10:29:22.595621 N DTVSM(/dev/dvb/adapter8/frontend0): PMT says program 13109 is encrypted 2013-04-17 10:29:22.595690 I CreatePMTSingleProgram() 2013-04-17 10:29:22.595693 I PMT in input stream 2013-04-17 10:29:22.595843 I Program Map Section PSIP tableID(0x2) length(280) extension(0x3335) version(1) current(1) section(0) last_section(0) pnum(13109) pid(0x29) Multiplex Buffer Utilization Descriptor (0x0c) length(4) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(178) Descriptor (0xb2) length(57) Conditional Access: sid(0x1861) pid(0x18a) data_size(0) Conditional Access: sid(0x1803) pid(0x18b) data_size(0) Conditional Access: sid(0x100) pid(0x18c) data_size(13) Conditional Access: sid(0x500) pid(0x18f) data_size(11) Conditional Access: sid(0x1813) pid(0x18c) data_size(3) Stream #0 pid(0x181) type(0x02 video-mpeg2) Stream Identifier Descriptor (0x52): ComponentTag=0x1 Video Descriptor (0x02) length(3) Data Stream Alignment Descriptor (0x06) length(1) Maximum Bitrate Descriptor (0x0e) length(3) Stream #1 pid(0x182) type(0x04 audio-mp2-layer[1,2,3]) Stream Identifier Descriptor (0x52): ComponentTag=0x2 ISO-639 Language: code(pol) canonical(pol) eng(Polish) Audio Descriptor (0x03) length(1) Maximum Bitrate Descriptor (0x0e) length(3) Stream #2 pid(0x184) type(0x06 private-data) Stream Identifier Descriptor (0x52): ComponentTag=0x3 Maximum Bitrate Descriptor (0x0e) length(3) Stream #3 pid(0xd0) type(0xc0 unknown) Unknown(198) Descriptor (0xc6) length(5) Unknown(194) Descriptor (0xc2) length(24) Stream #4 pid(0xd5) type(0xc1 unknown) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(194) Descriptor (0xc2) length(8) Stream #5 pid(0x108) type(0x06 private-data) Stream Identifier Descriptor (0x52): ComponentTag=0x5 Teletext Descriptor: 2 pages type(1) mag(1) page(00) lang(pol) type(2) mag(7) page(83) lang(pol) 2013-04-17 10:29:22.595918 I PMT for output stream 2013-04-17 10:29:22.596015 I Program Map Section PSIP tableID(0x2) length(217) extension(0x1) version(1) current(1) section(0) last_section(0) pnum(1) pid(0x29) Multiplex Buffer Utilization Descriptor (0x0c) length(4) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(178) Descriptor (0xb2) length(57) Stream #0 pid(0x181) type(0x02 video-mpeg2) Stream Identifier Descriptor (0x52): ComponentTag=0x1 Video Descriptor (0x02) length(3) Data Stream Alignment Descriptor (0x06) length(1) Maximum Bitrate Descriptor (0x0e) length(3) Stream #1 pid(0x182) type(0x04 audio-mp2-layer[1,2,3]) Stream Identifier Descriptor (0x52): ComponentTag=0x2 ISO-639 Language: code(pol) canonical(pol) eng(Polish) Audio Descriptor (0x03) length(1) Maximum Bitrate Descriptor (0x0e) length(3) Stream #2 pid(0x184) type(0x06 private-data) Stream Identifier Descriptor (0x52): ComponentTag=0x3 Maximum Bitrate Descriptor (0x0e) length(3) Stream #3 pid(0xd0) type(0xc0 unknown) Unknown(198) Descriptor (0xc6) length(5) Unknown(194) Descriptor (0xc2) length(24) Stream #4 pid(0xd5) type(0xc1 unknown) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(194) Descriptor (0xc2) length(8) Stream #5 pid(0x108) type(0x06 private-data) Stream Identifier Descriptor (0x52): ComponentTag=0x5 Teletext Descriptor: 2 pages type(1) mag(1) page(00) lang(pol) type(2) mag(7) page(83) lang(pol) 2013-04-17 10:29:22.596076 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0xd0 2013-04-17 10:29:22.596188 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0xd5 2013-04-17 10:29:22.596411 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x108 2013-04-17 10:29:22.596494 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x181 2013-04-17 10:29:22.596572 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x182 2013-04-17 10:29:22.596648 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x184 2013-04-17 10:29:22.596742 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18a 2013-04-17 10:29:22.596853 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18b 2013-04-17 10:29:22.596962 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18c 2013-04-17 10:29:22.597077 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18e 2013-04-17 10:29:22.597151 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18f 2013-04-17 10:29:22.748674 I PID 0x181 status: Decrypted 2013-04-17 10:29:22.748816 I PID 0x182 status: Decrypted 2013-04-17 10:29:22.748821 I Program 13109 status: Decrypted 2013-04-17 10:29:22.753940 I TVRec(17): Got good signal 2013-04-17 10:29:22.753994 I TVRec(17): TeardownSignalMonitor() -- begin 2013-04-17 10:29:22.754003 I DVBSM(/dev/dvb/adapter8/frontend0): Stop() -- begin 2013-04-17 10:29:22.804358 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- begin 2013-04-17 10:29:22.804367 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- locked 2013-04-17 10:29:22.849530 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): shutdown 2013-04-17 10:29:22.849557 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x0 2013-04-17 10:29:22.849661 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x1 2013-04-17 10:29:22.849820 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x29 2013-04-17 10:29:22.849884 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x83 2013-04-17 10:29:22.849987 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x86 2013-04-17 10:29:22.850085 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0xd0 2013-04-17 10:29:22.850128 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0xd5 2013-04-17 10:29:22.850169 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x108 2013-04-17 10:29:22.850259 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x181 2013-04-17 10:29:22.850370 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x182 2013-04-17 10:29:22.850474 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x184 2013-04-17 10:29:22.850509 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18a 2013-04-17 10:29:22.850607 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18b 2013-04-17 10:29:22.850702 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18c 2013-04-17 10:29:22.850740 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18e 2013-04-17 10:29:22.850777 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18f 2013-04-17 10:29:22.850813 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x1ffe 2013-04-17 10:29:22.851016 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): end 2013-04-17 10:29:22.851030 I DVBSH(/dev/dvb/adapter8/frontend0): run(): end 2013-04-17 10:29:22.851162 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- end 2013-04-17 10:29:22.851169 I DVBSM(/dev/dvb/adapter8/frontend0): Stop() -- end 2013-04-17 10:29:22.851207 I TVRec(17): TeardownSignalMonitor() -- end 2013-04-17 10:29:22.851217 I TVRec(17): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.851226 I TVRec(17): ClearFlags(WaitingForSignal,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady, 2013-04-17 10:29:22.851539 I EITScanner (17): Started passive scan. 2013-04-17 10:29:22.851545 I TVRec(17): Starting Recorder 2013-04-17 10:29:22.851908 I TVRec(17): FinishedRecording(21109_2013-04-17T08:29:22Z) title: Serwis... in recgroup: LiveTV status: Nagrywam:Nagrane is_dummy finished_now 2013-04-17 10:29:22.852507 I Chain: Updated endtime for '21109_20130417082922' to 20130417082922 2013-04-17 10:29:22.853240 I TVRec(17): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady, 2013-04-17 10:29:22.855155 I Using profile 'Live TV' to record 2013-04-17 10:29:22.855182 I TVRec(17): SwitchLiveTVRingBuffer(discont 1, set_next_rec 0) curRec(21109_2013-04-17T08:29:22Z) curRec.size(0) 2013-04-17 10:29:22.855598 I TVRec(17): GetProgramRingBufferForLiveTV() 2013-04-17 10:29:22.857293 N AutoExpire: CalcParams(): Max required Free Space: 17.0 GB w/freq: 14 min 2013-04-17 10:29:22.880172 E RecordingInfo::InsertProgram(ProgramInfo(21109_20130417082922.mpg): channame(Polsat News) startts(Wed Apr 17 08:00:00 2013) endts(Wed Apr 17 08:30:00 2013) recstartts(Wed Apr 17 08:29:22 2013) recendts(Wed Apr 17 08:30:00 2013) title(Serwis...)): recording already exists... 2013-04-17 10:29:22.882091 I TVRec(17): StartedRecording(21109_2013-04-17T08:29:23Z) fn(/myth/tv/21109_20130417082923.mpg) 2013-04-17 10:29:22.884456 I Chain: Appended@1 '21109_20130417082923' 2013-04-17 10:29:22.886989 I DTVRec(17): ResetForNewFile(void) 2013-04-17 10:29:22.887024 I RecBase(17:/dev/dvb/adapter8/frontend0): SetRingBuffer(0x7f084c124600) '/myth/tv/21109_20130417082923.mpg' 2013-04-17 10:29:22.887059 I DTVRec(17): SetPAT(13109 on 0x29) 2013-04-17 10:29:22.887085 I CreatePATSingleProgram() 2013-04-17 10:29:22.887087 I PAT in input stream 2013-04-17 10:29:22.887129 I Program Association Section PSIP tableID(0x0) length(69) extension(0x3390) version(0) current(1) section(0) last_section(0) tsid(13200) programCount(15) program number 0 has PID 0x0010 program number 13101 has PID 0x0021 program number 13102 has PID 0x0022 program number 13103 has PID 0x0023 program number 13104 has PID 0x0024 program number 13105 has PID 0x0025 program number 13106 has PID 0x0026 2013-04-17 10:29:22.887134 I desired_program(13109) pid(0x29) 2013-04-17 10:29:22.887150 I pmt_pid(0x29) 2013-04-17 10:29:22.887152 I PAT for output stream 2013-04-17 10:29:22.887166 I Program Association Section PSIP tableID(0x0) length(13) extension(0x3390) version(0) current(1) section(0) last_section(0) tsid(13200) programCount(1) program number 1 has PID 0x0029 2013-04-17 10:29:22.887193 I DTVRec(17): SetPMT(13109) 2013-04-17 10:29:22.887221 I CreatePMTSingleProgram() 2013-04-17 10:29:22.887224 I PMT in input stream 2013-04-17 10:29:22.887359 I Program Map Section PSIP tableID(0x2) length(280) extension(0x3335) version(1) current(1) section(0) last_section(0) pnum(13109) pid(0x29) Multiplex Buffer Utilization Descriptor (0x0c) length(4) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(178) Descriptor (0xb2) length(57) Conditional Access: sid(0x1861) pid(0x18a) data_size(0) Conditional Access: sid(0x1803) pid(0x18b) data_size(0) Conditional Access: sid(0x100) pid(0x18c) data_size(13) Conditional Access: sid(0xb01) pid(0x18e) data_size(0) 2013-04-17 10:29:22.887438 I PMT for output stream 2013-04-17 10:29:22.887543 I Program Map Section PSIP tableID(0x2) length(217) extension(0x1) version(1) current(1) section(0) last_section(0) pnum(1) pid(0x29) Multiplex Buffer Utilization Descriptor (0x0c) length(4) Maximum Bitrate Descriptor (0x0e) length(3) Unknown(178) Descriptor (0xb2) length(57) Stream #0 pid(0x181) type(0x02 video-mpeg2) Stream Identifier Descriptor (0x52): ComponentTag=0x1 Video Descriptor (0x02) length(3) Data Stream Alignment Descriptor (0x06) length(1) 2013-04-17 10:29:22.887564 I RecBase(17:/dev/dvb/adapter8/frontend0): SetRecording(0x7f084c19bf10) title(Serwis...) 2013-04-17 10:29:22.887893 I TVRec(17): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady, 2013-04-17 10:29:22.888127 I DTVRec(17): ResetForNewFile(void) 2013-04-17 10:29:22.888152 I DVBRec(17:/dev/dvb/adapter8/frontend0): Card opened successfully 2013-04-17 10:29:22.888188 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- begin 2013-04-17 10:29:22.888194 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- locked 2013-04-17 10:29:22.888276 I DVBSH(/dev/dvb/adapter8/frontend0): run(): begin 2013-04-17 10:29:22.893158 I TVRec(17): SetFlags(RecorderRunning,RingBufferReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady, 2013-04-17 10:29:22.893178 I TVRec(17): ClearFlags(NeedToStartRecorder,) -> FrontendReady,RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady, 2013-04-17 10:29:22.925449 I DevRdB(/dev/dvb/adapter8/frontend0): buffer size 32900 KB 2013-04-17 10:29:22.926593 I DevRdB(/dev/dvb/adapter8/frontend0): Start() -- begin 2013-04-17 10:29:22.926663 I DevRdB(/dev/dvb/adapter8/frontend0): Start() -- middle 2013-04-17 10:29:22.926668 I DevRdB(/dev/dvb/adapter8/frontend0): Start() -- end 2013-04-17 10:29:22.926672 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): begin 2013-04-17 10:29:22.926740 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x0 2013-04-17 10:29:22.926865 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x1 2013-04-17 10:29:22.926944 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x10 2013-04-17 10:29:22.927182 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x14 2013-04-17 10:29:22.927261 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x21 2013-04-17 10:29:22.927751 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x22 2013-04-17 10:29:22.927814 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x23 2013-04-17 10:29:22.927865 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x24 2013-04-17 10:29:22.927983 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x25 2013-04-17 10:29:22.928039 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x26 2013-04-17 10:29:22.928124 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x27 2013-04-17 10:29:22.928229 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x28 2013-04-17 10:29:22.928761 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x29 2013-04-17 10:29:22.929025 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x2a 2013-04-17 10:29:22.929387 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x32 2013-04-17 10:29:22.929451 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x36 2013-04-17 10:29:22.929512 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x39 2013-04-17 10:29:22.929571 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x43 2013-04-17 10:29:22.929631 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x83 2013-04-17 10:29:22.929690 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x86 2013-04-17 10:29:22.929750 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0xd0 2013-04-17 10:29:22.929828 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0xd5 2013-04-17 10:29:22.929890 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x108 2013-04-17 10:29:22.929952 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x181 2013-04-17 10:29:22.930026 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x182 2013-04-17 10:29:22.930097 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x184 2013-04-17 10:29:22.930163 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18a 2013-04-17 10:29:22.930230 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18b 2013-04-17 10:29:22.930298 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18c 2013-04-17 10:29:22.930367 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18e 2013-04-17 10:29:22.930745 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x18f 2013-04-17 10:29:22.930972 I PIDInfo(/dev/dvb/adapter8/frontend0): Opening filter for pid 0x1ffe 2013-04-17 10:29:22.950232 I MainServer::ANN Playback 2013-04-17 10:29:22.950240 I adding: fe-devel as a client (events: 0) 2013-04-17 10:29:22.952053 I MainServer::HandleAnnounce FileTransfer 2013-04-17 10:29:22.952060 I adding: fe-devel as a remote file transfer 2013-04-17 10:29:22.988401 I SH(/dev/dvb/adapter8/frontend0): AddListener(0x7f084c028180) -- end 2013-04-17 10:29:23.185951 I DTVRec(17): FindMPEG2Keyframes: frame rate = 25000 2013-04-17 10:29:23.186091 I DTVRec(17): PID 0x181 Found Payload Start 2013-04-17 10:29:23.186122 I DTVRec(17): PID 0x182 Found Payload Start 2013-04-17 10:29:24.222619 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:24.249353 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:25.156137 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:25.401827 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:26.368775 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:27.368924 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:27.395690 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:28.362650 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:29.329563 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:32.130627 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:32.195923 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:32.742085 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:32.807371 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:33.052943 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:33.719372 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:33.784629 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:34.030299 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:34.876956 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:34.942267 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:35.187948 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:35.794269 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:35.859531 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:38.600622 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:38.906268 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:39.452358 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:39.517664 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:39.763247 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:40.068969 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:40.134288 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:40.379912 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:41.346625 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:41.411942 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:42.018234 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:43.306731 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:43.852888 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:43.918199 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:44.103788 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:44.169002 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:44.835363 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:44.900612 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:45.146212 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:46.052861 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:46.118134 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:47.085056 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:48.074394 I RecBase(17:/dev/dvb/adapter8/frontend0): GetKeyframePositions(607,9223372036854775807,#0) out of 29 2013-04-17 10:29:49.089253 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:49.154580 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:49.640710 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:49.706010 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:49.951685 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:50.858381 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:50.923693 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:51.890524 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:51.955839 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:52.862698 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:52.928005 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:53.902475 I RecBase(17:/dev/dvb/adapter8/frontend0): GetKeyframePositions(607,9223372036854775807,#6) out of 35 2013-04-17 10:29:55.478395 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:55.543669 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:55.789307 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:56.696113 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:56.761381 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:57.761524 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:57.788301 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:58.695015 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:29:58.760286 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:00.915253 I TVRec(17): Switching Buffer (!has_rec(0) && !rec_soon(0) && (2013-04-17T08:30:00Z >= 2013-04-17T08:30:00Z(1) )) 2013-04-17 10:30:00.915279 I TVRec(17): SwitchLiveTVRingBuffer(discont 0, set_next_rec 1) curRec(21109_2013-04-17T08:29:23Z) curRec.size(0) 2013-04-17 10:30:00.915638 I TVRec(17): GetProgramRingBufferForLiveTV() 2013-04-17 10:30:00.917640 N AutoExpire: CalcParams(): Max required Free Space: 17.0 GB w/freq: 14 min 2013-04-17 10:30:00.949840 I TVRec(17): StartedRecording(21109_2013-04-17T08:30:00Z) fn(/myth/tv/21109_20130417083000.mpg) 2013-04-17 10:30:00.952004 I Chain: Appended@2 '21109_20130417083000' 2013-04-17 10:30:00.952048 I DTVRec(17): SetNextRecord(0x7f084c1995f0, 0x7f084c03eb80) 2013-04-17 10:30:00.952823 I TVRec(17): SetFlags(RingBufferReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady, 2013-04-17 10:30:00.952832 I TVRec(17): Enabling Full LiveTV UI. 2013-04-17 10:30:00.952860 I Waiting for ringbuffer switch 2013-04-17 10:30:00.952863 I TVRec(17): Enabling Full LiveTV UI. 2013-04-17 10:30:01.187985 I RecordingQuality() start(2013-04-17T08:00:00Z) end(2013-04-17T08:30:00Z) score(0) 2013-04-17 10:30:01.187998 I DTVRec(17): ResetForNewFile(void) 2013-04-17 10:30:01.188019 I RecBase(17:/dev/dvb/adapter8/frontend0): SetRingBuffer(0x7f084c03eb80) '/myth/tv/21109_20130417083000.mpg' 2013-04-17 10:30:01.188027 I RecBase(17:/dev/dvb/adapter8/frontend0): SetRecording(0x7f084c16ee00) title(Serwis...) 2013-04-17 10:30:01.188068 I TVRec(17): RingBufferChanged() 2013-04-17 10:30:01.188662 I TVRec(17): FinishedRecording(21109_2013-04-17T08:29:23Z) damaged recq:<RecordingQuality overall_score="0" key="21109_2013-04-17T08:29:23Z" countinuity_error_count="0" packet_count="95516"> <Gap start="2013-04-17T08:00:00Z" end="2013-04-17T08:29:22Z" duration="1762" /> </RecordingQuality> 2013-04-17 10:30:01.188709 I TVRec(17): FinishedRecording(21109_2013-04-17T08:29:23Z) title: Serwis... in recgroup: LiveTV status: Nieznany:Recorder Failed not_dummy finished_now 2013-04-17 10:30:01.189183 I Chain: Updated endtime for '21109_20130417082923' to 20130417083001 2013-04-17 10:30:01.189968 I SaveVideoProperties(0x38, 0x20) 2013-04-17 10:30:01.195260 I DTVRec(17): FindMPEG2Keyframes: frame rate = 25000 2013-04-17 10:30:01.775150 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:02.775337 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:03.124203 W RingBuf(/myth/tv/21109_20130417082923.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:05.923620 N Expiring 4 MB for 21109 at 2013-04-17T08:26:09Z => Serwis...:"Serwis informacyjny, Pogoda" 2013-04-17 10:30:05.923659 N Expiring 0 MB for 21109 at 2013-04-17T08:27:23Z => Serwis...:"Serwis informacyjny, Pogoda" 2013-04-17 10:30:05.923683 N Expiring 2 MB for 21109 at 2013-04-17T08:27:24Z => Serwis...:"Serwis informacyjny, Pogoda" 2013-04-17 10:30:05.923706 N Expiring 4 MB for 21109 at 2013-04-17T08:28:03Z => Serwis...:"Serwis informacyjny, Pogoda" 2013-04-17 10:30:13.781114 I MainServer::ANN Playback 2013-04-17 10:30:13.781123 I adding: fe-devel as a client (events: 0) 2013-04-17 10:30:13.782878 I MainServer::HandleAnnounce FileTransfer 2013-04-17 10:30:13.782884 I adding: fe-devel as a remote file transfer 2013-04-17 10:30:13.834441 I RecBase(17:/dev/dvb/adapter8/frontend0): GetKeyframePositions(289,9223372036854775807,#1) out of 14 2013-04-17 10:30:16.076372 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:16.802994 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:17.048496 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:17.775001 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:18.020587 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:19.020732 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:19.047515 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:20.047659 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:22.630061 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:22.695333 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:22.940969 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:23.547196 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:23.612464 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:23.858031 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:24.825108 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:24.890489 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:25.556776 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:28.904409 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:29.811185 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:29.876503 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:30.723242 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:30.788554 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:31.034424 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:31.941298 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:32.006465 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:32.973170 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:33.038458 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:35.042727 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:35.949237 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:36.014615 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:37.014772 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:37.101757 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:37.166978 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:38.133868 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:38.199125 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:39.105903 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:39.171146 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:39.416705 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:40.383540 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:40.448818 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:41.355595 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:41.420880 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:42.421037 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:44.512233 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:45.479029 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:45.544310 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:46.451007 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:46.516303 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:47.423075 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:47.488297 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:48.455248 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:48.520535 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:49.427357 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:49.492651 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:50.459526 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:50.524803 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:51.431554 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:52.790255 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:53.456621 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:53.521930 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:53.767486 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:54.433964 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:54.499283 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:54.744908 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:55.351096 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:55.416412 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:55.661996 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:57.616715 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:58.343216 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:58.408504 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:30:58.654267 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:00.493651 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:00.558974 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:02.578606 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:02.643966 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:03.610919 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:03.616058 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:03.681314 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:04.287620 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:04.352841 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:04.478251 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:07.349622 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:07.414897 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:07.660436 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:08.266633 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:08.331879 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:08.577461 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:09.484160 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:09.549401 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:10.516174 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:10.581452 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:11.067808 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:13.327750 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:13.573278 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:14.179414 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:14.244689 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:14.430092 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:14.495355 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:15.281941 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:15.347225 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:15.592849 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:16.259097 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:18.289055 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:19.015489 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:19.080694 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:19.266196 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:19.331521 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:19.817527 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:21.661907 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:21.727219 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:21.912750 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:21.978015 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:22.764508 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:22.829742 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:23.075405 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:24.849262 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:25.455445 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:25.520762 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:25.766367 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:26.432762 W RingBuf(/myth/tv/21109_20130417083000.mpg): Taking too long to be allowed to read.. 2013-04-17 10:31:26.510873 I TVRec(17): StopLiveTV(void) curRec: 0x7f082c2e6ae0 pseudoRec: 0x0 2013-04-17 10:31:26.511621 I TVRec(17): Changing from WatchingLiveTV to None 2013-04-17 10:31:26.512238 I TVRec(17): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady, 2013-04-17 10:31:26.512256 I TVRec(17): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,) 2013-04-17 10:31:26.512320 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- begin 2013-04-17 10:31:26.512333 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- locked 2013-04-17 10:31:26.512340 I DevRdB(/dev/dvb/adapter8/frontend0): Stop() -- begin 2013-04-17 10:31:26.512497 I DevRdB(/dev/dvb/adapter8/frontend0): Stop() -- end 2013-04-17 10:31:26.512646 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): shutdown 2013-04-17 10:31:26.512674 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x0 2013-04-17 10:31:26.512818 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x1 2013-04-17 10:31:26.512912 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x10 2013-04-17 10:31:26.512957 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x14 2013-04-17 10:31:26.513063 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x21 2013-04-17 10:31:26.513127 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x22 2013-04-17 10:31:26.513237 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x23 2013-04-17 10:31:26.513297 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x24 2013-04-17 10:31:26.513348 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x25 2013-04-17 10:31:26.513390 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x26 2013-04-17 10:31:26.513438 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x27 2013-04-17 10:31:26.513484 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x28 2013-04-17 10:31:26.513548 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x29 2013-04-17 10:31:26.513633 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x2a 2013-04-17 10:31:26.513678 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x32 2013-04-17 10:31:26.513764 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x36 2013-04-17 10:31:26.513851 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x39 2013-04-17 10:31:26.513889 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x43 2013-04-17 10:31:26.513972 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x83 2013-04-17 10:31:26.514019 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x86 2013-04-17 10:31:26.514057 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0xd0 2013-04-17 10:31:26.514098 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0xd5 2013-04-17 10:31:26.514199 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x108 2013-04-17 10:31:26.514337 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x181 2013-04-17 10:31:26.514424 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x182 2013-04-17 10:31:26.514477 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x184 2013-04-17 10:31:26.514513 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18a 2013-04-17 10:31:26.514608 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18b 2013-04-17 10:31:26.514704 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18c 2013-04-17 10:31:26.514739 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18e 2013-04-17 10:31:26.514950 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x18f 2013-04-17 10:31:26.515100 I PIDInfo(/dev/dvb/adapter8/frontend0): Closing filter for pid 0x1ffe 2013-04-17 10:31:26.515145 I DevRdB(/dev/dvb/adapter8/frontend0): Stop() -- begin 2013-04-17 10:31:26.515149 I DevRdB(/dev/dvb/adapter8/frontend0): Stop() -- end 2013-04-17 10:31:26.518077 I DVBSH(/dev/dvb/adapter8/frontend0): RunTS(): end 2013-04-17 10:31:26.518088 I DVBSH(/dev/dvb/adapter8/frontend0): run(): end 2013-04-17 10:31:26.519300 I SH(/dev/dvb/adapter8/frontend0): RemoveListener(0x7f084c028180) -- end 2013-04-17 10:31:26.519317 I DVBRec(17:/dev/dvb/adapter8/frontend0): Close() -- begin 2013-04-17 10:31:26.519347 I DVBRec(17:/dev/dvb/adapter8/frontend0): Close() -- end 2013-04-17 10:31:26.522461 I TVRec(17): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2013-04-17 10:31:26.522518 I RecordingQuality() start(2013-04-17T08:30:00Z) end(2013-04-17T09:00:00Z) score(0) 2013-04-17 10:31:26.522715 I RecBase(17:/dev/dvb/adapter8/frontend0): SetRecording(0x0) 2013-04-17 10:31:26.523573 I TVRec(17): FinishedRecording(21109_2013-04-17T08:30:00Z) damaged recq:<RecordingQuality overall_score="0" key="21109_2013-04-17T08:30:00Z" countinuity_error_count="0" packet_count="195650"> <Gap start="2013-04-17T08:31:25Z" end="2013-04-17T09:00:00Z" duration="1714" /> </RecordingQuality> 2013-04-17 10:31:26.523615 I TVRec(17): FinishedRecording(21109_2013-04-17T08:30:00Z) title: Serwis... in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now 2013-04-17 10:31:26.524098 I Chain: Updated endtime for '21109_20130417083000' to 20130417083126 2013-04-17 10:31:26.524986 I SaveVideoProperties(0x38, 0x20) 2013-04-17 10:31:26.527253 I TVRec(17): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady, 2013-04-17 10:31:26.527263 I TVRec(17): Tearing down RingBuffer 2013-04-17 10:31:26.527576 I TVRec(17): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady, 2013-04-17 10:31:26.528989 I TVRec(17): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady
comment:30 Changed 12 years ago by
It's obvious but FYI: I can rather confirm removing following hunk seems to solve problem with MPEG2 recording. (it looks on logs it solves - as I tested it only remotely via SSH and exterminating BE/FE logs :-p)
@@ -419,7 +418,11 @@ bool DTVRecorder::FindMPEG2Keyframes(const TSPacket* tspacket)
// looking for first byte of MPEG start code (3 bytes 0 0 1)
// otherwise, pick up search where we left off.
const bool payloadStart = tspacket->PayloadStart();
- _start_code = (payloadStart) ? 0xffffffff : _start_code;
+ if (payloadStart)
+ {
+ _start_code = 0xffffffff;
+ _seen_sps = false;
+ }
// Just make these local for efficiency reasons (gcc not so smart..)
const uint maxKFD = kMaxKeyFrameDistance;
Changed 12 years ago by
| Attachment: | SPS-H264Parser.patch added |
|---|
Fix parsing of SEI_TYPE_RECOVERY_POINT
comment:31 Changed 12 years ago by
git-diff4-cleaned.txt breaks keyframe detection for HD-PVR recordings. With it all I frames are counted as keyframes, but on the HD-PVR they are not.
That patch does clean up a few areas, though, and possibly most importantly, fixes the parsing of SEI recovery points. It also fixes some variable initializations.
I have attached a simplified version (SPS-H264Parser.patch) which doesn't break the HD-PVR. I am hoping it fixes the problem(s) described on this ticket. If it doesn't, the fix might get nasty since we will need to come up with a way of fixing these problems without breaking it for other people.
comment:33 Changed 12 years ago by
I don't think it breaks keyframe detection as such..problem is that the input data is dumped with no buffering because SPS is not seen.
My mistake because the H264 docs state that SPS/PPS do not have to be present in the same stream.. I suspect (from internet searches) that the hdpvr does not output SPS (or not often).
I don't like the idea of mushing parser states into one flag to avoid changing dtvrecorder but I understand your concerns.. A good soln could be to check for number keyframes passed without SPS & then start to write to file etc.. I have attached patch which does that.
This patch has no regressions with my international samples (playback) & local recording/ liveTV. In fact it has solved my problem with HLS (NasaTV) (liveTV).
I could try test hdpvr recording via dummy recorder but currently that assumes mpeg-ps.
Changed 12 years ago by
| Attachment: | gitdiff-cleaned5.txt added |
|---|
allow for H264 stream without SPS but still use it if possible.
comment:34 Changed 12 years ago by
After forcing dummy recorder to use H264 Parser & recording an hdpvr recording file..I get keyframes every 32 frames which is wrong should be every approx. 140 frames for 60fps.
Ah penny drops ..the flag "I_is_keyframe" was being set to false for hdpvr in mpegrecorder.cpp. I removed that logic. There still must be a flaw in the keyframe logic because there should not be a special case for hdpvr.
Have yet to test this...
comment:35 Changed 11 years ago by
FYI: I just give try for SPS-H264Parser-0.26.patch on current 0.26-fixes. Unfortunately "pixeled" edit with this patch returns. Also jumping forward/back is slower again (it has approx 1sec of slower playback just after jump and next playback becomes OK). With git-diff4-cleaned.txt I have OK working edit. Also jumps are really fast.
comment:36 Changed 11 years ago by
I am hoping to have more time to work on this soon. Do either of you have samples available that I can play with?
comment:37 Changed 11 years ago by
Sure, I can put it on my FTP (PM me pls for access details) or upload to place convenient for You. Tested recordings has 10min/2,5G. What "reasonable" size will be suitable for You?
comment:40 Changed 11 years ago by
I believe I have found the root of the problem reported. Using the sample that warpme provided, I determined that the reason the keyframe offsets where off, is because we were failing to flush the payload buffer whenever a new payload started.
I am attaching a patch which does that just for completeness, but I will likely go ahead and commit this fix within the next day...
Changed 11 years ago by
| Attachment: | keyframe-buffer-0.26.patch added |
|---|
Flush payload buffer at start each new payload - 0.26 version
Changed 11 years ago by
| Attachment: | keyframe-buffer.patch added |
|---|
Flush payload buffer whenever a new payload starts
comment:41 Changed 11 years ago by
| Resolution: | → fixed |
|---|---|
| Status: | accepted → closed |
comment:42 Changed 11 years ago by
| Milestone: | unknown → 0.27 |
|---|---|
| Version: | 0.26-fixes → Master Head |
comment:43 Changed 11 years ago by
My patch(s) also fixed the buffer offset problem in dtvrecorder.cpp.
HD-PVR: H264Parser.cpp correctly identifies actual IDR frames for HD-PVR & my later patch accidentally disabled the "all I frames as keyframes" override.
The identified IDR frames match with ffprobe & avidemux. I have also used Elecard StreamEye? (demo) analyser to inspect streams.
The original HD-PVR f/w produced non-compliant streams described as "No IDR, seekable I frame with no SEI recovery point messages. The "use_I_forKeyframes" function call (from mpegrecorder.cpp) sets "I_is_keyframe=true" for HD-PVR recordings. This then causes all I frames to be identified keyframes. I imagine this hack was needed to support the original HD-PVR streams.
The HD-PVR recording samples I have, use AVC main@L4.0 for 720p60 with an I frame every 28 frames with every 4th I frame as IDR. For IDR nal, the SEI recovery count is set correct (==0) & exact_match==1.
So for correct keyframe detection (in HD-PVR) needs I_is_keyframe=false. The non-IDR I frames do seem to be seekable so perhaps the I frames positions also need to be stored into the seektable ( but not as keyframes).
This keyframe error would explain the 0 to 2 sec position errors that have plagued the "lossless_cut" script.
Thanks.
comment:44 Changed 11 years ago by
Ha..from some digging in the archives.. http://www.gossamer-threads.com/lists/mythtv/commits/374997?search_string=hd-pvr;#374997 It seems you know all about this..
seektable created as recorded..