[mythtv-commits] Ticket #10934: Can't enter liveTV with IPTV

MythTV noreply at mythtv.org
Mon Jul 30 11:48:18 UTC 2012


#10934: Can't enter liveTV with IPTV
----------------------------------+-----------------------------
 Reporter:  jyavenard             |          Owner:  jya
     Type:  Bug Report - General  |         Status:  assigned
 Priority:  blocker               |      Milestone:  unknown
Component:  MythTV - General      |        Version:  Unspecified
 Severity:  medium                |     Resolution:
 Keywords:                        |  Ticket locked:  0
----------------------------------+-----------------------------

Comment (by jyavenard):

 I implemented a new method to immediately interrupt HLSRingBuffer::Read()
 (well, will happen at most 1s after the request), it changes nothing.

 Here is the backend log when trying to start playback:
 {{{
 2012-07-30 21:04:35.796998 I  Getting next free recorder after : -1
 2012-07-30 21:04:35.797095 I  Checking card 1. Best card so far -1
 2012-07-30 21:04:35.797430 I  Best card is 1
 2012-07-30 21:04:35.799878 I  MainServer::ANN Playback
 2012-07-30 21:04:35.799884 I  adding: jyaimac as a client (events: 0)
 2012-07-30 21:04:35.812075 I  TVRec(1): Changing from None to
 WatchingLiveTV
 2012-07-30 21:04:35.812095 I  TVRec(1):
 ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
 2012-07-30 21:04:35.812144 I  TVRec(1): HandleTuning Request:
 Program(NULL) channel() input() flags(LiveTV,)
 2012-07-30 21:04:35.813141 I  TVRec(1): Start channel: 301.
 2012-07-30 21:04:35.814416 I  TVRec(1): HW Tuner: 1->1
 2012-07-30 21:04:35.814423 I  TVRec(1): ClearFlags(PENDINGACTIONS,) ->
 RunMainLoop,
 2012-07-30 21:04:35.814458 I  TVRec(1): No recorder yet, calling
 TuningFrequency
 2012-07-30 21:04:35.814644 I  IPTVChan(1): Open() -- begin
 2012-07-30 21:04:35.814649 I  IPTVChan(1): Open() -- locked
 2012-07-30 21:04:35.815454 I  ChannelBase(1): Input #1: 'MPEG2TS'
 schan(301) sourceid(1) ccid(1)
 2012-07-30 21:04:35.815461 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
 2012-07-30 21:04:35.815478 I  IPTVChan(1): Open() -- end
 2012-07-30 21:04:35.815486 D  ChannelBase(1): SwitchToInput(MPEG2TS,301)
 2012-07-30 21:04:35.816374 I  IPTVChan(1): SetChannelByString(301) --
 begin
 2012-07-30 21:04:35.816379 I  IPTVChan(1): SetChannelByString() -- locked
 2012-07-30 21:04:35.817181 I  IPTVChan(1): GetChanInfo() -- begin
 2012-07-30 21:04:35.817186 I  IPTVChan(1): GetChanInfo() -- locked
 2012-07-30 21:04:35.817352 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al
 Jazeera (English))
 Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
 2012-07-30 21:04:35.817374 I  IPTVChan(1): SetChannelByString(301) = 301
 -- end
 2012-07-30 21:04:35.817403 I  TVRec(1): CreateLiveTVRingBuffer(301)
 2012-07-30 21:04:35.817695 I  TVRec(1): GetProgramRingBufferForLiveTV()
 2012-07-30 21:04:35.822368 N  AutoExpire: CalcParams(): Max required Free
 Space: 3.0 GB w/freq: 14 min
 2012-07-30 21:04:35.831802 I  TVRec(1):
 StartedRecording(1301_2012-07-30T11:04:35Z)
 fn(/DATA/Users/jyavenard/Downloads/mythtv/1301_20120730110435.mpg)
 2012-07-30 21:04:35.834733 I  Using profile 'Default' to record
 2012-07-30 21:04:35.837206 I  Chain: Appended at 0 '1301_20120730110435'
 2012-07-30 21:04:35.838021 I  TVRec(1): Starting Signal Monitor
 2012-07-30 21:04:35.838027 I  TVRec(1): SetupSignalMonitor(1, 1)
 2012-07-30 21:04:35.838103 I  IPTVChan(1): Open() -- begin
 2012-07-30 21:04:35.838107 I  IPTVChan(1): Open() -- locked
 2012-07-30 21:04:35.839044 I  ChannelBase(1): Input #1: 'MPEG2TS'
 schan(301) sourceid(1) ccid(1)
 2012-07-30 21:04:35.839051 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
 2012-07-30 21:04:35.839069 I  IPTVChan(1): Open() -- end
 2012-07-30 21:04:35.839270 I  IPTVChan(1): GetChanInfo() -- begin
 2012-07-30 21:04:35.839274 I  IPTVChan(1): GetChanInfo() -- locked
 2012-07-30 21:04:35.839459 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al
 Jazeera (English))
 Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
 2012-07-30 21:04:35.839494 I  IPTVFeed: Open() -- begin
 2012-07-30 21:04:35.839498 I  IPTVFeed: Init() -- begin
 [Switching to process 74535 thread 0x5207]
 2012-07-30 21:04:36.682758 D  HLSBuffer: IsHTTPLiveStreaming: #EXTM3U
 2012-07-30 21:04:36.682776 D  HLSBuffer: IsHTTPLiveStreaming:
 #EXT-X-VERSION:3
 2012-07-30 21:04:36.682940 I  IPTVFeed: Init() -- adding listeners
 2012-07-30 21:04:36.683005 I  IPTVFeed: Init() -- end 1
 2012-07-30 21:04:36.683012 I  IPTVHLS:
 Open(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) -- begin
 2012-07-30 21:04:37.766495 D  HLSBuffer: IsHTTPLiveStreaming: #EXTM3U
 2012-07-30 21:04:37.766503 D  HLSBuffer: IsHTTPLiveStreaming:
 #EXT-X-VERSION:3
 2012-07-30 21:04:37.766510 I  HLSBuffer: HTTP Live Streaming
 (http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8)
 2012-07-30 21:04:37.766554 I  HLSBuffer: Meta playlist
 2012-07-30 21:04:37.766578 I  HLSBuffer: bandwidth adaptation detected
 (program-id=1, bandwidth=409200
 2012-07-30 21:04:38.569454 I  HLSBuffer: Live Playlist HLS protocol
 version: 3
 2012-07-30 21:04:38.569464 D  HLSBuffer: ParseM3U8: #EXTM3U
 2012-07-30 21:04:38.569477 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
 2012-07-30 21:04:38.569488 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
 2012-07-30 21:04:38.569498 D  HLSBuffer: ParseM3U8:
 #EXT-X-TARGETDURATION:11
 2012-07-30 21:04:38.569512 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-
 SEQUENCE:208
 2012-07-30 21:04:38.569531 D  HLSBuffer: ParseM3U8: #EXTINF:8,
 2012-07-30 21:04:38.569549 D  HLSBuffer: ParseM3U8:
 media_208.ts?wowzasessionid=2103399960
 2012-07-30 21:04:38.569652 D  HLSBuffer: ParseM3U8: #EXTINF:9,
 2012-07-30 21:04:38.569661 D  HLSBuffer: ParseM3U8:
 media_209.ts?wowzasessionid=2103399960
 2012-07-30 21:04:38.569681 D  HLSBuffer: ParseM3U8: #EXTINF:11,
 2012-07-30 21:04:38.569688 D  HLSBuffer: ParseM3U8:
 media_210.ts?wowzasessionid=2103399960
 2012-07-30 21:04:38.569906 I  HLSBuffer: Starting Prefetch for 2 segments
 2012-07-30 21:04:38.570035 D  HLSBuffer: started download of segment 0
 [208/211] using stream 0
 [Switching to process 74535 thread 0x707]
 2012-07-30 21:04:41.300927 I  Starting mythlogserver
 2012-07-30 21:04:41.938138 D  HLSBuffer: downloaded segment 0 [id:208]
 took 3368ms for 401192 bytes: bandwidth:116.326kiB/s
 2012-07-30 21:04:41.938174 D  HLSBuffer: download completed, 3 segments
 ahead
 2012-07-30 21:04:41.938212 D  HLSBuffer: candidate stream 0 bitrate 952941
 >= 409200
 2012-07-30 21:04:41.938228 D  HLSBuffer: started download of segment 1
 [209/211] using stream 0
 2012-07-30 21:04:42.809424 I  MainServer::ANN Playback
 2012-07-30 21:04:42.809429 I  adding: jyaimac as a client (events: 0)
 2012-07-30 21:04:43.550389 D  HLSBuffer: downloaded segment 1 [id:209]
 took 1612ms for 413412 bytes: bandwidth:250.429kiB/s
 2012-07-30 21:04:43.550401 D  HLSBuffer: download completed, 2 segments
 ahead
 2012-07-30 21:04:43.550409 D  HLSBuffer: candidate stream 0 bitrate
 1502227 >= 409200
 2012-07-30 21:04:43.550424 D  HLSBuffer: started download of segment 2
 [210/211] using stream 0
 2012-07-30 21:04:43.550471 I  HLSBuffer: Finished Prefetch (4.98056s)
 2012-07-30 21:04:43.550579 I  IPTVHLS: Open() -- end
 2012-07-30 21:04:43.550583 I  IPTVFeed: Open() -- end
 2012-07-30 21:04:43.550597 I  TVRec(1): Signal monitor successfully
 created
 2012-07-30 21:04:43.550602 I  TVRec(1): Setting up table monitoring.
 2012-07-30 21:04:43.550661 D  HLSBuffer: PlayListWorker refreshing in 0s
 2012-07-30 21:04:43.552246 I  Using profile 'Live TV' to record
 2012-07-30 21:04:43.552798 I  TVRec(1): MPEG program number: 1
 2012-07-30 21:04:43.553338 I  DTVSM()::SetProgramNumber(1):
 2012-07-30 21:04:43.553385 D  SM()::RemoveFlags: Seen(PMT,Crypt,)
 Match(PMT,Crypt,) Wait()
 2012-07-30 21:04:43.553612 D  SM()::AddFlags: Seen() Match() Wait(PMT,)
 2012-07-30 21:04:43.553633 D  SM()::AddFlags: Seen() Match()
 Wait(PAT,PMT,Pos,)
 2012-07-30 21:04:43.553641 I  TVRec(1): Successfully set up MPEG table
 monitoring.
 2012-07-30 21:04:43.553831 D  SM()::Start: begin
 2012-07-30 21:04:43.553942 D  SM()::Start: end
 2012-07-30 21:04:43.553958 I  TVRec(1): SetFlags(SignalMonitorRunning,) ->
 RunMainLoop,SignalMonitorRunning,
 2012-07-30 21:04:43.553967 I  TVRec(1): ClearFlags(WaitingForSignal,) ->
 RunMainLoop,SignalMonitorRunning,
 2012-07-30 21:04:43.553975 I  TVRec(1): SetFlags(WaitingForSignal,) ->
 RunMainLoop,WaitingForSignal,SignalMonitorRunning,
 2012-07-30 21:04:43.553983 I  TVRec(1): SetFlags(DummyRecorderRunning,) ->
 RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,
 2012-07-30 21:04:43.553987 I  DummyDTVRecorder -- started
 2012-07-30 21:04:43.553995 I  TVRec(1): SetFlags(RingBufferReady,) ->
 RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:43.554006 I  TVRec(1): ClearFlags(NeedToStartRecorder,)
 ->
 RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:43.554015 I  TVRec(1): SetFlags(NeedToStartRecorder,) ->
 RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:43.554035 D  IPTVSM()::UpdateValues: Waiting for table
 monitor to start
 2012-07-30 21:04:43.554065 D  IPTVSM()::Run: begin
 2012-07-30 21:04:43.554072 I  IPTVFeed: AddListener(0x10783ee38) -- begin
 2012-07-30 21:04:43.554143 I  TVRec(1): SetFlags(CancelNextRecording,) ->
 RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:43.554310 I  FbFeedLive:AddListener(0x10783ee38) -- begin
 2012-07-30 21:04:43.554314 I  FbFeedLive:RemoveListener(0x10783ee38) --
 begin
 2012-07-30 21:04:43.554318 I  FbFeedLive:RemoveListener(0x10783ee38) --
 end 1
 2012-07-30 21:04:43.554322 I  FbFeedLive:AddListener(0x10783ee38) -- end
 2012-07-30 21:04:43.554326 I  IPTVFeed: AddListener(0x10783ee38) -- end 1
 2012-07-30 21:04:43.554329 I  IPTVFeed: Run() -- begin
 2012-07-30 21:04:43.554332 D  HLSBuffer: requesting restart
 2012-07-30 21:04:43.554395 I  HLSBuffer: started reading segment 0
 [id:208] from stream 0 (2 buffered)
 2012-07-30 21:04:43.555065 I  TVRec(1): StopLiveTV(void) curRec:
 0x10936cee0 pseudoRec: 0x0
 2012-07-30 21:04:43.555865 D  SM()::AddFlags: Seen(PAT,) Match() Wait()
 2012-07-30 21:04:43.555873 D  SM()::AddFlags: Seen() Match(PAT,) Wait()
 2012-07-30 21:04:43.555952 I  CreatePATSingleProgram()
 2012-07-30 21:04:43.555954 I  PAT in input stream
 2012-07-30 21:04:43.555983 I  Program Association Section
  PSIP tableID(0x0) length(13) extension(0x1)
       version(0) current(1) section(0) last_section(0)
       tsid(1) programCount(1)
   program number     1 has PID 0x0fff

 2012-07-30 21:04:43.555988 I  desired_program(1) pid(0xfff)
 2012-07-30 21:04:43.556141 I  pmt_pid(0xfff)
 2012-07-30 21:04:43.556144 I  PAT for output stream
 2012-07-30 21:04:43.556158 I  Program Association Section
  PSIP tableID(0x0) length(13) extension(0x1)
       version(0) current(1) section(0) last_section(0)
       tsid(1) programCount(1)
   program number     1 has PID 0x0fff

 2012-07-30 21:04:43.556464 D  SM()::AddFlags: Seen(PMT,) Match() Wait()
 2012-07-30 21:04:43.556861 D  SM()::AddFlags: Seen() Match(PMT,) Wait()
 2012-07-30 21:04:43.556865 I  CreatePMTSingleProgram()
 2012-07-30 21:04:43.556867 I  PMT in input stream
 2012-07-30 21:04:43.556937 I  Program Map Section
  PSIP tableID(0x2) length(60) extension(0x1)
       version(0) current(1) section(0) last_section(0)
       pnum(1) pid(0xfff)
   Metadata Pointer Descriptor (0x25) length(15)
   Stream #0 pid(0x102) type(0x15 unknown)
     Metadata Descriptor (0x26) length(13)
   Stream #1 pid(0x100) type(0x1b video-h264)
   Stream #2 pid(0x101) type(0x0f audio-aac)

 2012-07-30 21:04:43.557508 I  PMT for output stream
 2012-07-30 21:04:43.557540 I  Program Map Section
  PSIP tableID(0x2) length(60) extension(0x1)
       version(0) current(1) section(0) last_section(0)
       pnum(1) pid(0xfff)
   Metadata Pointer Descriptor (0x25) length(15)
   Stream #0 pid(0x102) type(0x15 unknown)
     Metadata Descriptor (0x26) length(13)
   Stream #1 pid(0x100) type(0x1b video-h264)
   Stream #2 pid(0x101) type(0x0f audio-aac)

 2012-07-30 21:04:43.558078 I  HLSBuffer: started reading segment 1
 [id:209] from stream 0 (1 buffered)
 2012-07-30 21:04:43.558154 I  HLSBuffer: pausing until we get sufficient
 data buffered
 2012-07-30 21:04:43.559415 D  IPTVSM()::UpdateValues: Table monitor
 started
 2012-07-30 21:04:43.565628 I  TVRec(1): Changing from WatchingLiveTV to
 None
 2012-07-30 21:04:43.565660 I  TVRec(1):
 ClearFlags(FrontendReady,CancelNextRecording,) ->
 RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:43.565674 I  TVRec(1): HandleTuning Request:
 Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
 2012-07-30 21:04:43.565685 I  TVRec(1): TeardownSignalMonitor() -- begin
 2012-07-30 21:04:43.565953 I  IPTVFeed: RemoveListener(0x10783ee38) --
 begin
 2012-07-30 21:04:43.566027 I  FbFeedLive:RemoveListener(0x10783ee38) --
 begin
 2012-07-30 21:04:43.566035 I  FbFeedLive:RemoveListener(0x10783ee38) --
 end 2
 2012-07-30 21:04:43.566040 I  IPTVFeed: RemoveListener(0x10783ee38) -- end
 (ok, removed)
 2012-07-30 21:04:43.566044 D  IPTVSM()::Stop: begin
 2012-07-30 21:04:43.566048 I  IPTVFeed: RemoveListener(0x10783ee38) --
 begin
 2012-07-30 21:04:43.566058 E  IPTVFeed: RemoveListener(0x10783ee38) -- end
 (not found)
 2012-07-30 21:04:43.566064 D  SM()::Stop: begin
 2012-07-30 21:04:43.651711 I  HLSBuffer: reloading HLS live meta playlist
 2012-07-30 21:04:43.809827 D  SM()::Stop: end
 2012-07-30 21:04:43.809838 I  IPTVFeed: Stop() -- begin
 2012-07-30 21:04:43.809841 I  IPTVHLS: Stop() -- begin
 2012-07-30 21:04:44.657432 I  HLSBuffer: Live Playlist HLS protocol
 version: 3
 2012-07-30 21:04:44.657445 D  HLSBuffer: ParseM3U8: #EXTM3U
 2012-07-30 21:04:44.657450 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
 2012-07-30 21:04:44.657455 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
 2012-07-30 21:04:44.657459 D  HLSBuffer: ParseM3U8:
 #EXT-X-TARGETDURATION:11
 2012-07-30 21:04:44.657463 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-
 SEQUENCE:209
 2012-07-30 21:04:44.657468 D  HLSBuffer: ParseM3U8: #EXTINF:9,
 2012-07-30 21:04:44.657476 D  HLSBuffer: ParseM3U8:
 media_209.ts?wowzasessionid=2103399960
 2012-07-30 21:04:44.657505 D  HLSBuffer: ParseM3U8: #EXTINF:11,
 2012-07-30 21:04:44.657511 D  HLSBuffer: ParseM3U8:
 media_210.ts?wowzasessionid=2103399960
 2012-07-30 21:04:44.657528 D  HLSBuffer: ParseM3U8: #EXTINF:9,
 2012-07-30 21:04:44.657534 D  HLSBuffer: ParseM3U8:
 media_211.ts?wowzasessionid=2103399960
 2012-07-30 21:04:44.657609 I  HLSBuffer: updated hls stream (program-id=1,
 bitrate=409200) has 3 segments
 2012-07-30 21:04:45.665939 D  HLSBuffer: downloaded segment 2 [id:210]
 took 2115ms for 496696 bytes: bandwidth:229.287kiB/s
 2012-07-30 21:04:45.665973 D  HLSBuffer: download completed, 1 segments
 ahead
 2012-07-30 21:04:45.665977 I  HLSBuffer: - segment 211 appended
 2012-07-30 21:04:45.665981 D  HLSBuffer: candidate stream 0 bitrate
 1627592 >= 409200
 2012-07-30 21:04:45.665994 D  HLSBuffer: started download of segment 3
 [211/212] using stream 0
 2012-07-30 21:04:45.666101 D  HLSBuffer: requesting interrupt
 2012-07-30 21:04:45.666119 D  HLSBuffer: interrupted
 2012-07-30 21:04:45.666127 I  IPTVFeed: Run() -- end
 2012-07-30 21:04:45.666130 I  IPTVHLS: Stop() -- end
 2012-07-30 21:04:45.666134 I  IPTVFeed: RemoveListener(0x10783ee38) --
 begin
 2012-07-30 21:04:45.666135 I  IPTVFeed: Stop() -- end
 2012-07-30 21:04:45.666138 E  IPTVFeed: RemoveListener(0x10783ee38) -- end
 (not found)
 2012-07-30 21:04:45.666143 D  IPTVSM()::Run: end
 2012-07-30 21:04:45.666192 D  HLSBuffer: PlayListWorker refreshing in 5s
 2012-07-30 21:04:45.666214 D  IPTVSM()::Stop: end
 2012-07-30 21:04:45.666219 D  IPTVSM()::~IPTVSignalMonitor: Didn't get a
 lock earlier, closing feed
 2012-07-30 21:04:45.666224 I  IPTVFeed: Close() -- begin
 2012-07-30 21:04:45.666227 I  IPTVHLS: Close() -- begin
 2012-07-30 21:04:45.666241 I  IPTVHLS: Stop() -- begin
 2012-07-30 21:04:45.666251 D  HLSBuffer: requesting interrupt
 2012-07-30 21:04:45.666253 I  IPTVHLS: Stop() -- end
 2012-07-30 21:04:45.666328 I  HLSBuffer: reloading HLS live meta playlist
 2012-07-30 21:04:46.670022 I  HLSBuffer: Live Playlist HLS protocol
 version: 3
 2012-07-30 21:04:46.670032 D  HLSBuffer: ParseM3U8: #EXTM3U
 2012-07-30 21:04:46.670037 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
 2012-07-30 21:04:46.670050 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
 2012-07-30 21:04:46.670054 D  HLSBuffer: ParseM3U8:
 #EXT-X-TARGETDURATION:11
 2012-07-30 21:04:46.670058 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-
 SEQUENCE:209
 2012-07-30 21:04:46.670062 D  HLSBuffer: ParseM3U8: #EXTINF:9,
 2012-07-30 21:04:46.670070 D  HLSBuffer: ParseM3U8:
 media_209.ts?wowzasessionid=2103399960
 2012-07-30 21:04:46.670096 D  HLSBuffer: ParseM3U8: #EXTINF:11,
 2012-07-30 21:04:46.670102 D  HLSBuffer: ParseM3U8:
 media_210.ts?wowzasessionid=2103399960
 2012-07-30 21:04:46.670119 D  HLSBuffer: ParseM3U8: #EXTINF:9,
 2012-07-30 21:04:46.670124 D  HLSBuffer: ParseM3U8:
 media_211.ts?wowzasessionid=2103399960
 2012-07-30 21:04:46.670150 I  HLSBuffer: updated hls stream (program-id=1,
 bitrate=409200) has 3 segments
 2012-07-30 21:04:47.078009 D  HLSBuffer: downloaded segment 3 [id:211]
 took 1411ms for 378820 bytes: bandwidth:262.002kiB/s
 2012-07-30 21:04:47.078020 D  HLSBuffer: download completed, 1 segments
 ahead
 2012-07-30 21:04:47.078029 D  HLSBuffer: candidate stream 0 bitrate
 1757274 >= 409200
 2012-07-30 21:04:47.078121 C  MThread prolog was never run!
 2012-07-30 21:04:47.078125 C  MThread epilog was never run!
 2012-07-30 21:04:47.078226 C  MThread prolog was never run!
 2012-07-30 21:04:47.078228 C  MThread epilog was never run!
 2012-07-30 21:04:47.078475 I  IPTVHLS: Close() -- end
 2012-07-30 21:04:47.078478 I  IPTVFeed: Close() -- end
 2012-07-30 21:04:47.078581 D  SM()::Stop: begin
 2012-07-30 21:04:47.078585 D  SM()::Stop: end
 2012-07-30 21:04:47.078635 I  TVRec(1): TeardownSignalMonitor() -- end
 2012-07-30 21:04:47.078644 I  TVRec(1): ClearFlags(SignalMonitorRunning,)
 ->
 RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:47.079130 I  TVRec(1): ClearFlags(WaitingForSignal,) ->
 RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
 2012-07-30 21:04:47.079752 I  TVRec(1):
 FinishedRecording(1301_2012-07-30T11:04:35Z)
                         title:
                         in recgroup: LiveTV status: Unknown:Recorder
 Failed is_dummy finished_now
 2012-07-30 21:04:47.080091 I  Chain: Updated endtime for
 '1301_20120730110435' to 20120730110447
 2012-07-30 21:04:47.080429 I  TVRec(1): ClearFlags(DummyRecorderRunning,)
 -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
 2012-07-30 21:04:47.080709 I  TVRec(1): ClearFlags(RecorderRunning,) ->
 RunMainLoop,NeedToStartRecorder,RingBufferReady,
 2012-07-30 21:04:47.080941 I  TVRec(1):
 FinishedRecording(1301_2012-07-30T11:04:35Z)
                         title:
                         in recgroup: LiveTV status: Recorder
 Failed:Recorder Failed not_dummy already_finished
 2012-07-30 21:04:47.081115 I  TVRec(1): ClearFlags(RecorderRunning,) ->
 RunMainLoop,NeedToStartRecorder,RingBufferReady,
 2012-07-30 21:04:47.081121 I  TVRec(1): Tearing down RingBuffer
 2012-07-30 21:04:47.081286 I  TVRec(1): ClearFlags(PENDINGACTIONS,) ->
 RunMainLoop,RingBufferReady,
 2012-07-30 21:04:47.081510 W  MainServer: Unknown socket closing
 MythSocket(0x1070310d0)
 2012-07-30 21:04:47.081533 E  MythSocket(1070310d0:-1): writeStringList:
 Error, No data written on writeBlock (1 errors)
                         starts with: 2       OK
 }}}

 Here is the frontend log:
 {{{
 2012-07-30 21:04:33.885720 I  Starting mythlogserver
 2012-07-30 21:04:33.885879 D  Launching: /Users/jyavenard/Work/mythtv
 /.osx-packager/build/bin/mythlogserver --daemon  --verbose
 general,audio,playback,libav,system --loglevel debug --nodblog
 2012-07-30 21:04:33.888087 I  Managed child (PID: 74637) has started! *
 command=/Users/jyavenard/Work/mythtv/.osx-packager/build/bin/mythlogserver
 --daemon  --verbose general,audio,playback,libav,system --loglevel debug
 --nodblog, timeout=0
 2012-07-30 21:04:34.119688 I  Managed child (PID: 74637) has exited!
 command=/Users/jyavenard/Work/mythtv/.osx-packager/build/bin/mythlogserver
 --daemon  --verbose general,audio,playback,libav,system --loglevel debug
 --nodblog, status=0, result=0
 2012-07-30 21:04:35.761594 D
 SendReceiveStringList(GET_FREE_RECORDER_COUNT) called from UI thread
 2012-07-30 21:04:35.763853 I  TV: Creating TV object
 2012-07-30 21:04:35.781838 I  TV: Finished creating TV object
 2012-07-30 21:04:35.781868 I  TV: StartTV() -- begin
 2012-07-30 21:04:35.782004 N  Resuming idle timer
 2012-07-30 21:04:35.782248 N  Suspending idle timer
 2012-07-30 21:04:35.782297 I  TV: Init -- begin
 2012-07-30 21:04:35.786941 I  TV: Created TvPlayWindow.
 2012-07-30 21:04:35.795805 I  TV: Init -- end
 2012-07-30 21:04:35.795913 D
 SendReceiveStringList(GET_FREE_RECORDER_COUNT) called from UI thread
 2012-07-30 21:04:35.796782 I  TV: tv->LiveTV() -- begin
 2012-07-30 21:04:35.796853 D
 SendReceiveStringList(GET_NEXT_FREE_RECORDER,-1) called from UI thread
 2012-07-30 21:04:35.799111 I  TV: HandleStateChange(0) -- begin
 2012-07-30 21:04:35.799249 I  TV: Attempting to change from None to
 WatchingLiveTV
 2012-07-30 21:04:35.799339 I  MythCoreContext: Connecting to backend
 server: 192.168.10.10:6543 (try 1 of 1)
 2012-07-30 21:04:35.800570 N  TV: Spawning LiveTV Recorder -- begin
 2012-07-30 21:04:42.800645 E  MythSocket(1085ed410:96): readStringList:
 Error, timed out after 7000 ms.
 2012-07-30 21:04:42.800721 E  RemoteEncoder::SendReceiveStringList(): No
 response.
 2012-07-30 21:04:42.800754 N  TV: Spawning LiveTV Recorder -- end
 2012-07-30 21:04:42.801831 I  LiveTVChain(live-
 jyaimac-2012-07-30T11:04:35Z): ReloadAll(): Added new recording
 2012-07-30 21:04:42.801944 I  LiveTVChain(live-
 jyaimac-2012-07-30T11:04:35Z): LiveTVChain has 1 entries
 *  DUMMY: 1301 (11:04:35 to 11:30:00)

 2012-07-30 21:04:42.808516 I  TV:
 playbackURL(/DATA/Users/jyavenard/Downloads/mythtv/1301_20120730110435.mpg)
 cardtype(DUMMY)
 2012-07-30 21:04:42.808761 I  MythCoreContext: Connecting to backend
 server: 192.168.10.10:6543 (try 1 of 1)
 2012-07-30 21:05:03.914346 I  Starting mythlogserver
 2012-07-30 21:05:03.914487 D  Launching: /Users/jyavenard/Work/mythtv
 /.osx-packager/build/bin/mythlogserver --daemon  --verbose
 general,audio,playback,libav,system --loglevel debug --nodblog
 2012-07-30 21:05:03.917733 I  Managed child (PID: 74645) has started! *
 command=/Users/jyavenard/Work/mythtv/.osx-packager/build/bin/mythlogserver
 --daemon  --verbose general,audio,playback,libav,system --loglevel debug
 --nodblog, timeout=0
 2012-07-30 21:05:04.145702 I  Managed child (PID: 74645) has exited!
 command=/Users/jyavenard/Work/mythtv/.osx-packager/build/bin/mythlogserver
 --daemon  --verbose general,audio,playback,libav,system --loglevel debug
 --nodblog, status=0, result=0
 2012-07-30 21:05:22.814345 E  TV: StartRecorder() -- timed out waiting for
 recorder to start
 2012-07-30 21:05:22.814446 E  TV: LiveTV not successfully started
 2012-07-30 21:05:22.817611 I  TV: DrawUnusedRects() -- begin
 2012-07-30 21:05:22.817718 I  TV: DrawUnusedRects() -- end
 2012-07-30 21:05:22.818217 I  TV: Main UI disabled.
 2012-07-30 21:05:22.818326 I  TV: HandleStateChange(0) -- end
 2012-07-30 21:05:22.818526 D  SendReceiveStringList(MESSAGE,SYSTEM_EVENT
 LIVETV_STARTED SENDER jyaimac) called from UI thread
 2012-07-30 21:05:22.819318 I  TV: tv->LiveTV() -- end
 2012-07-30 21:05:22.819436 I  TV: Entering main playback loop.
 2012-07-30 21:05:22.855834 I  TV: Exiting main playback loop.
 2012-07-30 21:05:22.855933 I  TV: StartTV -- process events 2 begin
 2012-07-30 21:05:22.856188 I  TV: StartTV -- process events 2 end
 2012-07-30 21:05:22.856288 I  TV::~TV() -- begin
 2012-07-30 21:05:22.868682 I  TV::~TV() -- lock
 2012-07-30 21:05:22.872299 I  TV::~TV() -- end
 2012-07-30 21:05:22.872928 D  SendReceiveStringList(MESSAGE,SYSTEM_EVENT
 PLAY_STOPPED SENDER jyaimac) called from UI thread
 2012-07-30 21:05:22.873713 N  Resuming idle timer
 2012-07-30 21:05:22.873865 I  TV: StartTV -- end
 }}}

 I got playback to start once.

 log attached when it did start (mythbackend crashed after changing the
 channel as HLSRingBuffer::Read() returned -1 due to a stream error that
 wasn't handled by IPTVFeeder::run(), but I fixed that now.

-- 
Ticket URL: <http://code.mythtv.org/trac/ticket/10934#comment:2>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center


More information about the mythtv-commits mailing list