Opened 13 years ago

Closed 13 years ago

Last modified 13 years ago

#10934 closed Bug Report - General (fixed)

Can't enter liveTV with IPTV

Reported by: JYA Owned by: jya
Priority: blocker Milestone: 0.26
Component: MythTV - General Version: Master Head
Severity: medium Keywords:
Cc: Ticket locked: no

Description

Used to work..

Now it always fail to enter LiveTV using the HLS recorder.

Recording HLS channels work just fine.

Timeout for capture card was set to 30s, it takes usually less than 10s to watch that same URL using mythavtest.

From time to time it works, very rarely. You can see in the log that it got a locks, signal monitor is closed and then it stops everything.

2012-07-24 12:05:33.406985 I  MainServer::ANN Playback
2012-07-24 12:05:33.406991 I  adding: jyamba as a client (events: 0)
2012-07-24 12:05:33.427861 I  MainServer::HandleAnnounce FileTransfer
2012-07-24 12:05:33.427867 I  adding: jyamba as a remote file transfer
2012-07-24 12:05:36.588791 I  Getting next free recorder after : -1
2012-07-24 12:05:36.588894 I  Checking card 1. Best card so far -1
2012-07-24 12:05:36.589376 I  Best card is 1
2012-07-24 12:05:36.643602 I  MainServer::ANN Playback
2012-07-24 12:05:36.643608 I  adding: jyamba as a client (events: 0)
2012-07-24 12:05:36.722958 I  TVRec(1): Found channel (300) on current card(1).
2012-07-24 12:05:36.738567 I  TVRec(1): Changing from None to WatchingLiveTV
2012-07-24 12:05:36.738596 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
2012-07-24 12:05:36.738652 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
2012-07-24 12:05:36.738686 I  ChannelBase(1): Looking for startchannel '300' on input 'MPEG2TS'
2012-07-24 12:05:36.740538 I  ChannelBase(1): Found startchannel '300' on input 'MPEG2TS'
2012-07-24 12:05:36.740553 I  TVRec(1): HW Tuner: 1->1
2012-07-24 12:05:36.740561 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,
2012-07-24 12:05:36.740604 I  TVRec(1): No recorder yet, calling TuningFrequency
2012-07-24 12:05:36.740874 I  IPTVChan(1): Open() -- begin
2012-07-24 12:05:36.740880 I  IPTVChan(1): Open() -- locked
2012-07-24 12:05:36.741977 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-24 12:05:36.741990 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-24 12:05:36.742016 I  IPTVChan(1): Open() -- end
2012-07-24 12:05:36.742022 D  ChannelBase(1): SwitchToInput(MPEG2TS,300)
2012-07-24 12:05:36.742936 I  IPTVChan(1): SetChannelByString(300) -- begin
2012-07-24 12:05:36.742941 I  IPTVChan(1): SetChannelByString() -- locked
2012-07-24 12:05:36.743739 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-24 12:05:36.743744 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-24 12:05:36.743914 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al Jazeera (English)) Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
2012-07-24 12:05:36.743938 I  IPTVChan(1): SetChannelByString(300) = 300 -- end
2012-07-24 12:05:36.743970 I  TVRec(1): CreateLiveTVRingBuffer(300)
2012-07-24 12:05:36.744255 I  TVRec(1): GetProgramRingBufferForLiveTV()
2012-07-24 12:05:36.748376 N  AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
2012-07-24 12:05:36.757905 I  TVRec(1): StartedRecording(1300_2012-07-24T02:05:36Z) fn(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020536.mpg)
2012-07-24 12:05:36.760600 I  Using profile 'Default' to record
2012-07-24 12:05:36.762822 I  Chain: Appended@0 '1300_20120724020536'
2012-07-24 12:05:36.763642 I  TVRec(1): Starting Signal Monitor
2012-07-24 12:05:36.763652 I  TVRec(1): SetupSignalMonitor(1, 1)
2012-07-24 12:05:36.763740 I  IPTVChan(1): Open() -- begin
2012-07-24 12:05:36.763744 I  IPTVChan(1): Open() -- locked
2012-07-24 12:05:36.764874 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-24 12:05:36.764881 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-24 12:05:36.764900 I  IPTVChan(1): Open() -- end
2012-07-24 12:05:36.765110 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-24 12:05:36.765114 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-24 12:05:36.765294 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al Jazeera (English)) Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
2012-07-24 12:05:36.765332 I  IPTVFeed: Open() -- begin
2012-07-24 12:05:36.765338 I  IPTVFeed: Init() -- begin
2012-07-24 12:05:37.744024 I  IPTVFeed: Init() -- adding listeners
2012-07-24 12:05:37.744093 I  IPTVFeed: Init() -- end 1
2012-07-24 12:05:37.744100 I  IPTVHLS: Open(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) -- begin
[Switching to process 860 thread 0x5107]
2012-07-24 12:05:39.846373 I  IPTVHLS: Open() -- end
2012-07-24 12:05:39.846380 I  IPTVFeed: Open() -- end
2012-07-24 12:05:39.846389 I  TVRec(1): Signal monitor successfully created
2012-07-24 12:05:39.846394 I  TVRec(1): Setting up table monitoring.
2012-07-24 12:05:39.847991 I  Using profile 'Live TV' to record
2012-07-24 12:05:39.848510 I  TVRec(1): MPEG program number: 1
2012-07-24 12:05:39.849052 I  DTVSM()::SetProgramNumber(1): 
2012-07-24 12:05:39.849095 D  SM()::RemoveFlags: Seen(PMT,Crypt,) Match(PMT,Crypt,) Wait()
2012-07-24 12:05:39.849305 D  SM()::AddFlags: Seen() Match() Wait(PMT,)
2012-07-24 12:05:39.849326 D  SM()::AddFlags: Seen() Match() Wait(PAT,PMT,Pos,)
2012-07-24 12:05:39.849333 I  TVRec(1): Successfully set up MPEG table monitoring.
2012-07-24 12:05:39.849504 D  SM()::Start: begin
2012-07-24 12:05:39.849639 D  SM()::Start: end
2012-07-24 12:05:39.849651 I  TVRec(1): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,
2012-07-24 12:05:39.849660 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,
2012-07-24 12:05:39.849667 I  TVRec(1): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,
2012-07-24 12:05:39.849681 I  TVRec(1): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,
2012-07-24 12:05:39.849685 I  DummyDTVRecorder -- started
2012-07-24 12:05:39.849693 I  TVRec(1): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:39.849701 I  TVRec(1): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:39.849703 D  IPTVSM()::UpdateValues: Waiting for table monitor to start
2012-07-24 12:05:39.849709 I  TVRec(1): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:39.849762 D  IPTVSM()::Run: begin
2012-07-24 12:05:39.849778 I  IPTVFeed: AddListener(0x10901fe38) -- begin
2012-07-24 12:05:39.849851 I  TVRec(1): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:39.849970 I  FbFeedLive:AddListener(0x10901fe38) -- begin
2012-07-24 12:05:39.849975 I  FbFeedLive:RemoveListener(0x10901fe38) -- begin
2012-07-24 12:05:39.849987 I  FbFeedLive:RemoveListener(0x10901fe38) -- end 1
2012-07-24 12:05:39.849994 I  FbFeedLive:AddListener(0x10901fe38) -- end
2012-07-24 12:05:39.849998 I  IPTVFeed: AddListener(0x10901fe38) -- end 1
2012-07-24 12:05:39.850001 I  IPTVFeed: Run() -- begin
2012-07-24 12:05:39.851470 D  SM()::AddFlags: Seen(PAT,) Match() Wait()
2012-07-24 12:05:39.851477 D  SM()::AddFlags: Seen() Match(PAT,) Wait()
2012-07-24 12:05:39.851570 I  CreatePATSingleProgram()
2012-07-24 12:05:39.851572 I  PAT in input stream
2012-07-24 12:05:39.851613 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-24 12:05:39.851618 I  desired_program(1) pid(0xfff)
2012-07-24 12:05:39.851768 I  pmt_pid(0xfff)
2012-07-24 12:05:39.851771 I  PAT for output stream
2012-07-24 12:05:39.851785 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-24 12:05:39.852082 D  SM()::AddFlags: Seen(PMT,) Match() Wait()
2012-07-24 12:05:39.852469 D  SM()::AddFlags: Seen() Match(PMT,) Wait()
2012-07-24 12:05:39.852473 I  CreatePMTSingleProgram()
2012-07-24 12:05:39.852475 I  PMT in input stream
2012-07-24 12:05:39.852547 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-24 12:05:39.853099 I  PMT for output stream
2012-07-24 12:05:39.853131 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-24 12:05:39.855376 D  IPTVSM()::UpdateValues: Table monitor started
2012-07-24 12:05:40.106214 I  TVRec(1): Got good signal
2012-07-24 12:05:40.106240 D  TVRec(1): SetRecordingStatus(Unknown->Recording) on line 3836
2012-07-24 12:05:40.106280 I  TVRec(1): TeardownSignalMonitor() -- begin
2012-07-24 12:05:40.106580 I  IPTVFeed: RemoveListener(0x10901fe38) -- begin
2012-07-24 12:05:40.106637 I  FbFeedLive:RemoveListener(0x10901fe38) -- begin
2012-07-24 12:05:40.106642 I  FbFeedLive:RemoveListener(0x10901fe38) -- end 2
2012-07-24 12:05:40.106654 I  IPTVFeed: RemoveListener(0x10901fe38) -- end (ok, removed)
2012-07-24 12:05:40.106658 D  IPTVSM()::Stop: begin
2012-07-24 12:05:40.106662 I  IPTVFeed: RemoveListener(0x10901fe38) -- begin
2012-07-24 12:05:40.106666 E  IPTVFeed: RemoveListener(0x10901fe38) -- end (not found)
2012-07-24 12:05:40.106670 D  SM()::Stop: begin
2012-07-24 12:05:40.357486 D  SM()::Stop: end
2012-07-24 12:05:40.357504 I  IPTVFeed: Stop() -- begin
2012-07-24 12:05:40.357507 I  IPTVHLS: Stop() -- begin
2012-07-24 12:05:41.761003 I  IPTVFeed: Run() -- end
2012-07-24 12:05:41.761010 I  IPTVHLS: Stop() -- end
2012-07-24 12:05:41.761016 I  IPTVFeed: RemoveListener(0x10901fe38) -- begin
2012-07-24 12:05:41.761018 I  IPTVFeed: Stop() -- end
2012-07-24 12:05:41.761022 E  IPTVFeed: RemoveListener(0x10901fe38) -- end (not found)
2012-07-24 12:05:41.761026 D  IPTVSM()::Run: end
2012-07-24 12:05:41.761099 D  IPTVSM()::Stop: end
2012-07-24 12:05:41.761213 D  SM()::Stop: begin
2012-07-24 12:05:41.761218 D  SM()::Stop: end
2012-07-24 12:05:41.761270 I  TVRec(1): TeardownSignalMonitor() -- end
2012-07-24 12:05:41.761280 I  TVRec(1): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:41.761289 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:05:41.761711 I  TVRec(1): Starting Recorder
2012-07-24 12:05:41.762246 I  TVRec(1): FinishedRecording(1300_2012-07-24T02:05:36Z)
			title: 
			in recgroup: LiveTV status: Recording:Recorded is_dummy finished_now
