MP stops recording before it is supposed to (1 Viewer)

Doomblaster

Portal Member
August 27, 2012
9
0
41
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.
 

mm1352000

Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    Hello Doomblaster

    From TV Server's perspective, it recorded the full program:
    [collapse]
    [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[/collapse]

    ...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:
    [2013-09-04 03:33:03,978] [Log ] [Digital Devices CiMenuHandler] [DEBUG] - Menu received (ID 2 Type 2 Choices 2)
    Have you seen any of these messages?

    mm
     

    Doomblaster

    Portal Member
    August 27, 2012
    9
    0
    41
    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.
     

    Users Who Are Viewing This Thread (Users: 0, Guests: 1)

    OP Similar threads Forum Replies Date
    D wintv doesn’t stop recording on time Newcomers Forum 1
    M MP 2.2.3 Unable to play .ts recordings and MediaPortal stops working for TV viewing General 31
    W Recordings will not stop General Support 8
    R [solved] Watching a record during recording stops sometimes 2.2 Archive 30
    N [confirm] Calling RemoveScheduleForProgramAsync does not stop the recording if it is currently in progress MediaPortal 2 1
    N [confirm] Playing a recording, then pressing stop does not leave cursor on the recording MediaPortal 2 21
    D Skip to end/live during dvbip recording causes it to stop playing instead. General Support 15
    C [solved] how to stop recording? General 3
    toricred Using TMM, How to Stop Importer From Going to The Movie Database for Data General 1
    mickb [solved] Mediaportal Stops working General Support 5
    D [solved] Movie artwork download stopped working Submit: Bug Reports 9
    ajs [solved] 4982: Why this error hard stop when Mediaportal start? MediaPortal 1 3
    rsbrux IR has stopped working Remotes 4
    2BitSculptor MP 1.23.. music stops playing General Support 6
    M MP1 stops responding after Starting Plugins General Support 14
    fredco [solved] Large import not working Moving Pictures 15
    S [solved] Live TV playing stopped General 13
    N [will not fix] Changed settings do not take effect until MP2-Client is stopped and restarted. Submit: Bug Reports 4
    Glith Sound stops working after first playback 1.21 88
    Patrik-See [solved] MediaPortal 2.2 Fernseher bleibt schwarz nach TV Sender Stop Allgemeines Support- und Diskussionsforum 2
    B Server service on the service monitor keeps stopping randomly. Client can't see server status. 2.2 Archive 5
    A TV playback intermittently stops on clients Television (MyTV frontend and TV-Server) 4
    M Scan channels stopped working on Windows 10 Installation, configuration support 1
    Alberto83 [no Bug] Watched status not retained when rewatching an episode and stopping. Archive 49
    M Music playback stops after certain files 1.19 0
    Similar threads

























    Top Bottom