Good morning,
In the past couple of weeks I've had trouble with Prime (terrestrial - Sugarloaf) on my MediaPortal 1.5.0. It does not display any video (audio okay) on MP nor on preview on MP TV Server Config. All other channels are fine.
It has been this way for maybe 2 weeks, except for a period for a couple of days where it came back and then went again. Interestingly it lost EPG after a while and after I performed a manual update of the EGP feed in the period the video returned.
I have been running MP for several months with no problem (1.4.0) before I performed a bare metal reinstalation. Once rebuilt All channels were working fine on 1.5.0. At some point the video for Prime dropped. I have completely uninstalled MP 1.5.0 including TV server, installed 1.4.0 (on video on prime), upgraded to 1.5.0 (no video on prime).
Has anyone else seen this or have any suggestion for troubleshooting?
MP 1.5.0
Win 7
Hauppauge HVR 2200
Sapphire Radeon HD 6450
Happy to supply more info, just let me know what!
Thanks
Nathan
Excerpt from the TV Server log when I previewed Prime:
[2013-10-27 10:01:48,345] [Log ] [3 ] [INFO ] - Controller: epg stop
[2013-10-27 10:02:57,199] [Log ] [3 ] [INFO ] - Controller: epg stop
[2013-10-27 10:03:02,720] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting PRIME 16
[2013-10-27 10:03:02,721] [Log ] [3 ] [INFO ] - Controller: epg stop
[2013-10-27 10:03:02,721] [Log ] [3 ] [INFO ] - Controller: find free card for channel PRIME
[2013-10-27 10:03:02,721] [Log ] [3 ] [INFO ] - Controller: find card for channel PRIME
[2013-10-27 10:03:02,722] [Log ] [3 ] [INFO ] - Controller: got 1 tuning details for PRIME
[2013-10-27 10:03:02,723] [Log ] [3 ] [INFO ] - Controller: channel #1 DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:02,723] [Log ] [3 ] [INFO ] - Controller: card:6 type:RadioWebStream cannot tune to channel
[2013-10-27 10:03:02,724] [Log ] [3 ] [INFO ] - Controller: card:1 type:DvbIP cannot tune to channel
[2013-10-27 10:03:02,724] [Log ] [3 ] [INFO ] - Controller: card:4 type:Analog cannot tune to channel
[2013-10-27 10:03:02,725] [Log ] [3 ] [INFO ] - Controller: card:5 type:Analog cannot tune to channel
[2013-10-27 10:03:02,726] [Log ] [3 ] [INFO ] - Controller: card:2 type:DvbT can tune to channel
[2013-10-27 10:03:02,728] [Log ] [3 ] [INFO ] - Controller: card:3 type:DvbT can tune to channel
[2013-10-27 10:03:02,728] [Log ] [3 ] [INFO ] - Controller: found 2 card(s) for channel
[2013-10-27 10:03:02,729] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 7 msec
[2013-10-27 10:03:02,729] [Log ] [3 ] [INFO ] - Controller: found 2 free card(s)
[2013-10-27 10:03:02,729] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 9 msec
[2013-10-27 10:03:02,731] [Log ] [3 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=31, tuningdetails=DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:02,732] [Log ] [3 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=32, tuningdetails=DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:02,732] [Log ] [3 ] [INFO ] - Controller: card:2 type:DvbT users: 0
[2013-10-27 10:03:02,733] [Log ] [3 ] [INFO ] - Controller: card:2 type:DvbT is available
[2013-10-27 10:03:02,733] [Log ] [3 ] [INFO ] - Controller: card:3 type:DvbT users: 0
[2013-10-27 10:03:02,734] [Log ] [3 ] [INFO ] - Controller: card:3 type:DvbT is available
[2013-10-27 10:03:02,734] [Log ] [3 ] [INFO ] - Controller: try max 2 of 2 cards for timeshifting
[2013-10-27 10:03:02,735] [Log ] [3 ] [DEBUG] - CardReservationBase: tvcard=2, user=setuptv, dbChannel=16, ticket=31, tunestate=Tuning, stopstate=Idle
[2013-10-27 10:03:02,739] [Log ] [3 ] [INFO ] - card: CardTune 2 PRIME setuptv:2:-1
[2013-10-27 10:03:02,740] [Log ] [3 ] [INFO ] - card: Tune on card 2 to subchannel PRIME
[2013-10-27 10:03:02,740] [Log ] [3 ] [DEBUG] - card: user: setuptv:2:-1 tune DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:02,751] [Log ] [3 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2013-10-27 10:03:02,751] [Log ] [3 ] [INFO ] - dvbt: Tune:DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:02,752] [Log ] [3 ] [INFO ] - dvb:Submiting tunerequest Channel:PRIME subChannel:-1
[2013-10-27 10:03:02,752] [Log ] [3 ] [INFO ] - dvb:Getting new subchannel
[2013-10-27 10:03:02,753] [Log ] [3 ] [INFO ] - dvb:GetNewSubChannel:0 #0
[2013-10-27 10:03:02,756] [Log ] [3 ] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2013-10-27 10:03:02,756] [Log ] [3 ] [INFO ] - card: AddTuneEvent card: 2 / subch: 0
[2013-10-27 10:03:02,757] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2013-10-27 10:03:02,758] [Log ] [3 ] [INFO ] - subch:0 OnBeforeTune
[2013-10-27 10:03:02,759] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2013-10-27 10:03:02,760] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2013-10-27 10:03:02,760] [Log ] [3 ] [INFO ] - subch:0 OnAfterTune
[2013-10-27 10:03:02,761] [Log ] [3 ] [INFO ] - RunGraph
[2013-10-27 10:03:02,761] [Log ] [3 ] [INFO ] - subch:0 OnGraphStart
[2013-10-27 10:03:02,762] [Log ] [3 ] [INFO ] - dvb: RunGraph
[2013-10-27 10:03:03,523] [Log ] [3 ] [INFO ] - dvb: LockInOnSignal ok
[2013-10-27 10:03:03,524] [Log ] [3 ] [INFO ] - subch:0 OnGraphStarted
[2013-10-27 10:03:03,524] [Log ] [3 ] [INFO ] - subch:0 SetupPmtGrabber:pid CC sid:57C
[2013-10-27 10:03:03,525] [Log ] [3 ] [INFO ] - subch:0 set pmt grabber pmt:CC sid:57C
[2013-10-27 10:03:03,526] [Log ] [3 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2013-10-27 10:03:03,526] [Log ] [3 ] [DEBUG] - WaitForPMT: Waiting for PMT CC
[2013-10-27 10:03:03,667] [Log ] [22 ] [INFO ] - subch:0 OnPMTReceived() pmt:CC ran:True dynamic:False
[2013-10-27 10:03:03,668] [Log ] [3 ] [DEBUG] - WaitForPMT: Found PMT after 0.1416016 seconds.
[2013-10-27 10:03:03,669] [Log ] [3 ] [INFO ] - subch:0 SendPmt:57C 57C FFFFFFFF F
[2013-10-27 10:03:03,669] [Log ] [3 ] [INFO ] - Decode pmt
[2013-10-27 10:03:03,670] [Log ] [3 ] [INFO ] - Set descriptor data with length 3
[2013-10-27 10:03:03,670] [Log ] [3 ] [INFO ] - Set descriptor data with length 3
[2013-10-27 10:03:03,671] [Log ] [3 ] [INFO ] - Set descriptor data with length 3
[2013-10-27 10:03:03,671] [Log ] [3 ] [INFO ] - PROBLEM : descriptor lengths dont match 6 9
[2013-10-27 10:03:03,672] [Log ] [3 ] [INFO ] - subch:0 SendPMT: Channel is FTA, nothing to do.
[2013-10-27 10:03:03,672] [Log ] [3 ] [INFO ] - subch:0 SetMpegPidMapping
[2013-10-27 10:03:03,672] [Log ] [3 ] [INFO ] - subch:0 pid:22A pcr
[2013-10-27 10:03:03,673] [Log ] [3 ] [INFO ] - subch:0 pid:CC pmt
[2013-10-27 10:03:03,673] [Log ] [3 ] [INFO ] - subch:0 pid:3EC type:B
[2013-10-27 10:03:03,674] [Log ] [3 ] [INFO ] - subch:0 pid:22A video type:H.264
[2013-10-27 10:03:03,674] [Log ] [3 ] [INFO ] - subch:0 map pid:22A video type:H.264
[2013-10-27 10:03:03,675] [Log ] [3 ] [INFO ] - subch:0 pid:25C audio lang: type:MPEG-1
[2013-10-27 10:03:03,676] [Log ] [3 ] [INFO ] - subch:0 map pid:25C audio lang: type:MPEG-1
[2013-10-27 10:03:03,677] [Log ] [3 ] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
[2013-10-27 10:03:03,678] [Log ] [3 ] [INFO ] - subch:0 stop tif
[2013-10-27 10:03:03,678] [Log ] [3 ] [DEBUG] - WaitForPmt: PMT handling took 0.0087891 seconds.
[2013-10-27 10:03:03,679] [Log ] [3 ] [INFO ] - dvbt: tune: Graph running. Returning TvLibrary.Implementations.DVB.TvDvbChannel
[2013-10-27 10:03:03,751] [Log ] [3 ] [DEBUG] - card: Tuner locked: True
[2013-10-27 10:03:03,752] [Log ] [3 ] [INFO ] - **************************************************
[2013-10-27 10:03:03,753] [Log ] [3 ] [INFO ] - ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 25 *****
[2013-10-27 10:03:03,753] [Log ] [3 ] [INFO ] - **************************************************
[2013-10-27 10:03:03,754] [Log ] [3 ] [DEBUG] - card: tuned user: setuptv subchannel: 0
[2013-10-27 10:03:03,754] [Log ] [3 ] [INFO ] - user:setuptv add
[2013-10-27 10:03:03,757] [Log ] [3 ] [INFO ] - card2:setuptv 2 0
[2013-10-27 10:03:03,758] [Log ] [3 ] [INFO ] - Controller: delete timeshift files D:\Timeshift\live2-0.ts
[2013-10-27 10:03:03,759] [Log ] [3 ] [INFO ] - Controller: epg stop
[2013-10-27 10:03:03,763] [Log ] [3 ] [INFO ] - card: StartTimeShifting 2 D:\Timeshift\live2-0.ts
[2013-10-27 10:03:03,764] [Log ] [3 ] [INFO ] - card: CAM enabled : False
[2013-10-27 10:03:03,764] [Log ] [3 ] [INFO ] - subch:0 SetTimeShiftFileName:D:\Timeshift\live2-0.ts
[2013-10-27 10:03:03,765] [Log ] [3 ] [INFO ] - Set video / audio observer
[2013-10-27 10:03:03,767] [Log ] [3 ] [INFO ] - subch:0 SetTimeShiftFileName fill in pids
[2013-10-27 10:03:03,772] [Log ] [3 ] [INFO ] - subch:0-0 tswriter StartTimeshifting...
[2013-10-27 10:03:03,774] [Log ] [3 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2013-10-27 10:03:03,779] [Log ] [22 ] [INFO ] - PID seen - type = Video
[2013-10-27 10:03:03,779] [Log ] [22 ] [INFO ] - audioVideoEventHandler Video
[2013-10-27 10:03:03,920] [Log ] [22 ] [INFO ] - PID seen - type = Audio
[2013-10-27 10:03:03,921] [Log ] [22 ] [INFO ] - audioVideoEventHandler Audio
[2013-10-27 10:03:03,921] [Log ] [3 ] [INFO ] - card: WaitForFile - video and audio are seen after 0.1464844 seconds
[2013-10-27 10:03:03,925] [Log ] [3 ] [INFO ] - user:setuptv card:2 sub:0 add stream:D:\Timeshift\live2-0.ts.tsbuffer
[2013-10-27 10:03:03,926] [Log ] [3 ] [INFO ] - RTSP: add stream stream2.0 file:D:\Timeshift\live2-0.ts.tsbuffer
[2013-10-27 10:03:03,927] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting started on card:2 to D:\Timeshift\live2-0.ts.tsbuffer
[2013-10-27 10:03:03,928] [Log ] [3 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=31, tuningdetails=DVBT:tv:SKY PRIME Freq:594000 ONID:8746 TSID:33 SID:1404 PMT:0xCC FTA:True LCN:10 BandWidth:8
[2013-10-27 10:03:03,928] [Log ] [3 ] [INFO ] - card: SignalTuneEvent card: 2 / subch: 0
[2013-10-27 10:03:03,929] [Log ] [3 ] [INFO ] - Controller: setuptv 2 0
[2013-10-27 10:03:03,929] [Log ] [3 ] [DEBUG] - CardReservation.CancelCardReservation id=32
[2013-10-27 10:03:03,929] [Log ] [3 ] [INFO ] - control2:setuptv 2 0
[2013-10-27 10:03:09,066] [Log ] [3 ] [INFO ] - Controller: StopTimeShifting 2
[2013-10-27 10:03:09,069] [Log ] [3 ] [DEBUG] - CardTuner.RequestCardStopReservation: placed reservation with id=33, user=setuptv
[2013-10-27 10:03:09,170] [Log ] [3 ] [DEBUG] - CardTuner.Stop: ticket id=33, found=True
[2013-10-27 10:03:09,170] [Log ] [3 ] [INFO ] - Stop cardid=2, ticket=33, tunestate=Idle, stopstate=Stopping
[2013-10-27 10:03:09,171] [Log ] [3 ] [INFO ] - card Hauppauge WinTV-7164 BDA DVBT Tuner: StopTimeShifting user:setuptv sub:0
[2013-10-27 10:03:09,171] [Log ] [3 ] [DEBUG] - card not IDLE - removing user: setuptv
[2013-10-27 10:03:09,172] [Log ] [3 ] [DEBUG] - usermanagement.RemoveUser: setuptv, subch: 0 of 1, card: 2
[2013-10-27 10:03:09,172] [Log ] [3 ] [INFO ] - user:setuptv remove
[2013-10-27 10:03:09,173] [Log ] [3 ] [INFO ] - subch:0-0 tswriter StopTimeshifting...
[2013-10-27 10:03:09,176] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2013-10-27 10:03:09,177] [Log ] [3 ] [INFO ] - DVB subch:0 Decompose()
[2013-10-27 10:03:09,179] [Log ] [3 ] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
[2013-10-27 10:03:09,179] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
[2013-10-27 10:03:09,180] [Log ] [3 ] [INFO ] - dvb:StopGraph called
[2013-10-27 10:03:09,180] [Log ] [3 ] [INFO ] - tvcard:FreeAllSubChannels
[2013-10-27 10:03:09,181] [Log ] [3 ] [INFO ] - dvb:StopGraph
[2013-10-27 10:03:09,403] [Log ] [3 ] [INFO ] - dvb:StopGraph called
[2013-10-27 10:03:09,403] [Log ] [3 ] [INFO ] - tvcard:FreeAllSubChannels
[2013-10-27 10:03:09,404] [Log ] [3 ] [INFO ] - dvb:StopGraph filterstate already stopped, returning.
[2013-10-27 10:03:09,404] [Log ] [3 ] [INFO ] - user:setuptv remove
[2013-10-27 10:03:09,405] [Log ] [3 ] [DEBUG] - CardReservation.RemoveStopTicket: removed STOP reservation with id=33
[2013-10-27 10:03:09,405] [Log ] [3 ] [INFO ] - Controller:Timeshifting stopped on card:2
[2013-10-27 10:03:09,406] [Log ] [3 ] [INFO ] - RTSP: remove stream stream2.0
[2013-10-27 10:03:09,406] [Log ] [3 ] [INFO ] - Controller: epg start
[2013-10-27 10:03:09,407] [Log ] [TS_File_Cleanup] [INFO ] - card: delete timeshift files D:\Timeshift\live2-0.ts
ID Verified
