TV Server crashed - why? (1 Viewer)

[c 4]

Hi everyone,

when I checked my recordings from the last 2 weekends, I noticed that TVServer was not running. From the missed recordings, the first time it (presumably) crashed was before the 20th then I restarted the HTPC and everything worked until last week, 26th of November - it just recorded 1 second, then stopped.
I am still running 1.5.0 Pre with these patches by mm1352000 on the HTPC:
- TsWriter_mm_deadlock_v6_[mp_1.5pr].zip [containing TVLibrary.dll, TvService.exe] from https://forum.team-mediaportal.com/...ock-potential-fix.114898/page-22#post-1027148
- TsWriter_mm_deadlock_v5_[mp_1.5pr].zip [containing TsWriter.ax] from https://forum.team-mediaportal.com/...ock-potential-fix.114898/page-21#post-1026741 - worked quite well otherwise.

Please have a look at my logs and tell me what is going on.

[attachment removed]

 

[mm1352000]

Looks like a failure to communicate with the database:

[2013-11-26 07:12:54,778] [Log ] [14 ] [INFO ] - Tvservice stopped due to an unhandled app domain exception System.NullReferenceException: Der Objektverweis wurde nicht auf eine Objektinstanz festgelegt.
bei MySql.Data.MySqlClient.MySqlCommand.TimeoutExpired(Object commandObject)
bei System.Threading._TimerCallback.TimerCallback_Context(Object state)
bei System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
bei System.Threading._TimerCallback.PerformTimerCallback(Object state)

 

[c 4]

Nobody touched the HTPC during the respective weeks, it was offline so there were no updates. The problem occurred mid-week - it worked fine from Sunday to Tuesday or Wednesday and then, without user interference, decided to malfunction. So I would consider this a bug, but I don't know if something similar has already been reported.

 

[mm1352000]

