MP stops recording before it is supposed to

Discussion in 'General Support' started by Doomblaster, September 9, 2013.

  1. Doomblaster

    Doomblaster Portal Member

    Joined:
    August 27, 2012
    Messages:
    9
    Likes Received:
    0
    Gender:
    Male
    Ratings:
    +0 / 0
    Home Country:
    Norway Norway
    Okay...this has happened more and more often lately, and I can't really get to the bottom of this. Last time this happened was yesterday (08.09.2013). I had scheduled a recording from 21.29 to 22.35, and basically only 13 minutes and 50 seconds were recorded. I wasn't actually watching any other channel at that time, but I was using the HTPC to rent a movie online, so it was online streaming data. Other times this has happened, I have actually watched other channels, but MP has always indicated that it has been recording. Therefore it may look like similar to this issue: https://forum.team-mediaportal.com/...as-recording-but-doesnt-write-to-file.121429/. Before yesterdays recording I did actually turn on preloading the tuners though, so at least that isn't going to fix it for me.

    Anyone able to decode anything from the logs?

    My setup is single seat
    Intel DH77EB
    Intel 3770T
    Intel X-25 SSD
    8GB RAM
    Digital Devices Cine CT V6 with 2 tuners and CAM



    Surely this should be sufficient to run everything? It is working pretty well at least, except for the issue with recordings lately.
     
  2. Google AdSense Guest Advertisement



    to hide all adverts.
  3. mm1352000
    • Team MediaPortal

    mm1352000 Development Group

    Joined:
    September 1, 2008
    Messages:
    21,527
    Likes Received:
    4,738
    Ratings:
    +8,205 / 17
    Home Country:
    New Zealand New Zealand
    Hello Doomblaster

    From TV Server's perspective, it recorded the full program:
    Show Spoiler

    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Scheduler: Time to record TV Norge HD 21:29-22:30 Åndenes makt
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: find free card for channel TV Norge HD
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: find card for channel TV Norge HD
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: got 1 tuning details for TV Norge HD
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: channel #1 DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:5 type:DvbC can tune to channel
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:3 type:DvbC can tune to channel
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:6 type:RadioWebStream cannot tune to channel
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:2 type:DvbS is disabled
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:4 type:DvbS is disabled
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: found 2 card(s) for channel
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 1 msec
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: found 2 free card(s)
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 1 msec
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=237, tuningdetails=DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=238, tuningdetails=DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:5 type:DvbC users: 1
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:5 type:DvbC is available
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:3 type:DvbC users: 0
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - Controller: card:3 type:DvbC is available
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - scheduler: try max 2 of 2 free cards for recording
    [2013-09-08 21:29:07,512] [EPG ] [scheduler thread] [INFO ] - epg cancelled due to start recording
    [2013-09-08 21:29:07,512] [EPG ] [scheduler thread] [INFO ] - epg grabber:epg cancelled
    [2013-09-08 21:29:07,512] [EPG ] [scheduler thread] [INFO ] - EpgGrabbing: Stop - user epg
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - user:epg remove
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
    [2013-09-08 21:29:07,512] [Log ] [scheduler thread] [INFO ] - DVB subch:0 Decompose()
    [2013-09-08 21:29:07,527] [Log ] [scheduler thread] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
    [2013-09-08 21:29:07,527] [Log ] [scheduler thread] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
    [2013-09-08 21:29:07,527] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph called
    [2013-09-08 21:29:07,527] [Log ] [scheduler thread] [INFO ] - tvcard:FreeAllSubChannels
    [2013-09-08 21:29:07,527] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - Controller: epg stop
    [2013-09-08 21:29:07,549] [EPG ] [scheduler thread] [INFO ] - EPG: grabber stopped..
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - Scheduler : record, first tune to channel
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - card: Tune on card 3 to subchannel TV Norge HD
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [DEBUG] - card: user: scheduler263:3:-1 tune DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - dvbc: Tune:DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - dvb:confused:ubmiting tunerequest Channel:TV Norge HD subChannel:-1
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - dvb:Getting new subchannel
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - dvb:GetNewSubChannel:0 #0
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - TvDvbChannel ctor new subchIndex:0
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - card: AddTuneEvent card: 3 / subch: 0
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - dvb:confused:ubmit tunerequest size:1 new:0
    [2013-09-08 21:29:07,549] [Log ] [scheduler thread] [INFO ] - subch:0 OnBeforeTune
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - dvb:confused:ubmit tunerequest calling put_TuneRequest
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - dvb:confused:ubmit tunerequest done calling put_TuneRequest
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - subch:0 OnAfterTune
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - RunGraph
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - subch:0 OnGraphStart
    [2013-09-08 21:29:07,564] [Log ] [scheduler thread] [INFO ] - dvb: RunGraph
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [INFO ] - dvb: LockInOnSignal ok
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [INFO ] - subch:0 OnGraphStarted
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [INFO ] - subch:0 SetupPmtGrabber:pid B5 sid:1007
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [INFO ] - subch:0 set pmt grabber pmt:B5 sid:1007
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
    [2013-09-08 21:29:07,721] [Log ] [scheduler thread] [DEBUG] - WaitForPMT: Waiting for PMT B5
    [2013-09-08 21:29:07,971] [Log ] [3 ] [INFO ] - subch:0 OnPMTReceived() pmt:B5 ran:True dynamic:False
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [DEBUG] - WaitForPMT: Found PMT after 0,2500509 seconds.
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 SendPmt:1007 1007 FFFFFFFF 2
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - Decode pmt
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - descr1 len:6 9 4 b 0 fd aa
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - descr2 pid:431 len:6 9 4 b 0 fd aa
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - Set descriptor data with length 6
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - descr2 pid:BFB len:6 9 4 b 0 fd aa
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - Set descriptor data with length 7
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 SendPMT version:2 len:67 4103
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [DEBUG] - Digital Devices:--> Setting service id 4103 for decrypting returned 0
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 cam flags:True
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 SetMpegPidMapping
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 pid:431 pcr
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 pid:B5 pmt
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 pid:431 video type:H.264
    [2013-09-08 21:29:07,971] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:431 video type:H.264
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 pid:BFB audio lang:nor type:MPEG-2
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:BFB audio lang:nor type:MPEG-2
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 pid:178E teletext type:6
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 map pid:178E teletext type:6
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 stop tif
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - WaitForPmt: PMT handling took 0,0156262 seconds.
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - card: Tuner locked: True
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - **************************************************
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - ***** SIGNAL LEVEL: 100, SIGNAL QUALITY: 100 *****
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - **************************************************
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - card: tuned user: scheduler263 subchannel: 0
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - user:scheduler263 add
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - Scheduler: MakeFileName() using "moviesformat" (_isSerie=False)
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - Scheduler : record to C:\Users\Public\Recorded TV\Åndenes makt - TV Norge HD - 2013-09-08.ts
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - Controller: epg stop
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [DEBUG] - Recorder.start add audioVideoEventHandler
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - card: StartRecording 3 C:\Users\Public\Recorded TV\Åndenes makt - TV Norge HD - 2013-09-08.ts
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - StartRecording to C:\Users\Public\Recorded TV\Åndenes makt - TV Norge HD - 2013-09-08.ts
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0 StartRecord(C:\Users\Public\Recorded TV\Åndenes makt - TV Norge HD - 2013-09-08.ts)
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - subch:0-0 tswriter StartRecording...
    [2013-09-08 21:29:07,986] [Log ] [scheduler thread] [INFO ] - SetRecorderPids
    [2013-09-08 21:29:08,002] [Log ] [scheduler thread] [INFO ] - Set video / audio observer
    [2013-09-08 21:29:08,018] [Log ] [scheduler thread] [INFO ] - DVB subch:0 Started recording
    [2013-09-08 21:29:08,018] [Log ] [scheduler thread] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
    [2013-09-08 21:29:09,065] [Log ] [3 ] [INFO ] - PID seen - type = Video
    [2013-09-08 21:29:09,065] [Log ] [3 ] [DEBUG] - Recorder audioVideoEventHandler Video
    [2013-09-08 21:29:09,177] [Log ] [3 ] [INFO ] - PID seen - type = Audio
    [2013-09-08 21:29:09,177] [Log ] [3 ] [DEBUG] - Recorder audioVideoEventHandler Audio
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [INFO ] - card: WaitForFile - video and audio are seen after 1,1592707 seconds
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [INFO ] - TimeshiftingEPG: channel TV Norge HD is not configured for grabbing epg
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=238, tuningdetails=DVBC:tv:Canal Digital KTV TV Norge HD Freq:298000 ONID:70 TSID:6 SID:4103 PMT:0xB5 FTA:False LCN:6 SymbolRate:6950 Modulation:Mod256Qam
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [INFO ] - card: SignalTuneEvent card: 3 / subch: 0
    [2013-09-08 21:29:09,177] [Log ] [Channel state thread] [DEBUG] - Controller: DoSetChannelStates for 198 channels
    [2013-09-08 21:29:09,177] [Log ] [Channel state thread] [INFO ] - ChannelStates.DoSetChannelStates took 0 msec
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [DEBUG] - Scheduler: adding new row in db for title="Åndenes makt" of type="0"
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [INFO ] - Scheduler: recList: count: 1 add scheduleid: 263 card: Digital Devices DVB-C Tuner 2
    [2013-09-08 21:29:09,177] [Log ] [scheduler thread] [DEBUG] - CardReservation.CancelCardReservation id=237
    [2013-09-08 21:29:09,620] [Log ] [PowerScheduler poll thread] [DEBUG] - ActiveSharesHandler: Share monitoring is enabled.
    [2013-09-08 21:30:10,728] [Log ] [PowerScheduler poll thread] [DEBUG] - ActiveSharesHandler: Share monitoring is enabled.
    [2013-09-08 21:31:11,752] [Log ] [PowerScheduler poll thread] [DEBUG] - ActiveSharesHandler: Share monitoring is enabled.
    [2013-09-08 21:32:12,797] [Log ] [PowerScheduler poll thread] [DEBUG] - ActiveSharesHandler: Share monitoring is enabled.
    [2013-09-08 21:33:13,805] [Log ] [PowerScheduler poll thread] [DEBUG] - ActiveSharesHandler: Share monitoring is enabled.
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - Scheduler: stop record TV Norge HD 08.09.2013 21:29:09-08.09.2013 22:30:00 Åndenes makt
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - card: StopRecording card=3, user=scheduler263
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - tvdvbchannel.OnStopRecording subch=0, subch index=0
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - tvdvbchannel.OnStopRecording subch:0-0 tswriter StopRecording...
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
    [2013-09-08 22:35:13,753] [Log ] [scheduler thread] [INFO ] - DVB subch:0 Decompose()
    [2013-09-08 22:35:13,768] [Log ] [scheduler thread] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
    [2013-09-08 22:35:13,768] [Log ] [scheduler thread] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
    [2013-09-08 22:35:13,768] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph called
    [2013-09-08 22:35:13,768] [Log ] [scheduler thread] [INFO ] - tvcard:FreeAllSubChannels
    [2013-09-08 22:35:13,768] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [DEBUG] - usermanagement.RemoveUser: scheduler263, subch: 0 of 0, card: 3
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [INFO ] - user:scheduler263 remove
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph called
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [INFO ] - tvcard:FreeAllSubChannels
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [INFO ] - dvb:confused:topGraph filterstate already stopped, returning.
    [2013-09-08 22:35:13,784] [Log ] [scheduler thread] [INFO ] - Controller: epg start


    ...and nothing happened during the recording that could have stopped it.

    I suspect the CAM is stops decrypting the program but right now I'm not sure why. Maybe something to do with your subscription. From other entries in your log file I suspect your CAM is trying to tell you something:
    Have you seen any of these messages?

    mm
     
  4. Doomblaster

    Doomblaster Portal Member

    Joined:
    August 27, 2012
    Messages:
    9
    Likes Received:
    0
    Gender:
    Male
    Ratings:
    +0 / 0
    Home Country:
    Norway Norway
    Well...my subscription is working for sure. As I said, I've been watching TV while this has been happening as well, so it's not like it's stopped working. I haven't seen any of those lines either...not really sure where to look for it either. Got any pointers what this could mean? I'm totally clueless here to be honest.
     
Loading...

Users Viewing Thread (Users: 0, Guests: 0)

  1. This site uses cookies to help personalise content, tailor your experience and to keep you logged in if you register.
    By continuing to use this site, you are consenting to our use of cookies.
    Dismiss Notice
  • About The Project

    The vision of the MediaPortal project is to create a free open source media centre application, which supports all advanced media centre functions, and is accessible to all Windows users.

    In reaching this goal we are working every day to make sure our software is one of the best.

             

  • Support MediaPortal!

    The team works very hard to make sure the community is running the best HTPC-software. We give away MediaPortal for free but hosting and software is not for us.

    Care to support our work with a few bucks? We'd really appreciate it!