[mythtv] [SVN7344] Live TV fails on second try

Sat Oct 1 23:20:57 UTC 2005

>
>
>These logs were not made with up to date SVN, so they don't tell me
>exactly what is wrong. Maybe your lib path is broken?
>
>Anyway it seems to have been caused by a RingBuffer shutdown issue.
>Try revision 7368 or later, it may be fixed there.
>
>==
>
>Please make sure you are running with up to date libs.
>  
>

I have updated to r7371 on both back- and frontend. Libraries look good 
on both (I did have versions going back to .16, so I deleted them before 
running 'make install') I have two DVB cards in the backend: a DVico 
Fusion HDTV Plus and a Twinhan Visionplus DVB-T. I have changed the 
signal_timeout value for the VisionPlus form 1000 to 3000. The frontend 
is set to "avoid scheduling conflicts", so card 2 gets used most of the 
time for Live TV. As a side note, should the frontend be configured to 
support DVB? I only have DVB support included on the backend.

server mythtv # ldd `which mythbackend` | grep 'libmyth'
        libmythtv-0.18.so.0 => /usr/local/lib/libmythtv-0.18.so.0 
(0xb75d4000)
        libmythavformat-0.18.so.0 => 
/usr/local/lib/libmythavformat-0.18.so.0 (0xb7562000)
        libmythavutil-0.18.so.0 => 
/usr/local/lib/libmythavutil-0.18.so.0 (0xb755e000)
        libmythavcodec-0.18.so.0 => 
/usr/local/lib/libmythavcodec-0.18.so.0 (0xb71ed000)
        libmyth-0.18.so.0 => /usr/local/lib/libmyth-0.18.so.0 (0xb6f0e000)

I'm still getting the problem when I exit and re-enter Live TV: I get a 
blank screen for ~20s, then get dropped back to the menu. It doesn't 
happen all the time, nor does it seem to be any particular channel. 
Here's the frontend log. It starts with live TV running. Then I escape 
to the menu, and hit enter to go back into live TV.

