[mythtv-commits] Ticket #1454: mythfrontend "Ignoring livetv eof in decoder loop" message at end of LiveTV show then consumes all swap and crashes

MythTV mythtv at cvs.mythtv.org
Sat Mar 4 23:14:44 UTC 2006


#1454: mythfrontend "Ignoring livetv eof in decoder loop" message at end of LiveTV
show then consumes all swap and crashes
---------------------------------+------------------------------------------
 Reporter:  ut_crom at hotmail.com  |        Owner:  ijr 
     Type:  defect               |       Status:  new 
 Priority:  minor                |    Milestone:      
Component:  mythtv               |      Version:  0.19
 Severity:  medium               |   Resolution:      
---------------------------------+------------------------------------------
Comment (by ut_crom at hotmail.com):

 Additional observations.
 When I start LiveTV, the mythfrontend log shows normal operation:

 2006-03-04 14:56:33.560 Using audio as timebase
 2006-03-04 14:56:33.560 Video timing method: USleep with busy wait
 2006-03-04 14:56:33.560 Refresh rate: 16666, frame interval: 33366
 2006-03-04 14:56:35.966 AFD: positionMap[ 6 ] == 3330086.
 2006-03-04 14:56:36.466 AFD: positionMap[ 7 ] == 3813414.
 'video_output' mean = '33386.46', std. dev. = '4210.91', fps = '29.95'
 2006-03-04 14:56:36.967 AFD: positionMap[ 8 ] == 4284454.
 2006-03-04 14:56:37.467 AFD: positionMap[ 9 ] == 4773926.
 2006-03-04 14:56:37.967 AFD: positionMap[ 10 ] == 5255206.
 2006-03-04 14:56:38.470 AFD: positionMap[ 11 ] == 5599270.
 2006-03-04 14:56:38.970 AFD: positionMap[ 12 ] == 6021158.
 2006-03-04 14:56:39.470 AFD: positionMap[ 13 ] == 6440998.
 2006-03-04 14:56:39.970 AFD: positionMap[ 14 ] == 6864934.
 'video_output' mean = '33356.56', std. dev. = '1647.91', fps = '29.98'
 2006-03-04 14:56:40.470 AFD: positionMap[ 15 ] == 7311398.
 2006-03-04 14:56:40.970 AFD: positionMap[ 16 ] == 7778342.
 2006-03-04 14:56:41.471 AFD: positionMap[ 17 ] == 8232998.
 2006-03-04 14:56:41.973 AFD: positionMap[ 18 ] == 8724518.
 2006-03-04 14:56:42.473 AFD: positionMap[ 19 ] == 9267238.
 2006-03-04 14:56:42.973 AFD: positionMap[ 20 ] == 9746470.
 2006-03-04 14:56:43.473 AFD: positionMap[ 21 ] == 10231846.
 'video_output' mean = '33358.87', std. dev. = '1514.06', fps = '29.98'
 2006-03-04 14:56:43.974 AFD: positionMap[ 22 ] == 10704934.
 2006-03-04 14:56:44.474 AFD: positionMap[ 23 ] == 11325478.

 ... etc

 However, when changing the channel, the following "rebuffering" output is
 produced in the mythfrontend log:

 2006-03-04 14:57:07.203 reads allowed (149569 32768)
 2006-03-04 14:57:07.214 AFD: HandleGopStart: gopset not set, syncing
 positionMap
 2006-03-04 14:57:07.214 Resyncing position map. posmapStarted = 1
 livetv(1) watchingRec(1)
 2006-03-04 14:57:07.219 Filling position map from 2 to 1
 2006-03-04 14:57:07.227 Position map filled from Encoder to: 1
 2006-03-04 14:57:07.227 SyncPositionMap watchingrecording total: 1 entries
 2006-03-04 14:57:07.227 AFD: HandleGopStart: Initial key frame distance:
 15.
 'video_output' mean = '37939.83', std. dev. = '44485.65', fps = '26.36'
 2006-03-04 14:57:07.724 AFD: positionMap[ 1 ] == 1185894.
 2006-03-04 14:57:07.779 rebuffering (24641 32768)
 2006-03-04 14:57:07.907 reads allowed (155713 32768)
 2006-03-04 14:57:08.239 AFD: positionMap[ 2 ] == 1728614.
 2006-03-04 14:57:08.290 rebuffering (28737 32768)
 2006-03-04 14:57:08.483 reads allowed (159809 32768)
 2006-03-04 14:57:08.813 AFD: positionMap[ 3 ] == 2199654.
 2006-03-04 14:57:08.866 rebuffering (2113 32768)
 2006-03-04 14:57:09.059 reads allowed (133185 32768)
 2006-03-04 14:57:09.122 rebuffering (20545 32768)
 2006-03-04 14:57:09.379 reads allowed (151617 32768)
 2006-03-04 14:57:09.379 AFD: positionMap[ 4 ] == 2650214.
 2006-03-04 14:57:09.442 rebuffering (28737 32768)
 2006-03-04 14:57:09.698 reads allowed (159809 32768)
 2006-03-04 14:57:09.763 AFD: positionMap[ 5 ] == 3176550.
 2006-03-04 14:57:10.082 rebuffering (30785 32768)
 2006-03-04 14:57:10.338 reads allowed (161857 32768)
 2006-03-04 14:57:10.356 AFD: positionMap[ 6 ] == 3584102.
 2006-03-04 14:57:10.658 rebuffering (10305 32768)
 'video_output' mean = '33865.91', std. dev. = '5800.84', fps = '29.53'
 2006-03-04 14:57:10.914 reads allowed (141377 32768)
 2006-03-04 14:57:10.918 AFD: positionMap[ 7 ] == 4034662.
 2006-03-04 14:57:11.258 AFD: positionMap[ 8 ] == 4470886.
 2006-03-04 14:57:11.298 rebuffering (30785 32768)
 2006-03-04 14:57:11.491 reads allowed (161857 32768)
 2006-03-04 14:57:11.819 AFD: positionMap[ 9 ] == 4925542.
 2006-03-04 14:57:12.130 rebuffering (20545 32768)
 2006-03-04 14:57:12.450 buffering (20545 32768 0)
 2006-03-04 14:57:12.576 NVP: prebuffering pause
 2006-03-04 14:57:12.576 NVP: Waiting for prebuffer.. 0
 uAAAAAAAAAAAAAAaAALAAAAAAAAAAAA
 2006-03-04 14:57:12.706 reads allowed (151617 32768)
 2006-03-04 14:57:12.710 AFD: positionMap[ 10 ] == 5382246.
 2006-03-04 14:57:12.718 NVP: Waiting for prebuffer.. 1
 UUUAAUAAAAAAAAAAAAUALLAAAAAAAAA
 2006-03-04 14:57:12.770 rebuffering (26689 32768)
 2006-03-04 14:57:12.858 NVP: Waiting for prebuffer.. 2
 UUUAUUAAUAAAAAAAAAUAUuAALAAAAAA
 2006-03-04 14:57:12.998 NVP: Waiting for prebuffer.. 3
 UUUAUUAAUAAAAAAAAAUAUuAALAAAAAA
 2006-03-04 14:57:13.026 reads allowed (157761 32768)
 2006-03-04 14:57:13.044 AFD: positionMap[ 11 ] == 5744742.
 2006-03-04 14:57:13.361 AFD: positionMap[ 12 ] == 6017126.
 2006-03-04 14:57:13.410 rebuffering (24641 32768)
 2006-03-04 14:57:13.602 reads allowed (155713 32768)
 2006-03-04 14:57:13.666 rebuffering (28737 32768)
 2006-03-04 14:57:13.922 reads allowed (159809 32768)
 2006-03-04 14:57:13.928 AFD: positionMap[ 13 ] == 6469734.
 2006-03-04 14:57:14.328 AFD: positionMap[ 14 ] == 6920294.
 'video_output' mean = '37744.01', std. dev. = '45427.00', fps = '26.49'
 2006-03-04 14:57:14.691 rebuffering (26689 32768)
 2006-03-04 14:57:14.882 reads allowed (157761 32768)
 2006-03-04 14:57:14.891 AFD: positionMap[ 15 ] == 7325798.
 2006-03-04 14:57:15.288 AFD: positionMap[ 16 ] == 7739494.

 ...

 I noticed that this "rebuffering" occurs only when changing the channel
 and that LiveTV is 2 seconds behind the broadcast instead if the normal 5
 seconds. When I press the rewind button and then the fast forward button
 again, the buffer changes from 2 seconds to the normal 5 seconds. I also
 noticed that after i rewind and fast forward, the log produces the normal
 output intead of the output with the "rebuffering" messages.

 When a program ends during the time when the "rebuffering" messages occur,
 then mythfrontend starts to display the "Ignoring livetv eof in decoder
 loop", LiveTV freezes, mythfrontend consumes all of the swap and
 eventually crashes.

 When a progam ends and there is no "rebuffering" messages, then operation
 of mythfrontend continues normally without freezing LiveTV, consuming swap
 or crashing.

 I'll attach the full log of my observations.

-- 
Ticket URL: <http://svn.mythtv.org/trac/ticket/1454>
MythTV <http://www.mythtv.org/>
MythTV


More information about the mythtv-commits mailing list