I haven't seen any similar reports.
If it is a bug I think it is going to be really hard to track down. An unhandled app domain exception basically means that the exception was caught on the "last line of defence". All we could do is stop the TV service cleanly. Right now I have no idea where the exception is coming from... except that I can see the "MySql.Data.MySqlClient.MySqlCommand" so I know that this is something to do with the database or database access layer (gentle). I find it interesting that in both cases the exception is shortly after resume and that it looks like the service was not suspended cleanly. For example:
[collapse]
[2013-11-26 03:18:42,446] [Log ] [PowerEventThread] [DEBUG] - OnPowerEvent: PowerStatus: Suspend
[2013-11-26 03:18:42,446] [Log ] [PowerEventThread] [DEBUG] - OnPowerEventHandler: PowerStatus: Suspend
[2013-11-26 03:18:42,446] [Log ] [PowerEventThread] [INFO ] - TvController.OnSuspend()
[2013-11-26 03:18:42,477] [Log ] [PowerEventThread] [INFO ] - Scheduler: stopped
[2013-11-26 03:18:43,569] [Log ] [PowerEventThread] [DEBUG] - Scheduler: thread stopped.
[2013-11-26 03:18:45,051] [Log ] [PowerEventThread] [INFO ] - Stopcard
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [INFO ] - Stopcard
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [INFO ] - dvbtopGraph called
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeAllSubChannels
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [INFO ] - dvbtopGraph filterstate already stopped, returning.
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: SUSPEND
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: System is going to suspend
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: Signal "Suspend" to StandbyWakeupThread
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: Stop EPG grabbing and TV controller
[2013-11-26 03:18:45,067] [Log ] [PS StandbyWakeup] [DEBUG] - PS: StandbyWakeupThread suspended
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [INFO ] - Controller: epg stop
[2013-11-26 03:18:45,067] [EPG ] [PowerEventThread] [INFO ] - EPG: grabber stopped..
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: Run external command
[2013-11-26 03:18:45,067] [Log ] [PowerEventThread] [DEBUG] - PS: Send "EnteringStandby" event
[2013-11-26 03:18:45,878] [Log ] [22 ] [DEBUG] - PS: RegisterRemote tag: 4, uris: http://localhost:31458/2bb1f42b_4c7b_45aa_901a_6f5f2377f0fb/bjw9uy1t0grbopql5q9x0tlp_1.rem, http://localhost:31458/2bb1f42b_4c7b_45aa_901a_6f5f2377f0fb/bjw9uy1t0grbopql5q9x0tlp_1.rem
[2013-11-26 03:18:46,845] [Log ] [7 ] [DEBUG] - PS: UnregisterRemote StandbyHandler 4
[2013-11-26 03:18:46,845] [Log ] [7 ] [DEBUG] - PS: UnregisterRemote WakeupHandler 4
[2013-11-26 03:18:57,406] [EPG ] [EPG Update thread] [INFO ] - - Inserted 1269 epg entries for channel SWR2
[2013-11-26 03:18:57,406] [EPG ] [EPG Update thread] [INFO ] - TimeshiftingEpgGrabber: SWR3 lastUpdate:25.11.2013 23:06:21
[2013-11-26 03:18:58,452] [EPG ] [EPG Update thread] [INFO ] - - Inserted 211 epg entries for channel SWR3
[2013-11-26 03:18:58,452] [EPG ] [EPG Update thread] [INFO ] - TimeshiftingEpgGrabber: SWR4 BW lastUpdate:25.11.2013 23:06:21
[2013-11-26 03:19:00,136] [EPG ] [EPG Update thread] [INFO ] - - Inserted 283 epg entries for channel SWR4 BW
[2013-11-26 03:19:00,136] [EPG ] [EPG Update thread] [INFO ] - TimeshiftingEpgGrabber: SWR4 RP lastUpdate:25.11.2013 23:06:21
[2013-11-26 03:19:01,416] [EPG ] [EPG Update thread] [INFO ] - - Inserted 230 epg entries for channel SWR4 RP
[2013-11-26 03:19:01,431] [EPG ] [EPG Update thread] [INFO ] - TimeshiftingEpgGrabber: DASDING lastUpdate:25.11.2013 23:06:21
[2013-11-26 03:19:02,476] [EPG ] [EPG Update thread] [INFO ] - - Inserted 211 epg entries for channel DASDING
[2013-11-26 03:19:02,476] [EPG ] [EPG Update thread] [INFO ] - TimeshiftingEpgGrabber: SWRinfo lastUpdate:25.11.2013 23:06:21
[2013-11-26 03:19:06,314] [Log ] [21 ] [DEBUG] - Detecting BDA/WDM devices...
[2013-11-26 03:19:06,314] [Log ] [21 ] [DEBUG] - Detect legacy AM filter devices
[2013-11-26 03:19:06,330] [Log ] [21 ] [DEBUG] - Detect AM KS crossbar devices
[2013-11-26 03:19:06,330] [Log ] [21 ] [DEBUG] - Detect AM KS TV tuner devices
[2013-11-26 03:19:06,330] [Log ] [21 ] [DEBUG] - Detect BDA source devices
[2013-11-26 07:12:43,531] [Log ] [PowerEventThread] [DEBUG] - TV service PowerEventThread 30
[2013-11-26 07:12:43,812] [Log ] [PowerEventThread] [DEBUG] - TV service PowerEventThread 30
[2013-11-26 07:12:43,952] [Log ] [PowerEventThread] [DEBUG] - OnPowerEvent: PowerStatus: ResumeAutomatic
[2013-11-26 07:12:43,952] [Log ] [PowerEventThread] [DEBUG] - OnPowerEventHandler: PowerStatus: ResumeAutomatic[/collapse]

Notice the "[PowerEventThread] [INFO ] - EPG: grabber stopped.." entry, which suggests PS is trying to or thinks it has stopped the EPG grabber... and yet there are entries from the EPG update thread after that. Even stranger: it is the timeshifting EPG grabber. I have no idea where that is coming from.

Tag to @michael_t - any ideas?

 

[michael_t]

I have seen this database exception pattern before - but I cannot remember when (must be at least one year ago) and where it came from. I will try to find it, but I cannot promise it...

Michael