2012-07-24 12:05:41.762558 I  Chain: Updated endtime for '1300_20120724020536' to 20120724020541
2012-07-24 12:05:41.762948 I  TVRec(1): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady,
2012-07-24 12:05:41.764760 I  Using profile 'Live TV' to record
2012-07-24 12:05:41.764778 I  TVRec(1): SwitchLiveTVRingBuffer(discont 1, set_next_rec 0) curRec(1300_2012-07-24T02:05:36Z) curRec.size(0)
2012-07-24 12:05:41.765193 I  TVRec(1): GetProgramRingBufferForLiveTV()
2012-07-24 12:05:41.769052 N  AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
2012-07-24 12:05:41.773664 I  TVRec(1): StartedRecording(1300_2012-07-24T02:05:41Z) fn(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020541.mpg)
2012-07-24 12:05:41.775712 I  Using profile 'Default' to record
2012-07-24 12:05:41.778091 I  Chain: Appended@1 '1300_20120724020541'
2012-07-24 12:05:41.778623 I  DTVRec(1): ResetForNewFile(void)
2012-07-24 12:05:41.778641 I  IPTVFeed: AddListener(0x10b809d08) -- begin
2012-07-24 12:05:41.778647 I  FbFeedLive:AddListener(0x10b809d08) -- begin
2012-07-24 12:05:41.778653 I  FbFeedLive:RemoveListener(0x10b809d08) -- begin
2012-07-24 12:05:41.778660 I  FbFeedLive:RemoveListener(0x10b809d08) -- end 1
2012-07-24 12:05:41.778665 I  FbFeedLive:AddListener(0x10b809d08) -- end
2012-07-24 12:05:41.778671 I  IPTVFeed: AddListener(0x10b809d08) -- end 1
2012-07-24 12:05:41.778683 W  RecBase(1:): SetOption(mrl,http://192.168.10.10/~jyavenard/playlist.m3u): Option not recognized
2012-07-24 12:05:41.778692 I  RecBase(1:): SetRingBuffer(0x10a06d990) '/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020541.mpg'
2012-07-24 12:05:41.778923 I  RecBase(1:): SetRecording(0x10994ab20) title()
2012-07-24 12:05:41.779374 I  IPTVRec: run() -- begin
2012-07-24 12:05:41.779378 I  IPTVRec: Open() -- begin
2012-07-24 12:05:41.779381 I  IPTVFeed: IsOpen() -- begin
2012-07-24 12:05:41.779386 I  IPTVFeed: IsOpen() -- end
2012-07-24 12:05:41.779390 I  IPTVFeed: Run() -- begin
2012-07-24 12:05:41.779394 I  TVRec(1): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,NeedToStartRecorder,RingBufferReady,
2012-07-24 12:05:41.780717 I  DTVRec(1): FindH264Keyframes: timescale: 50, tick: 1, framerate: 25000
2012-07-24 12:05:41.784664 I  TVRec(1): SetFlags(RecorderRunning,RingBufferReady,) -> FrontendReady,RunMainLoop,CancelNextRecording,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2012-07-24 12:05:41.784688 I  TVRec(1): ClearFlags(NeedToStartRecorder,) -> FrontendReady,RunMainLoop,CancelNextRecording,RecorderRunning,RingBufferReady,
2012-07-24 12:05:42.081057 I  MainServer::ANN Playback
2012-07-24 12:05:42.081064 I  adding: jyamba as a client (events: 0)
2012-07-24 12:05:42.089192 I  MainServer::HandleAnnounce FileTransfer
2012-07-24 12:05:42.089196 I  adding: jyamba as a remote file transfer
2012-07-24 12:05:43.171173 W  RingBuf(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020541.mpg): Taking too long to be allowed to read..
2012-07-24 12:05:44.172237 W  RingBuf(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020541.mpg): Taking too long to be allowed to read..
2012-07-24 12:05:44.546786 W  RingBuf(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020541.mpg): Taking too long to be allowed to read..
[Switching to process 860 thread 0x707]
2012-07-24 12:05:47.469796 I  Starting mythlogserver
2012-07-24 12:05:52.539254 I  JobQueue: Metadata Lookup Starting for  recorded from channel 1300 at 2012-07-24T02:05:36Z
2012-07-24 12:05:52.963734 E  JobQueue: Metadata Lookup Errored:  recorded from channel 1300 at 2012-07-24T02:05:36Z (Failed with exit status 128)
2012-07-24 12:05:53.185228 D  DTVRec(1): Updating timeOfLatestData elapsed(11405) interval(2000)
2012-07-24 12:05:53.186570 D  DTVRec(1): Updating timeOfLatestData elapsed(1) interval(1600)
2012-07-24 12:05:58.285324 I  TVRec(1): StopLiveTV(void) curRec: 0x10994ab20 pseudoRec: 0x0
2012-07-24 12:05:58.296866 I  TVRec(1): Changing from WatchingLiveTV to None
2012-07-24 12:05:58.296885 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RecorderRunning,RingBufferReady,
2012-07-24 12:05:58.296897 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
2012-07-24 12:05:58.296904 I  IPTVFeed: Stop() -- begin
2012-07-24 12:05:58.296907 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:01.771077 N  AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2012-07-24 12:06:01.773379 N  Expiring 0 MB for 1300 at 2012-07-24T02:00:12Z => 
2012-07-24 12:06:01.773414 N  Expiring 0 MB for 1300 at 2012-07-24T02:00:18Z => 
2012-07-24 12:06:01.773439 N  Expiring 0 MB for 1300 at 2012-07-24T02:00:49Z => 
2012-07-24 12:06:02.990961 I  IPTVFeed: Run() -- end
2012-07-24 12:06:02.990963 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:02.990973 I  IPTVFeed: Stop() -- end
2012-07-24 12:06:02.990978 I  IPTVRec: Close() -- begin
2012-07-24 12:06:02.990981 I  IPTVFeed: Stop() -- begin
2012-07-24 12:06:02.990983 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:02.990985 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:02.990987 I  IPTVFeed: Stop() -- end
2012-07-24 12:06:02.990990 I  IPTVFeed: Close() -- begin
2012-07-24 12:06:02.990992 I  IPTVHLS: Close() -- begin
2012-07-24 12:06:02.990994 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:02.990996 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:03.794910 C  MThread prolog was never run!
2012-07-24 12:06:03.794917 C  MThread epilog was never run!
2012-07-24 12:06:05.207267 C  MThread prolog was never run!
2012-07-24 12:06:05.207275 C  MThread epilog was never run!
2012-07-24 12:06:05.207546 I  IPTVHLS: Close() -- end
2012-07-24 12:06:05.207550 I  IPTVFeed: Close() -- end
2012-07-24 12:06:05.207553 I  IPTVRec: Close() -- end
2012-07-24 12:06:05.260105 I  IPTVRec: run() -- end
2012-07-24 12:06:05.260203 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.260779 I  IPTVFeed: Stop() -- begin
2012-07-24 12:06:05.260783 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:05.260786 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:05.260788 I  IPTVFeed: Stop() -- end
2012-07-24 12:06:05.260793 I  IPTVFeed: RemoveListener(0x10b809d08) -- begin
2012-07-24 12:06:05.260800 I  FbFeedLive:RemoveListener(0x10b809d08) -- begin
2012-07-24 12:06:05.260804 I  FbFeedLive:RemoveListener(0x10b809d08) -- end 2
2012-07-24 12:06:05.260808 I  IPTVFeed: RemoveListener(0x10b809d08) -- end (ok, removed)
2012-07-24 12:06:05.261413 I  RecBase(1:): SetRecording(0x0)
2012-07-24 12:06:05.262204 I  TVRec(1): FinishedRecording(1300_2012-07-24T02:05:41Z) damaged recq:<RecordingQuality overall_score="0" key="1300_2012-07-24T02:05:41Z">
    <Gap start="2012-07-24T02:05:53Z" end="2012-07-24T02:30:00Z" duration="1446" />
</RecordingQuality>

2012-07-24 12:06:05.262293 I  TVRec(1): FinishedRecording(1300_2012-07-24T02:05:41Z)
			title: 
			in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy finished_now
2012-07-24 12:06:05.262587 I  Chain: Updated endtime for '1300_20120724020541' to 20120724020605
2012-07-24 12:06:05.263177 I  SaveVideoProperties(0x38, 0x20)
2012-07-24 12:06:05.264289 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.264296 I  TVRec(1): Tearing down RingBuffer
2012-07-24 12:06:05.264387 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.294436 I  MainServer::ANN Playback
2012-07-24 12:06:05.294443 I  adding: jyamba as a client (events: 0)
2012-07-24 12:06:05.296295 I  TVRec(1): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.331829 I  TVRec(1): SetFlags(FrontendReady,) -> FrontendReady,RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.413509 I  Getting next free recorder after : -1
2012-07-24 12:06:05.413518 I  Checking card 1. Best card so far -1
2012-07-24 12:06:05.413958 I  Best card is 1
2012-07-24 12:06:05.454326 I  MainServer::ANN Playback
2012-07-24 12:06:05.454342 I  adding: jyamba as a client (events: 0)
2012-07-24 12:06:05.502378 I  TVRec(1): Found channel (300) on current card(1).
2012-07-24 12:06:05.516339 I  TVRec(1): Changing from None to WatchingLiveTV
2012-07-24 12:06:05.516366 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.516381 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
2012-07-24 12:06:05.516399 I  ChannelBase(1): Looking for startchannel '300' on input 'MPEG2TS'
2012-07-24 12:06:05.518310 I  ChannelBase(1): Found startchannel '300' on input 'MPEG2TS'
2012-07-24 12:06:05.518326 I  TVRec(1): HW Tuner: 1->1
2012-07-24 12:06:05.518335 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:05.518342 I  TVRec(1): No recorder yet, calling TuningFrequency
2012-07-24 12:06:05.518520 I  IPTVChan(1): Open() -- begin
2012-07-24 12:06:05.518525 I  IPTVChan(1): Open() -- locked
2012-07-24 12:06:05.519293 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-24 12:06:05.519300 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-24 12:06:05.519319 I  IPTVChan(1): Open() -- end
2012-07-24 12:06:05.519324 D  ChannelBase(1): SwitchToInput(MPEG2TS,300)
2012-07-24 12:06:05.520283 I  IPTVChan(1): SetChannelByString(300) -- begin
2012-07-24 12:06:05.520288 I  IPTVChan(1): SetChannelByString() -- locked
2012-07-24 12:06:05.521199 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-24 12:06:05.521204 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-24 12:06:05.521374 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al Jazeera (English)) Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
2012-07-24 12:06:05.521397 I  IPTVChan(1): SetChannelByString(300) = 300 -- end
2012-07-24 12:06:05.521403 I  TVRec(1): CreateLiveTVRingBuffer(300)
2012-07-24 12:06:05.521668 I  TVRec(1): GetProgramRingBufferForLiveTV()
2012-07-24 12:06:05.524369 N  AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
2012-07-24 12:06:05.528696 I  TVRec(1): StartedRecording(1300_2012-07-24T02:06:05Z) fn(/DATA/Users/jyavenard/Downloads/mythtv/1300_20120724020605.mpg)
2012-07-24 12:06:05.530159 I  Using profile 'Default' to record
2012-07-24 12:06:05.531601 I  Chain: Appended@0 '1300_20120724020605'
2012-07-24 12:06:05.532361 I  TVRec(1): Starting Signal Monitor
2012-07-24 12:06:05.532367 I  TVRec(1): SetupSignalMonitor(1, 1)
2012-07-24 12:06:05.532372 I  IPTVChan(1): Open() -- begin
2012-07-24 12:06:05.532376 I  IPTVChan(1): Open() -- locked
2012-07-24 12:06:05.533724 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-24 12:06:05.533732 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-24 12:06:05.533758 I  IPTVChan(1): Open() -- end
2012-07-24 12:06:05.533801 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-24 12:06:05.533805 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-24 12:06:05.534142 D  IPTVChan(1): Found: IPTVChannelInfo: Name(Al Jazeera (English)) Url(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) xmltvid(
2012-07-24 12:06:05.534180 I  IPTVFeed: Open() -- begin
2012-07-24 12:06:05.534186 I  IPTVFeed: Init() -- begin
2012-07-24 12:06:06.822849 I  IPTVFeed: Init() -- end 0
2012-07-24 12:06:06.822858 I  IPTVHLS: Open(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) -- begin
2012-07-24 12:06:08.851297 I  IPTVHLS: Open() -- end
2012-07-24 12:06:08.851304 I  IPTVFeed: Open() -- end
2012-07-24 12:06:08.851314 I  TVRec(1): Signal monitor successfully created
2012-07-24 12:06:08.851319 I  TVRec(1): Setting up table monitoring.
2012-07-24 12:06:08.852858 I  Using profile 'Live TV' to record
2012-07-24 12:06:08.852878 I  TVRec(1): MPEG program number: 1
2012-07-24 12:06:08.852895 I  DTVSM()::SetProgramNumber(1): 
2012-07-24 12:06:08.852904 D  SM()::RemoveFlags: Seen(PMT,Crypt,) Match(PMT,Crypt,) Wait()
2012-07-24 12:06:08.852917 D  SM()::AddFlags: Seen() Match() Wait(PMT,)
2012-07-24 12:06:08.852924 D  SM()::AddFlags: Seen() Match() Wait(PAT,PMT,Pos,)
2012-07-24 12:06:08.852928 I  TVRec(1): Successfully set up MPEG table monitoring.
2012-07-24 12:06:08.852942 D  SM()::Start: begin
2012-07-24 12:06:08.853018 D  SM()::Start: end
2012-07-24 12:06:08.853028 I  TVRec(1): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2012-07-24 12:06:08.853036 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2012-07-24 12:06:08.853040 D  IPTVSM()::UpdateValues: Waiting for table monitor to start
2012-07-24 12:06:08.853043 I  TVRec(1): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2012-07-24 12:06:08.853050 I  TVRec(1): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.853062 I  DummyDTVRecorder -- started
2012-07-24 12:06:08.853066 D  IPTVSM()::Run: begin
2012-07-24 12:06:08.853069 I  TVRec(1): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.853073 I  IPTVFeed: AddListener(0x108818e38) -- begin
2012-07-24 12:06:08.853077 I  TVRec(1): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.853079 I  FbFeedLive:AddListener(0x108818e38) -- begin
2012-07-24 12:06:08.853083 I  FbFeedLive:RemoveListener(0x108818e38) -- begin
2012-07-24 12:06:08.853087 I  FbFeedLive:RemoveListener(0x108818e38) -- end 1
2012-07-24 12:06:08.853087 I  TVRec(1): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.853090 I  FbFeedLive:AddListener(0x108818e38) -- end
2012-07-24 12:06:08.853093 I  IPTVFeed: AddListener(0x108818e38) -- end 1
2012-07-24 12:06:08.853096 I  IPTVFeed: Run() -- begin
2012-07-24 12:06:08.853131 I  TVRec(1): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.853164 D  SM()::AddFlags: Seen(PAT,) Match() Wait()
2012-07-24 12:06:08.853171 D  SM()::AddFlags: Seen() Match(PAT,) Wait()
2012-07-24 12:06:08.853178 I  CreatePATSingleProgram()
2012-07-24 12:06:08.853180 I  PAT in input stream
2012-07-24 12:06:08.853197 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-24 12:06:08.853202 I  desired_program(1) pid(0xfff)
2012-07-24 12:06:08.853213 I  pmt_pid(0xfff)
2012-07-24 12:06:08.853216 I  PAT for output stream
2012-07-24 12:06:08.853229 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-24 12:06:08.853255 D  SM()::AddFlags: Seen(PMT,) Match() Wait()
2012-07-24 12:06:08.853276 D  SM()::AddFlags: Seen() Match(PMT,) Wait()
2012-07-24 12:06:08.853279 I  CreatePMTSingleProgram()
2012-07-24 12:06:08.853281 I  PMT in input stream
2012-07-24 12:06:08.853316 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-24 12:06:08.853352 I  PMT for output stream
2012-07-24 12:06:08.853384 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-24 12:06:08.858718 D  IPTVSM()::UpdateValues: Table monitor started
2012-07-24 12:06:08.951885 I  TVRec(1): StopLiveTV(void) curRec: 0x10a074800 pseudoRec: 0x0
2012-07-24 12:06:08.952268 I  TVRec(1): Changing from WatchingLiveTV to None
2012-07-24 12:06:08.952305 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:08.952355 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
2012-07-24 12:06:08.952366 I  TVRec(1): TeardownSignalMonitor() -- begin
2012-07-24 12:06:08.952451 I  IPTVFeed: RemoveListener(0x108818e38) -- begin
2012-07-24 12:06:08.952464 I  FbFeedLive:RemoveListener(0x108818e38) -- begin
2012-07-24 12:06:08.952473 I  FbFeedLive:RemoveListener(0x108818e38) -- end 2
2012-07-24 12:06:08.952480 I  IPTVFeed: RemoveListener(0x108818e38) -- end (ok, removed)
2012-07-24 12:06:08.952487 D  IPTVSM()::Stop: begin
2012-07-24 12:06:08.952495 I  IPTVFeed: RemoveListener(0x108818e38) -- begin
2012-07-24 12:06:08.952502 E  IPTVFeed: RemoveListener(0x108818e38) -- end (not found)
2012-07-24 12:06:08.952509 D  SM()::Stop: begin
2012-07-24 12:06:09.109675 D  SM()::Stop: end
2012-07-24 12:06:09.109688 I  IPTVFeed: Stop() -- begin
2012-07-24 12:06:09.109693 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:09.159310 I  IPTVFeed: Run() -- end
2012-07-24 12:06:09.159313 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:09.159322 I  IPTVFeed: RemoveListener(0x108818e38) -- begin
2012-07-24 12:06:09.159324 I  IPTVFeed: Stop() -- end
2012-07-24 12:06:09.159327 E  IPTVFeed: RemoveListener(0x108818e38) -- end (not found)
2012-07-24 12:06:09.159332 D  IPTVSM()::Run: end
2012-07-24 12:06:09.159395 D  IPTVSM()::Stop: end
2012-07-24 12:06:09.159401 D  IPTVSM()::~IPTVSignalMonitor: Didn't get a lock earlier, closing feed
2012-07-24 12:06:09.159405 I  IPTVFeed: Close() -- begin
2012-07-24 12:06:09.159407 I  IPTVHLS: Close() -- begin
2012-07-24 12:06:09.159409 I  IPTVHLS: Stop() -- begin
2012-07-24 12:06:09.159411 I  IPTVHLS: Stop() -- end
2012-07-24 12:06:09.762202 C  MThread prolog was never run!
2012-07-24 12:06:09.762209 C  MThread epilog was never run!
2012-07-24 12:06:09.762256 C  MThread prolog was never run!
2012-07-24 12:06:09.762260 C  MThread epilog was never run!
2012-07-24 12:06:09.762388 I  IPTVHLS: Close() -- end
2012-07-24 12:06:09.762392 I  IPTVFeed: Close() -- end
2012-07-24 12:06:09.762408 D  SM()::Stop: begin
2012-07-24 12:06:09.762412 D  SM()::Stop: end
2012-07-24 12:06:09.762424 I  TVRec(1): TeardownSignalMonitor() -- end
2012-07-24 12:06:09.762434 I  TVRec(1): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:09.762482 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-24 12:06:09.762922 I  TVRec(1): FinishedRecording(1300_2012-07-24T02:06:05Z)
			title: 
			in recgroup: LiveTV status: Unknown:Recorder Failed is_dummy finished_now
2012-07-24 12:06:09.763098 I  Chain: Updated endtime for '1300_20120724020605' to 20120724020609
2012-07-24 12:06:09.763358 I  TVRec(1): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-24 12:06:09.763572 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-24 12:06:09.763794 I  TVRec(1): FinishedRecording(1300_2012-07-24T02:06:05Z)
			title: 
			in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy already_finished
2012-07-24 12:06:09.763953 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-24 12:06:09.763959 I  TVRec(1): Tearing down RingBuffer
2012-07-24 12:06:09.764043 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2012-07-24 12:06:17.528511 I  Starting mythlogserver

Attachments (6)

10934-partial-fix.patch (3.0 KB) - added by danielk 13 years ago.
mythbackend.log.zip (68.0 KB) - added by JYA 13 years ago.
Log when it did start…
log1.txt (15.8 KB) - added by JYA 13 years ago.
bt1.txt (38.3 KB) - added by JYA 13 years ago.
log2.txt (22.4 KB) - added by JYA 13 years ago.
bt2.txt (39.3 KB) - added by JYA 13 years ago.

Download all attachments as: .zip

Change History (11)

Changed 13 years ago by danielk

Attachment: 10934-partial-fix.patch added

comment:1 Changed 13 years ago by danielk

Owner: changed from danielk to jya
Status: newassigned

The problem is this call:

m_hls->Read((void *)m_buffer, BUFFER_SIZE);

In ivtvfeederhls.cpp

The IPTVFeeder::Stop() call is blocked from even setting m_interrupted to true because we're stuck in that call. The attached patch reworks the locking to avoid that problem. But IPTVFeederHLS needs to signal HLSRingBuffer to return from HLSRingBuffer::Read() quickly when IPTVFeederHLS::Stop() has been called.

comment:2 Changed 13 years ago by JYA

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@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.

Changed 13 years ago by JYA

Attachment: mythbackend.log.zip added

Log when it did start...

comment:3 Changed 13 years ago by JYA

another one just in case:

2012-07-30 22:11:08.713751 I  Getting next free recorder after : -1
2012-07-30 22:11:08.713762 I  Checking card 1. Best card so far -1
2012-07-30 22:11:08.714120 I  Best card is 1
2012-07-30 22:11:08.716039 I  MainServer::ANN Playback
2012-07-30 22:11:08.716048 I  adding: jyaimac as a client (events: 0)
2012-07-30 22:11:08.719988 I  TVRec(1): Found channel (301) on current card(1).
2012-07-30 22:11:08.731758 I  TVRec(1): Changing from None to WatchingLiveTV
2012-07-30 22:11:08.731790 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReady,
2012-07-30 22:11:08.731806 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
2012-07-30 22:11:08.731815 I  ChannelBase(1): Looking for startchannel '301' on input 'MPEG2TS'
2012-07-30 22:11:08.733336 I  ChannelBase(1): Found startchannel '301' on input 'MPEG2TS'
2012-07-30 22:11:08.733347 I  TVRec(1): HW Tuner: 1->1
2012-07-30 22:11:08.733354 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2012-07-30 22:11:08.733363 I  TVRec(1): No recorder yet, calling TuningFrequency
2012-07-30 22:11:08.733537 I  IPTVChan(1): Open() -- begin
2012-07-30 22:11:08.733542 I  IPTVChan(1): Open() -- locked
2012-07-30 22:11:08.734262 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-30 22:11:08.734268 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-30 22:11:08.734285 I  IPTVChan(1): Open() -- end
2012-07-30 22:11:08.734290 D  ChannelBase(1): SwitchToInput(MPEG2TS,301)
2012-07-30 22:11:08.735160 I  IPTVChan(1): SetChannelByString(301) -- begin
2012-07-30 22:11:08.735165 I  IPTVChan(1): SetChannelByString() -- locked
2012-07-30 22:11:08.736004 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-30 22:11:08.736009 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-30 22:11:08.736248 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 22:11:08.736286 I  IPTVChan(1): SetChannelByString(301) = 301 -- end
2012-07-30 22:11:08.736292 I  TVRec(1): CreateLiveTVRingBuffer(301)
2012-07-30 22:11:08.736584 I  TVRec(1): GetProgramRingBufferForLiveTV()
2012-07-30 22:11:08.740821 N  AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
2012-07-30 22:11:08.747620 I  TVRec(1): StartedRecording(1301_2012-07-30T12:11:08Z) fn(/DATA/Users/jyavenard/Downloads/mythtv/1301_20120730121108.mpg)
2012-07-30 22:11:08.749898 I  Using profile 'Default' to record
2012-07-30 22:11:08.751671 I  Chain: Appended@0 '1301_20120730121108'
2012-07-30 22:11:08.752343 I  TVRec(1): Starting Signal Monitor
2012-07-30 22:11:08.752349 I  TVRec(1): SetupSignalMonitor(1, 1)
2012-07-30 22:11:08.752354 I  IPTVChan(1): Open() -- begin
2012-07-30 22:11:08.752358 I  IPTVChan(1): Open() -- locked
2012-07-30 22:11:08.753509 I  ChannelBase(1): Input #1: 'MPEG2TS' schan(301) sourceid(1) ccid(1)
2012-07-30 22:11:08.753517 I  ChannelBase(1): Current Input #1: 'MPEG2TS'
2012-07-30 22:11:08.753536 I  IPTVChan(1): Open() -- end
2012-07-30 22:11:08.753573 I  IPTVChan(1): GetChanInfo() -- begin
2012-07-30 22:11:08.753576 I  IPTVChan(1): GetChanInfo() -- locked
2012-07-30 22:11:08.753821 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 22:11:08.753842 I  IPTVFeed: Open() -- begin
2012-07-30 22:11:08.753845 I  IPTVFeed: Init() -- begin
2012-07-30 22:11:09.850215 D  HLSBuffer: IsHTTPLiveStreaming: #EXTM3U
2012-07-30 22:11:09.850231 D  HLSBuffer: IsHTTPLiveStreaming: #EXT-X-VERSION:3
2012-07-30 22:11:09.850303 I  IPTVFeed: Init() -- end 0
2012-07-30 22:11:09.850314 I  IPTVHLS: Open(http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8) -- begin
2012-07-30 22:11:10.654443 D  HLSBuffer: IsHTTPLiveStreaming: #EXTM3U
2012-07-30 22:11:10.654452 D  HLSBuffer: IsHTTPLiveStreaming: #EXT-X-VERSION:3
2012-07-30 22:11:10.654460 I  HLSBuffer: HTTP Live Streaming (http://aj.lsops.net/live/aljazeer_en_high.sdp/playlist.m3u8)
2012-07-30 22:11:10.654477 I  HLSBuffer: Meta playlist
2012-07-30 22:11:10.654495 I  HLSBuffer: bandwidth adaptation detected (program-id=1, bandwidth=407796
2012-07-30 22:11:11.458286 I  HLSBuffer: Live Playlist HLS protocol version: 3
2012-07-30 22:11:11.458296 D  HLSBuffer: ParseM3U8: #EXTM3U
2012-07-30 22:11:11.458300 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
2012-07-30 22:11:11.458305 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
2012-07-30 22:11:11.458309 D  HLSBuffer: ParseM3U8: #EXT-X-TARGETDURATION:12
2012-07-30 22:11:11.458313 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-SEQUENCE:652
2012-07-30 22:11:11.458317 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:11.458325 D  HLSBuffer: ParseM3U8: media_652.ts?wowzasessionid=74172855
2012-07-30 22:11:11.458349 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:11.458354 D  HLSBuffer: ParseM3U8: media_653.ts?wowzasessionid=74172855
2012-07-30 22:11:11.458370 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:11.458380 D  HLSBuffer: ParseM3U8: media_654.ts?wowzasessionid=74172855
2012-07-30 22:11:11.458442 I  HLSBuffer: Starting Prefetch for 2 segments
2012-07-30 22:11:11.458506 D  HLSBuffer: started download of segment 0 [652/655] using stream 0
2012-07-30 22:11:12.205271 I  Starting mythlogserver
2012-07-30 22:11:15.484557 D  HLSBuffer: downloaded segment 0 [id:652] took 4026ms for 409652 bytes: bandwidth:99.3661kiB/s
2012-07-30 22:11:15.484574 D  HLSBuffer: download completed, 3 segments ahead
2012-07-30 22:11:15.484583 D  HLSBuffer: candidate stream 0 bitrate 814007 >= 407796
2012-07-30 22:11:15.484598 D  HLSBuffer: started download of segment 1 [653/655] using stream 0
2012-07-30 22:11:15.731322 I  MainServer::ANN Playback
2012-07-30 22:11:15.731328 I  adding: jyaimac as a client (events: 0)
2012-07-30 22:11:17.899275 D  HLSBuffer: downloaded segment 1 [id:653] took 2414ms for 418488 bytes: bandwidth:169.25kiB/s
2012-07-30 22:11:17.899287 D  HLSBuffer: download completed, 2 segments ahead
2012-07-30 22:11:17.899295 D  HLSBuffer: candidate stream 0 bitrate 1100249 >= 407796
2012-07-30 22:11:17.899311 D  HLSBuffer: started download of segment 2 [654/655] using stream 0
2012-07-30 22:11:17.899357 I  HLSBuffer: Finished Prefetch (6.44091s)
2012-07-30 22:11:17.899401 I  IPTVHLS: Open() -- end
2012-07-30 22:11:17.899408 I  IPTVFeed: Open() -- end
2012-07-30 22:11:17.899420 I  TVRec(1): Signal monitor successfully created
2012-07-30 22:11:17.899425 I  TVRec(1): Setting up table monitoring.
2012-07-30 22:11:17.899454 D  HLSBuffer: PlayListWorker refreshing in 0s
2012-07-30 22:11:17.900956 I  Using profile 'Live TV' to record
2012-07-30 22:11:17.900979 I  TVRec(1): MPEG program number: 1
2012-07-30 22:11:17.900995 I  DTVSM()::SetProgramNumber(1): 
2012-07-30 22:11:17.901004 D  SM()::RemoveFlags: Seen(PMT,Crypt,) Match(PMT,Crypt,) Wait()
2012-07-30 22:11:17.901017 D  SM()::AddFlags: Seen() Match() Wait(PMT,)
2012-07-30 22:11:17.901023 D  SM()::AddFlags: Seen() Match() Wait(PAT,PMT,Pos,)
2012-07-30 22:11:17.901027 I  TVRec(1): Successfully set up MPEG table monitoring.
2012-07-30 22:11:17.901045 D  SM()::Start: begin
2012-07-30 22:11:17.901109 D  SM()::Start: end
2012-07-30 22:11:17.901119 I  TVRec(1): SetFlags(SignalMonitorRunning,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2012-07-30 22:11:17.901127 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,SignalMonitorRunning,RingBufferReady,
2012-07-30 22:11:17.901132 D  IPTVSM()::UpdateValues: Waiting for table monitor to start
2012-07-30 22:11:17.901134 I  TVRec(1): SetFlags(WaitingForSignal,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,RingBufferReady,
2012-07-30 22:11:17.901141 I  TVRec(1): SetFlags(DummyRecorderRunning,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.901144 I  DummyDTVRecorder -- started
2012-07-30 22:11:17.901150 I  TVRec(1): SetFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.901157 I  TVRec(1): ClearFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.901164 I  TVRec(1): SetFlags(NeedToStartRecorder,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.901226 D  IPTVSM()::Run: begin
2012-07-30 22:11:17.901234 I  IPTVFeed: AddListener(0x108840a38) -- begin
2012-07-30 22:11:17.901239 I  FbFeedLive:AddListener(0x108840a38) -- begin
2012-07-30 22:11:17.901240 I  TVRec(1): SetFlags(CancelNextRecording,) -> RunMainLoop,CancelNextRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.901245 I  FbFeedLive:RemoveListener(0x108840a38) -- begin
2012-07-30 22:11:17.901261 I  FbFeedLive:RemoveListener(0x108840a38) -- end 1
2012-07-30 22:11:17.901264 I  FbFeedLive:AddListener(0x108840a38) -- end
2012-07-30 22:11:17.901267 I  IPTVFeed: AddListener(0x108840a38) -- end 1
2012-07-30 22:11:17.901270 I  IPTVFeed: Run() -- begin
2012-07-30 22:11:17.901273 D  HLSBuffer: requesting restart
2012-07-30 22:11:17.901282 I  HLSBuffer: started reading segment 0 [id:652] from stream 0 (2 buffered)
2012-07-30 22:11:17.901364 D  SM()::AddFlags: Seen(PAT,) Match() Wait()
2012-07-30 22:11:17.901370 D  SM()::AddFlags: Seen() Match(PAT,) Wait()
2012-07-30 22:11:17.901377 I  CreatePATSingleProgram()
2012-07-30 22:11:17.901379 I  PAT in input stream
2012-07-30 22:11:17.901394 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 22:11:17.901398 I  desired_program(1) pid(0xfff)
2012-07-30 22:11:17.901409 I  pmt_pid(0xfff)
2012-07-30 22:11:17.901411 I  PAT for output stream
2012-07-30 22:11:17.901423 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 22:11:17.901452 D  SM()::AddFlags: Seen(PMT,) Match() Wait()
2012-07-30 22:11:17.901474 D  SM()::AddFlags: Seen() Match(PMT,) Wait()
2012-07-30 22:11:17.901477 I  CreatePMTSingleProgram()
2012-07-30 22:11:17.901479 I  PMT in input stream
2012-07-30 22:11:17.901512 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 22:11:17.901546 I  PMT for output stream
2012-07-30 22:11:17.901579 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 22:11:17.901974 I  HLSBuffer: started reading segment 1 [id:653] from stream 0 (1 buffered)
2012-07-30 22:11:17.902015 I  HLSBuffer: pausing until we get sufficient data buffered
2012-07-30 22:11:17.902123 I  TVRec(1): StopLiveTV(void) curRec: 0x1093691f0 pseudoRec: 0x0
2012-07-30 22:11:17.906805 D  IPTVSM()::UpdateValues: Table monitor started
2012-07-30 22:11:17.912921 I  TVRec(1): Changing from WatchingLiveTV to None
2012-07-30 22:11:17.912955 I  TVRec(1): ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:17.912966 I  TVRec(1): HandleTuning Request: Program(NULL) channel() input() flags(KillRec,KillRingBuffer,)
2012-07-30 22:11:17.912973 I  TVRec(1): TeardownSignalMonitor() -- begin
2012-07-30 22:11:17.912981 I  IPTVFeed: RemoveListener(0x108840a38) -- begin
2012-07-30 22:11:17.912987 I  FbFeedLive:RemoveListener(0x108840a38) -- begin
2012-07-30 22:11:17.912991 I  FbFeedLive:RemoveListener(0x108840a38) -- end 2
2012-07-30 22:11:17.912995 I  IPTVFeed: RemoveListener(0x108840a38) -- end (ok, removed)
2012-07-30 22:11:17.912998 D  IPTVSM()::Stop: begin
2012-07-30 22:11:17.913001 I  IPTVFeed: RemoveListener(0x108840a38) -- begin
2012-07-30 22:11:17.913012 E  IPTVFeed: RemoveListener(0x108840a38) -- end (not found)
2012-07-30 22:11:17.913016 D  SM()::Stop: begin
2012-07-30 22:11:17.999954 I  HLSBuffer: reloading HLS live meta playlist
2012-07-30 22:11:18.157597 D  SM()::Stop: end
2012-07-30 22:11:18.157607 I  IPTVFeed: Stop() -- begin
2012-07-30 22:11:18.157610 I  IPTVHLS: Stop() -- begin
2012-07-30 22:11:19.006071 I  HLSBuffer: Live Playlist HLS protocol version: 3
2012-07-30 22:11:19.006083 D  HLSBuffer: ParseM3U8: #EXTM3U
2012-07-30 22:11:19.006087 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
2012-07-30 22:11:19.006092 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
2012-07-30 22:11:19.006096 D  HLSBuffer: ParseM3U8: #EXT-X-TARGETDURATION:12
2012-07-30 22:11:19.006100 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-SEQUENCE:653
2012-07-30 22:11:19.006104 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:19.006112 D  HLSBuffer: ParseM3U8: media_653.ts?wowzasessionid=74172855
2012-07-30 22:11:19.006140 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:19.006145 D  HLSBuffer: ParseM3U8: media_654.ts?wowzasessionid=74172855
2012-07-30 22:11:19.006161 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:19.006166 D  HLSBuffer: ParseM3U8: media_655.ts?wowzasessionid=74172855
2012-07-30 22:11:19.006192 I  HLSBuffer: updated hls stream (program-id=1, bitrate=407796) has 3 segments
2012-07-30 22:11:19.815398 D  HLSBuffer: downloaded segment 2 [id:654] took 1916ms for 413788 bytes: bandwidth:210.896kiB/s
2012-07-30 22:11:19.815398 I  HLSBuffer: - segment 655 appended
2012-07-30 22:11:19.815412 D  HLSBuffer: download completed, 2 segments ahead
2012-07-30 22:11:19.815419 D  HLSBuffer: candidate stream 0 bitrate 1309386 >= 407796
2012-07-30 22:11:19.815420 D  HLSBuffer: PlayListWorker refreshing in 6s
2012-07-30 22:11:19.815436 D  HLSBuffer: started download of segment 3 [655/656] using stream 0
2012-07-30 22:11:19.815470 D  HLSBuffer: requesting interrupt
2012-07-30 22:11:19.815489 D  HLSBuffer: interrupted
2012-07-30 22:11:19.815496 I  IPTVFeed: Run() -- end
2012-07-30 22:11:19.815498 I  IPTVHLS: Stop() -- end
2012-07-30 22:11:19.815501 I  IPTVFeed: Stop() -- end
2012-07-30 22:11:19.815503 I  IPTVFeed: RemoveListener(0x108840a38) -- begin
2012-07-30 22:11:19.815508 E  IPTVFeed: RemoveListener(0x108840a38) -- end (not found)
2012-07-30 22:11:19.815511 D  IPTVSM()::Run: end
2012-07-30 22:11:19.815593 D  IPTVSM()::Stop: end
2012-07-30 22:11:19.815599 D  IPTVSM()::~IPTVSignalMonitor: Didn't get a lock earlier, closing feed
2012-07-30 22:11:19.815602 I  IPTVFeed: Close() -- begin
2012-07-30 22:11:19.815605 I  IPTVHLS: Close() -- begin
2012-07-30 22:11:19.815607 I  IPTVHLS: Stop() -- begin
2012-07-30 22:11:19.815609 D  HLSBuffer: requesting interrupt
2012-07-30 22:11:19.815611 I  IPTVHLS: Stop() -- end
2012-07-30 22:11:19.815629 I  HLSBuffer: reloading HLS live meta playlist
2012-07-30 22:11:21.021607 I  HLSBuffer: Live Playlist HLS protocol version: 3
2012-07-30 22:11:21.021615 D  HLSBuffer: ParseM3U8: #EXTM3U
2012-07-30 22:11:21.021620 D  HLSBuffer: ParseM3U8: #EXT-X-VERSION:3
2012-07-30 22:11:21.021624 D  HLSBuffer: ParseM3U8: #EXT-X-ALLOW-CACHE:YES
2012-07-30 22:11:21.021628 D  HLSBuffer: ParseM3U8: #EXT-X-TARGETDURATION:12
2012-07-30 22:11:21.021633 D  HLSBuffer: ParseM3U8: #EXT-X-MEDIA-SEQUENCE:653
2012-07-30 22:11:21.021637 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:21.021645 D  HLSBuffer: ParseM3U8: media_653.ts?wowzasessionid=74172855
2012-07-30 22:11:21.021672 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:21.021677 D  HLSBuffer: ParseM3U8: media_654.ts?wowzasessionid=74172855
2012-07-30 22:11:21.021695 D  HLSBuffer: ParseM3U8: #EXTINF:9,
2012-07-30 22:11:21.021701 D  HLSBuffer: ParseM3U8: media_655.ts?wowzasessionid=74172855
2012-07-30 22:11:21.021728 I  HLSBuffer: updated hls stream (program-id=1, bitrate=407796) has 3 segments
2012-07-30 22:11:21.427966 D  HLSBuffer: downloaded segment 3 [id:655] took 1612ms for 412096 bytes: bandwidth:249.574kiB/s
2012-07-30 22:11:21.427987 D  HLSBuffer: download completed, 1 segments ahead
2012-07-30 22:11:21.427994 D  HLSBuffer: candidate stream 0 bitrate 1493167 >= 407796
2012-07-30 22:11:21.428019 C  MThread prolog was never run!
2012-07-30 22:11:21.428024 C  MThread epilog was never run!
2012-07-30 22:11:21.428145 C  MThread prolog was never run!
2012-07-30 22:11:21.428148 C  MThread epilog was never run!
2012-07-30 22:11:21.428281 I  IPTVHLS: Close() -- end
2012-07-30 22:11:21.428284 I  IPTVFeed: Close() -- end
2012-07-30 22:11:21.428301 D  SM()::Stop: begin
2012-07-30 22:11:21.428304 D  SM()::Stop: end
2012-07-30 22:11:21.428316 I  TVRec(1): TeardownSignalMonitor() -- end
2012-07-30 22:11:21.428324 I  TVRec(1): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:21.428375 I  TVRec(1): ClearFlags(WaitingForSignal,) -> RunMainLoop,NeedToStartRecorder,DummyRecorderRunning,RingBufferReady,
2012-07-30 22:11:21.428899 I  TVRec(1): FinishedRecording(1301_2012-07-30T12:11:08Z)
			title: 
			in recgroup: LiveTV status: Unknown:Recorder Failed is_dummy finished_now
2012-07-30 22:11:21.429172 I  Chain: Updated endtime for '1301_20120730121108' to 20120730121121
2012-07-30 22:11:21.429448 I  TVRec(1): ClearFlags(DummyRecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-30 22:11:21.429741 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-30 22:11:21.429946 I  TVRec(1): FinishedRecording(1301_2012-07-30T12:11:08Z)
			title: 
			in recgroup: LiveTV status: Recorder Failed:Recorder Failed not_dummy already_finished
2012-07-30 22:11:21.430176 I  TVRec(1): ClearFlags(RecorderRunning,) -> RunMainLoop,NeedToStartRecorder,RingBufferReady,
2012-07-30 22:11:21.430183 I  TVRec(1): Tearing down RingBuffer
2012-07-30 22:11:21.430310 I  TVRec(1): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,RingBufferReady,
2012-07-30 22:11:21.430405 W  MainServer: Unknown socket closing MythSocket(0x10937c1e0)
2012-07-30 22:11:21.430429 E  MythSocket(10937c1e0:-1): writeStringList: Error, No data written on writeBlock (1 errors)
			starts with: 2       OK
2012-07-30 22:11:40.778534 D  MMulticastSocketDevice(239.255.255.250:94): setsockopt - IP_DROP_MEMBERSHIP 
			eno: Invalid argument (22)
2012-07-30 22:11:42.319811 I  Starting mythlogserver

I should add that mythfrontend takes about an extra 20-30s to finally exit playback, and that it displays no error whatsoever, just go back to the main menu

Changed 13 years ago by JYA

Attachment: log1.txt added

Changed 13 years ago by JYA

Attachment: bt1.txt added

Changed 13 years ago by JYA

Attachment: log2.txt added

Changed 13 years ago by JYA

Attachment: bt2.txt added

comment:4 Changed 13 years ago by Jean-Yves Avenard <jyavenard@…>

Resolution: fixed
Status: assignedclosed

In 8c551e600f3b993f8b5199e0f02ce79357e0d6ea/mythtv:

Error: Processor CommitTicketReference failed
GIT backend not available

comment:5 Changed 13 years ago by Raymond Wagner

Milestone: unknown0.26
Version: UnspecifiedMaster Head
Note: See TracTickets for help on using tickets.