#684: LiveTV: "Waited too long for ringbuffer pause" on program change
--------------------+-------------------------------------------------------
Reporter: oscar | Owner: ijr
Type: defect | Status: new
Priority: major | Milestone: 0.19
Component: mythtv | Version: head
Severity: medium |
--------------------+-------------------------------------------------------
When viewing LiveTV and there's a program change (at 13:35), the frontend
times out waiting for data.
Frontend:
{{{
2005-11-20 13:35:00.040 Resyncing position map. posmapStarted = 0
livetv(1) watchingRec(0)
2005-11-20 13:35:00.087 Position map filled from DB to: 191
2005-11-20 13:35:00.087 SyncPositionMap watchingrecording, from DB: 191
entries
2005-11-20 13:35:00.088 SyncPositionMap watchingrecording no entries from
encoder, try DB
2005-11-20 13:35:00.108 Position map filled from DB to: 192
2005-11-20 13:35:00.109 SyncPositionMap watchingrecording total: 192
entries
2005-11-20 13:35:01.162 NVP: prebuffering pause
2005-11-20 13:35:01.162 waiting for prebuffer... 0
2005-11-20 13:35:01.325 waiting for prebuffer... 1
2005-11-20 13:35:01.488 waiting for prebuffer... 2
2005-11-20 13:35:01.651 waiting for prebuffer... 3
2005-11-20 13:35:01.814 waiting for prebuffer... 4
2005-11-20 13:35:01.976 waiting for prebuffer... 5
2005-11-20 13:35:02.139 waiting for prebuffer... 6
2005-11-20 13:35:02.302 waiting for prebuffer... 7
2005-11-20 13:35:02.465 waiting for prebuffer... 8
2005-11-20 13:35:02.628 waiting for prebuffer... 9
2005-11-20 13:35:02.792 waiting for prebuffer... 10
2005-11-20 13:35:02.954 Prebuffer wait timed out 10 times.
2005-11-20 13:35:02.954 waiting for prebuffer... 0
2005-11-20 13:35:03.117 waiting for prebuffer... 1
2005-11-20 13:35:03.280 waiting for prebuffer... 2
2005-11-20 13:35:03.443 waiting for prebuffer... 3
2005-11-20 13:35:03.606 waiting for prebuffer... 4
2005-11-20 13:35:03.689 LiveTVChain::SwitchToNext(up)
2005-11-20 13:35:03.689 LiveTVChain::SwitchTo(1)
2005-11-20 13:35:03.690 LiveTVChain: [EMAIL PROTECTED]: '6_20051120133500'
2005-11-20 13:35:03.769 waiting for prebuffer... 5
2005-11-20 13:35:03.932 waiting for prebuffer... 6
2005-11-20 13:35:04.095 waiting for prebuffer... 7
2005-11-20 13:35:04.258 waiting for prebuffer... 8
2005-11-20 13:35:04.421 waiting for prebuffer... 9
2005-11-20 13:35:04.523
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg): Waited 4 seconds
for data to become available, waiting again...
2005-11-20 13:35:04.584 waiting for prebuffer... 10
2005-11-20 13:35:04.747 Prebuffer wait timed out 10 times.
}}}
This is repeated a couple of times, then theres this:
{{{
2005-11-20 13:35:32.543
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg): Waited 14 seconds
for data to become available, aborting
2005-11-20 13:35:32.628 waiting for prebuffer... 6
2005-11-20 13:35:32.791 waiting for prebuffer... 7
2005-11-20 13:35:32.954 waiting for prebuffer... 8
2005-11-20 13:35:33.117 waiting for prebuffer... 9
2005-11-20 13:35:33.280 waiting for prebuffer... 10
2005-11-20 13:35:33.443 Prebuffer wait timed out 10 times.
2005-11-20 13:35:33.443 waiting for prebuffer... 0
2005-11-20 13:35:33.580
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg): Waited too long
for ringbuffer pause..
2005-11-20 13:35:33.606 waiting for prebuffer... 1
2005-11-20 13:35:33.769 waiting for prebuffer... 2
2005-11-20 13:35:33.932 waiting for prebuffer... 3
2005-11-20 13:35:34.094 waiting for prebuffer... 4
2005-11-20 13:35:34.257 waiting for prebuffer... 5
2005-11-20 13:35:34.420 waiting for prebuffer... 6
2005-11-20 13:35:34.583 waiting for prebuffer... 7
2005-11-20 13:35:34.585
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg): Waited too long
for ringbuffer pause..
2005-11-20 13:35:34.747 waiting for prebuffer... 8
2005-11-20 13:35:34.909 waiting for prebuffer... 9
2005-11-20 13:35:35.072 waiting for prebuffer... 10
2005-11-20 13:35:35.235 Prebuffer wait timed out 10 times.
2005-11-20 13:35:35.236 waiting for prebuffer... 0
2005-11-20 13:35:35.398 waiting for prebuffer... 1
2005-11-20 13:35:35.561 waiting for prebuffer... 2
2005-11-20 13:35:35.588
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg): Waited too long
for ringbuffer pause..
2005-11-20 13:35:35.719
RingBuf(myth://192.168.1.20:6543/6_20051120133328.mpg):
OpenFile(myth://192.168.1.20:6543/6_20051120133500.mpg, 4)
2005-11-20 13:35:35.725 waiting for prebuffer... 3
[mpeg2video @ 0xb76f4270]00 motion_type at 9 6
[mpeg2video @ 0xb76f4270]Warning MVs not available
2005-11-20 13:35:35.888 VideoOutputXv: dtor
2005-11-20 13:35:35.888 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAUUULAAAAAAAA
2005-11-20 13:35:35.889 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
}}}
The backend at the same time:
{{{
2005-11-20 13:35:00.672 TVRec(2): SwitchLiveTVRingBuffer(discont 0)
2005-11-20 13:35:00.672 TVRec(2): GetProgramRingBufferForLiveTV()
2005-11-20 13:35:00.834 TVRec(2): StartedRecording(0x818ff90)
fn(/var/video/6_20051120133500.mpg)
[New Thread -1343415376 (LWP 24109)]
[New Thread -1390425168 (LWP 24110)]
[New Thread -1351808080 (LWP 24111)]
2005-11-20 13:35:00.874 Chain: [EMAIL PROTECTED] '6_20051120133500'
2005-11-20 13:35:00.875 TVRec(2): SetFlags(RingBufferReset,) ->
FrontendReady,RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReset,
2005-11-20 13:35:00.905 PreviewGen, Error: Run() file not local:
'myth://192.168.1.20:6543/6_20051120133328.mpg'
[Thread -1351808080 (LWP 24111) exited]
2005-11-20 13:35:00.986 RecBase(/dev/video1): SetRingBuffer(0x81947e0)
2005-11-20 13:35:00.987 TVRec(2): RingBufferChanged()
[Thread -1382032464 (LWP 24098) exited]
[Thread -1373639760 (LWP 24097) exited]
2005-11-20 13:35:01.026 Finished recording Lyckochansen: channel 6
2005-11-20 13:35:01.034 scheduler: Last message repeated 1 times
2005-11-20 13:35:01.047 scheduler: Finished recording
2005-11-20 13:35:36.614 MainServer::HandleAnnounce Playback
2005-11-20 13:35:36.614 adding: laban as a client (events: 0)
2005-11-20 13:35:36.622 MainServer::HandleAnnounce FileTransfer
2005-11-20 13:35:36.622 adding: laban as a remote file transfer
2005-11-20 13:35:36.630 Local file path: /var/video/6_20051120133500.mpg
2005-11-20 13:35:36.630 RingBuf(/var/video/6_20051120133500.mpg):
OpenFile(/var/video/6_20051120133500.mpg, 6)
2005-11-20 13:35:44.173 AutoExpire::UpdateDontExpireSet: Adding chanid 8 @
Sun Nov 20 12:30:01 2005 to DON'T Expire List
2005-11-20 13:35:44.173 AutoExpire::UpdateDontExpireSet: Adding chanid 6 @
Sun Nov 20 13:35:00 2005 to DON'T Expire List
2005-11-20 13:35:44.174 AutoExpire::UpdateDontExpireSet: Adding chanid 6 @
Sun Nov 20 13:35:00 2005 to DON'T Expire List
2005-11-20 13:36:44.193 AutoExpire::UpdateDontExpireSet: Adding chanid 8 @
Sun Nov 20 12:30:01 2005 to DON'T Expire List
2005-11-20 13:36:44.193 AutoExpire::UpdateDontExpireSet: Adding chanid 6 @
Sun Nov 20 13:35:00 2005 to DON'T Expire List
2005-11-20 13:36:44.194 AutoExpire::UpdateDontExpireSet: Adding chanid 6 @
Sun Nov 20 13:35:00 2005 to DON'T Expire List
2005-11-20 13:36:44.217 AutoExpire::FillDBOrdered: Adding chanid 6 @ Sun
Nov 20 13:33:28 2005 to expire list
2005-11-20 13:36:44.218 AutoExpiring: Lyckochansen Sun Nov 20 12:50:00
2005 62 MBytes
2005-11-20 13:36:44.218 After unlink we will have 14034 MB free.
[New Thread -1373639760 (LWP 24112)]
2005-11-20 13:36:44.372 Reschedule requested for id 0.
2005-11-20 13:36:45.594 Scheduled 60 items in 1.2 = 0.00 match + 1.22
place
2005-11-20 13:36:45.670 scheduler: Scheduled items
2005-11-20 13:36:47.406 About to unlink/delete file:
/var/video/6_20051120133328.mpg
2005-11-20 13:36:53.872 Reschedule requested for id 0.
}}}
Let me know if you need more info or can't reproduce it.
At revision 7943.
--
Ticket URL: <http://svn.mythtv.org/trac/ticket/684>
MythTV <http://www.mythtv.org/>
MythTV
_______________________________________________
mythtv-commits mailing list
mythtv-commits@mythtv.org
http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-commits