<Live TV running fine here>
2005-10-02 08:40:21.060 Read(): reqd=128000, rcvd=128000, rept=128000, 
error=0
2005-10-02 08:40:21.284 write -> 16 53      QUERY_RECORDER 
2[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
2005-10-02 08:40:21.306 read  <- 16 6       128000
2005-10-02 08:40:21.307 Read(): reqd=128000, rcvd=128000, rept=128000, 
error=0
2005-10-02 08:40:21.472 write -> 16 53      QUERY_RECORDER 
2[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
2005-10-02 08:40:21.503 read  <- 16 6       128000
2005-10-02 08:40:21.503 Read(): reqd=128000, rcvd=128000, rept=128000, 
error=0
<Escape to the menu>
2005-10-02 08:40:21.622 Attempting to change from WatchingLiveTV to None
2005-10-02 08:40:21.671 write -> 15 32      QUERY_RECORDER 2[]:[]STOP_LIVETV
2005-10-02 08:40:21.724 read  <-  4 50      
BACKEND_MESSAGE[]:[]DONE_RECORDING 2 127[]:[]empty
2005-10-02 08:40:21.763 read  <- 15 2       ok
2005-10-02 08:40:21.780 read  <-  4 51      
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2005-10-02 08:40:21.804 write -> 16 33      QUERY_RECORDER 
2[]:[]DONE_RINGBUF
2005-10-02 08:40:21.810 read  <- 16 2       OK
2005-10-02 08:40:21.810 Changing from WatchingLiveTV to None
2005-10-02 08:40:21.813 Attempting to change from None to None
<back at the menu now. Hit enter to go back into Live TV>
2005-10-02 08:40:26.301 write -> 14 29      GET_NEXT_FREE_RECORDER[]:[]-1
2005-10-02 08:40:26.313 read  <- 14 28      2[]:[]192.168.1.100[]:[]6543
2005-10-02 08:40:26.314 Attempting to change from None to WatchingLiveTV
2005-10-02 08:40:26.315 write -> 15 21      MYTH_PROTO_VERSION 18
2005-10-02 08:40:26.322 read  <- 15 13      ACCEPT[]:[]18
2005-10-02 08:40:26.322 Using protocol version 18
2005-10-02 08:40:26.323 write -> 15 19      ANN Playback epia 0
2005-10-02 08:40:26.331 read  <- 15 2       OK
2005-10-02 08:40:26.332 write -> 15 44      QUERY_RECORDER 
2[]:[]SETUP_RING_BUFFER[]:[]0
2005-10-02 08:40:26.404 read  <- 15 101     
ok[]:[]rbuf://192.168.1.100:6543/var/media/video/ringbuf2.mpg[]:[...
2005-10-02 08:40:26.406 write -> 16 19      ANN Playback epia 0
2005-10-02 08:40:26.415 read  <- 16 2       OK
2005-10-02 08:40:26.416 write -> 17 21      ANN RingBuffer epia 2
2005-10-02 08:40:26.425 read  <- 17 2       OK
2005-10-02 08:40:26.425 write -> 15 33      QUERY_RECORDER 
2[]:[]SPAWN_LIVETV
2005-10-02 08:40:46.426 ReadStringList timeout (quick).
2005-10-02 08:40:46.427 RemoteEncoder::SendReceiveStringList(): No response.
2005-10-02 08:40:46.427 WriteStringList: Bad socket
2005-10-02 08:40:46.428 ReadStringList: Bad socket
2005-10-02 08:40:46.428 RemoteEncoder::SendReceiveStringList(): No response.
2005-10-02 08:40:46.429 WriteStringList: Bad socket
2005-10-02 08:40:46.430 ReadStringList: Bad socket
<These three messages get repeated every 2ms until.........>
2005-10-02 08:41:06.427 RemoteEncoder::SendReceiveStringList(): No response.
2005-10-02 08:41:06.427 WriteStringList: Bad socket
2005-10-02 08:41:06.427 ReadStringList: Bad socket
2005-10-02 08:41:06.428 RemoteEncoder::SendReceiveStringList(): No response.
2005-10-02 08:41:06.428 StartRecorder() -- timed out waiting for 
recorder to start
2005-10-02 08:41:06.428 LiveTV not successfully started
2005-10-02 08:41:06.437 write -> 16 33      QUERY_RECORDER 
2[]:[]DONE_RINGBUF
2005-10-02 08:41:26.438 ReadStringList timeout (quick).
2005-10-02 08:41:26.439 Remote file timeout.
<Now I'm back at the main menu. If a subsequently hit enter gain to go 
back into live TV, a get a blank screen for a couple of seconds, then a 
message to the extent that the backend has gone away.>
2005-10-02 09:09:13.109 write -> 14 29      GET_NEXT_FREE_RECORDER[]:[]-1
2005-10-02 09:09:33.111 ReadStringList timeout (quick).
2005-10-02 09:09:33.112 Connection to backend server lost
2005-10-02 09:09:33.116 WriteStringList: Bad socket
2005-10-02 09:09:33.117 ReadStringList: Bad socket
2005-10-02 09:09:33.117 Reconnection to backend server failed

Here's what the backend's doing at the time:

<Live TV running fine here, then escape to the menu.>
2005-10-02 08:40:21.665 TVRec(2): Changing from WatchingLiveTV to None
2005-10-02 08:40:21.666 TVRec(2): 
ClearFlags(FrontendReady,CancelNextRecording,) -> 
RunMainLoop,AskAllowRecording,SIParserRunning,RecorderRunning,FlagRingBuf
ferReset,
2005-10-02 08:40:21.667 TVRec(2): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,SIParserRunning,RecorderRunning,FlagRingBufferReset,
2005-10-02 08:40:21.667 TVRec(2): Request: Program(no) channel() input() 
flags(KillRec,)
2005-10-02 08:40:21.668 SIParser: Stopping DVB Section Reader
2005-10-02 08:40:21.688 SIParser: DVB Section Reader thread stopped
2005-10-02 08:40:21.690 DVB#1 Rec: Closing DVB recorder
2005-10-02 08:40:21.691 TVRec(2): SetFlags(FlagRingBufferReset,) -> 
RunMainLoop,AskAllowRecording,SIParserRunning,RecorderRunning,FlagRingBufferReset,
2005-10-02 08:40:21.692 TVRec(2): 
ClearFlags(WaitingForSIParser,SIParserRunning,) -> 
RunMainLoop,AskAllowRecording,RecorderRunning,FlagRingBufferReset,
2005-10-02 08:40:21.692 TVRec(2): 
ClearFlags(WaitingForSignal,SignalMonitorRunning,) -> 
RunMainLoop,AskAllowRecording,RecorderRunning,FlagRingBufferReset,
2005-10-02 08:40:21.747 TVRec(2): ClearFlags(RecorderRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:21.748 TVRec(2): ClearFlags(RecorderRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:21.749 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
<Back at the menu. Hit enterr to go back into Live TV.>
2005-10-02 08:40:26.293 Getting next free recorder after : -1
2005-10-02 08:40:26.296 Checking card 1. Best card so far 1
2005-10-02 08:40:26.297 Checking card 2. Best card so far 2
2005-10-02 08:40:26.317 MainServer::HandleAnnounce Playback
2005-10-02 08:40:26.318 adding: epia as a client (events: 0)
2005-10-02 08:40:26.325 TVRec(2): Request: Program(no) channel() input() 
flags(KillRingBuffer,)
2005-10-02 08:40:26.326 TVRec(2): 
ClearFlags(WaitingForSIParser,SIParserRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.326 TVRec(2): 
ClearFlags(WaitingForSignal,SignalMonitorRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.327 TVRec(2): Tearing down RingBuffer
2005-10-02 08:40:26.327 DummyDTVRecorder::StopRecordingThread(void)
2005-10-02 08:40:26.329 DummyDTVRecorder::StopRecordingThread(void)
2005-10-02 08:40:26.329 TVRec(2): ClearFlags(DummyRecorderRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.385 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.385 TVRec(2): Request: Program(no) channel() input() 
flags(KillRingBuffer,)
2005-10-02 08:40:26.386 TVRec(2): 
ClearFlags(WaitingForSIParser,SIParserRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.386 TVRec(2): 
ClearFlags(WaitingForSignal,SignalMonitorRunning,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.387 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,FlagRingBufferReset,
2005-10-02 08:40:26.401 MainServer::HandleAnnounce Playback
2005-10-02 08:40:26.402 adding: epia as a client (events: 0)
2005-10-02 08:40:26.409 adding: epia as a remote ringbuffer

Note that the backend doesn't log anything one the frontend's final 
attempt to enter live TV. The backend is still running, though.

I hope this is useful..

Cheers,

Jon