Scheduled Recordings Failed (MP 1.22) (1 Viewer)

joecrow

Test Group
  • Team MediaPortal
  • August 9, 2012
    2,528
    1,878
    Home Country
    Germany Germany
    This evening I scheduled 2 recordings from the EPG but neither worked:(. Following a restart of MP I tried to record a currently running program and that failed also. All three programs remain in the Recording Schedule, see attached screenshot. At the time recordings should have started MP was up and running and I was viewing content in Online Videos not TV. After rebooting and restarting MP1 a recording for the currently running program that I had sceduled started and ran OK and recording worked perfectly yesterday (Sunday) evening. Please can someone take a look at the attached log and let me know if there is any clue to how to fix this problem.
    rec1.jpg
     

    Attachments

    • MediaPortalLogs_29_04_19__23_46.zip
      938.6 KB

    Owlsroost

    Retired Team Member
  • Premium Supporter
  • October 28, 2008
    5,540
    5,038
    Cambridge
    Home Country
    United Kingdom United Kingdom
    Which date is 'This evening' and when were the recordings scheduled to run?

    (the earliest date/time in any of the TV server logs is '[2019-04-28 18:39:41,553]' which is early Sunday evening)
     

    joecrow

    Test Group
  • Team MediaPortal
  • August 9, 2012
    2,528
    1,878
    Home Country
    Germany Germany
    Which date is 'This evening' and when were the recordings scheduled to run?

    That was Monday the 29th as shown on the screenshot.
    This is not the first time I have had this problem recently, much the same happened 7-10 days ago (on that occasion it was sleeping and did not wake up and once awake recordings did not work as per the OP) not sure though whether it was MP 1.21f or 1.22pre but reboot fixed it and I put it down to a once off.

    (the earliest date/time in any of the TV server logs is '[2019-04-28 18:39:41,553]' which is early Sunday evening
    That could have been the last successful recording for a program on ARD starting at 20:15.
     

    Owlsroost

    Retired Team Member
  • Premium Supporter
  • October 28, 2008
    5,540
    5,038
    Cambridge
    Home Country
    United Kingdom United Kingdom
    It looks like setting up these schedules (from MediaPortal.log):

    Code:
    [2019-04-29 16:59:23,916] [Log    ] [MPMain   ] [INFO ] - GetConflictingSchedules: Schedule = Sanft schläft der Tod on 69 29.04.2019 20:15:00 - 29.04.2019 22:25:00  ID=0
    [2019-04-29 16:59:23,919] [Log    ] [MPMain   ] [INFO ] - GetConflictingSchedules: Cards.Count = 6
    [2019-04-29 16:59:23,989] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: schedule = Sanft schläft der Tod on 69 29.04.2019 20:15:00 - 29.04.2019 22:25:00  ID=0
    [2019-04-29 16:59:24,067] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: free on card 0, ID = 4
    .....
    [2019-04-29 16:59:29,666] [Log    ] [MPMain   ] [INFO ] - GetConflictingSchedules: Schedule = Nord Nord Mord on 74 29.04.2019 20:15:00 - 29.04.2019 21:45:00  ID=0
    [2019-04-29 16:59:29,668] [Log    ] [MPMain   ] [INFO ] - GetConflictingSchedules: Cards.Count = 6
    [2019-04-29 16:59:29,671] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: schedule = Sanft schläft der Tod on 69 29.04.2019 20:15:00 - 29.04.2019 22:25:00  ID=2
    [2019-04-29 16:59:29,673] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: free on card 0, ID = 4
    [2019-04-29 16:59:29,674] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: schedule = Nord Nord Mord on 74 29.04.2019 20:15:00 - 29.04.2019 21:45:00  ID=0
    [2019-04-29 16:59:29,676] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: card 0, ID = 4 has schedule = Sanft schläft der Tod on 69 29.04.2019 20:15:00 - 29.04.2019 22:25:00  ID=2
    [2019-04-29 16:59:29,683] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: overlapping with Sanft schläft der Tod on 69 29.04.2019 20:15:00 - 29.04.2019 22:25:00  ID=2 on card 0, ID = 4
    [2019-04-29 16:59:29,685] [Log    ] [MPMain   ] [INFO ] - AssignSchedulesToCard: free on card 1, ID = 5

    Caused exception errors in TV Server:

    Code:
    [2019-04-29 16:59:24,104] [Log    ] [29       ] [ERROR] - Exception   :System.ObjectDisposedException: Safe handle has been closed
       at System.Runtime.InteropServices.SafeHandle.DangerousAddRef(Boolean& success)
       at System.StubHelpers.StubHelpers.SafeHandleAddRef(SafeHandle pHandle, Boolean& success)
       at Microsoft.Win32.Win32Native.SetEvent(SafeWaitHandle handle)
       at System.Threading.EventWaitHandle.Set()
       at TvService.TVController.OnNewSchedule()
    
    [2019-04-29 16:59:29,694] [Log    ] [29       ] [ERROR] - Exception   :System.ObjectDisposedException: Safe handle has been closed
       at System.Runtime.InteropServices.SafeHandle.DangerousAddRef(Boolean& success)
       at System.StubHelpers.StubHelpers.SafeHandleAddRef(SafeHandle pHandle, Boolean& success)
       at Microsoft.Win32.Win32Native.SetEvent(SafeWaitHandle handle)
       at System.Threading.EventWaitHandle.Set()
       at TvService.TVController.OnNewSchedule()

    ...so I assume the schedules didn't get added correctly because of the exception errors.
     

    joecrow

    Test Group
  • Team MediaPortal
  • August 9, 2012
    2,528
    1,878
    Home Country
    Germany Germany
    Caused exception errors in TV Server:

    Any idea what could have caused these errors, tuner hardware/driver??? I have not knowingly changed anything there but will check if MS has installed any new drivers/updates round this area recently.:unsure:
     

    joecrow

    Test Group
  • Team MediaPortal
  • August 9, 2012
    2,528
    1,878
    Home Country
    Germany Germany
    Further to the above the currently installed TBS tuner driver is the latest and has been in place since April 2018. Also given that with the problem present, Live TV was still working it seems unlikely that was the problem.:confused:
    Recordings scheduled for yesterday evening completed OK.
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    I wondered if it might have been related to this earlier exception:
    [collapse]
    [2019-04-28 22:18:59,012] [Log ] [PS StandbyWakeup] [INFO ] - Tvservice stopped due to an unhandled app domain exception Error: DatabaseUnavailableUnclassified
    Gentle.Common.GentleException: The database backend (provider MySQL) could not be reached.
    Check the connection string: Server=NEWCORWIN;Database=MpTvDb;User ID=root;Password=MediaPortal;charset=utf8;Connection Timeout=30; ---> MySql.Data.MySqlClient.MySqlException: Unable to connect to any of the specified MySQL hosts. ---> System.Exception: Exception of type 'System.Exception' was thrown.
    at MySql.Data.MySqlClient.NativeDriver.Open()
    --- End of inner exception stack trace ---
    at MySql.Data.MySqlClient.NativeDriver.Open()
    at MySql.Data.MySqlClient.Driver.Create(MySqlConnectionStringBuilder settings)
    at MySql.Data.MySqlClient.MySqlPool.CheckoutConnection()
    at MySql.Data.MySqlClient.MySqlPool.GetPooledConnection()
    at MySql.Data.MySqlClient.MySqlPool.GetConnection()
    at MySql.Data.MySqlClient.MySqlConnection.Open()
    at Gentle.Provider.MySQL.MySQLProvider.GetConnection()
    --- End of inner exception stack trace ---
    at Gentle.Common.Check.FailWith(Severity severity, Error error, Exception e, String msg)
    at Gentle.Common.Check.Fail(Exception e, Error error, Object[] args)
    at Gentle.Provider.MySQL.MySQLProvider.GetConnection()
    at Gentle.Framework.PersistenceBroker.Execute(SqlStatement stmt, IDbConnection dbConnection, IDbTransaction dbTransaction)
    at TvDatabase.TvBusinessLayer.GetSetting(String tagName, String defaultValue)
    at TvEngine.PowerScheduler.PowerScheduler.LoadSettings()
    at TvEngine.PowerScheduler.PowerScheduler.StandbyWakeupThread()
    at System.Threading.ThreadHelper.ThreadStart_Context(Object state)
    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
    at System.Threading.ThreadHelper.ThreadStart()MySql.Data.MySqlClient.MySqlException (0x80004005): Unable to connect to any of the specified MySQL hosts. ---> System.Exception: Exception of type 'System.Exception' was thrown.
    at MySql.Data.MySqlClient.NativeDriver.Open()
    at MySql.Data.MySqlClient.NativeDriver.Open()
    at MySql.Data.MySqlClient.Driver.Create(MySqlConnectionStringBuilder settings)
    at MySql.Data.MySqlClient.MySqlPool.CheckoutConnection()
    at MySql.Data.MySqlClient.MySqlPool.GetPooledConnection()
    at MySql.Data.MySqlClient.MySqlPool.GetConnection()
    at MySql.Data.MySqlClient.MySqlConnection.Open()
    at Gentle.Provider.MySQL.MySQLProvider.GetConnection()System.Exception: Exception of type 'System.Exception' was thrown.
    at MySql.Data.MySqlClient.NativeDriver.Open()[/collapse]

    Further to the above the currently installed TBS tuner driver is the latest and has been in place since April 2018.
    Whatever the case, the problem is certainly nothing to do with the tuner drivers.

    Also given that with the problem present, Live TV was still working it seems unlikely that was the problem.:confused:
    Database problems can cause weird symptoms. Your observation is not inconsistent with a zombied TV service.
     

    Owlsroost

    Retired Team Member
  • Premium Supporter
  • October 28, 2008
    5,540
    5,038
    Cambridge
    Home Country
    United Kingdom United Kingdom
    Maybe excluding all the database related stuff in Program Files and ProgramData (i.e. MySQL and its database files) from realtime virus scanning might help, in case that is causing delays in database availability after resume from sleep etc.
     

    joecrow

    Test Group
  • Team MediaPortal
  • August 9, 2012
    2,528
    1,878
    Home Country
    Germany Germany
    Maybe excluding all the database related stuff in Program Files and ProgramData (i.e. MySQL and its database files) from realtime virus scanning might help, in case that is causing delays in database availability after resume from sleep etc.

    Will do, just have Windows Defender on my HTPC and MP1 folders are already excluded. This evening when I woke it up from sleep it was not connected to the TV Server, no TV, EPG etc, restarting MP fixed it and recordings are working, different but perhaps not unrelated. Log is attached, incident occurred aprox. 19:00. 1-May.

    @Owlsroost @mm135200 In the event the problem continues do you think a complete MP and MySql uninstall with folder delete and MP 1.22 new install with settings etc. restored from MP Backup could be helpful?
     
    Last edited:

    Users who are viewing this thread

    Top Bottom