Freeze after resume (1 Viewer)

[MariuCh]

MediaPortal Version: 1.2.1
MediaPortal Skin: Blue Wide
Windows Version: Windows 7 64bit
CPU Type: Intel Atom D510
HDD: ST3500418AS
Memory: 2GB
Motherboard: ASUS ET2010PNT
Video Card: NVIDIA ION
Video Card Driver: 88.17.12.8026
Sound Card: IDT High Definition Audio Codec
Sound Card AC3: IDT High Definition Audio Codec
Sound Card Driver: 6.10.6274.0
1. TV Card: - (client only)
1. TV Card Type: -
1. TV Card Driver: -
2. TV Card: -
2. TV Card Type: -
2. TV Card Driver: -
3. TV Card: -
3. TV Card Type: -
3. TV Card Driver: -
4. TV Card: -
4. TV Card Type: -
4. TV Card Driver: -
MPEG2 Video Codec: Cyberlink PDVD11
MPEG2 Audio Codec: LAV Audio Decoder
h.264 Video Codec: Cyberlink PDVD11
Satelite/CableTV Provider: -
HTPC Case: ASUS ET2010PNT
Cooling: build in power supply only
Power Supply: build in
Remote: -
TV: build in
TV - HTPC Connection: buid in

Hi,
my system freeze shortly after resume (S3 hibrid) up to over a minute (the interface does not respond, you see the clock stops). Later works OK.
This computer is a client connected TV service over the network.
The attached logs from the time of freezing.

Regards,
MariuCh

 

[mm1352000]

Hi MariuCh

The reason seems to be that the TV Server database is not available yet. Your delay after sending the WOL command may not be long enough. If you want me to check then you need to supply the TV Server logs as well.

mm

 

[MariuCh]

Hi,
Thank you for your response.
But the problem also occurs when the TV Server is running (no wake), and use it locally installed client.

Regards,
MariuCh

PS.
TV Server logs (if needed) I put in 12 hours.

 

[mm1352000]

Hi again

I'm just reporting what I see in the logs. There are no other obvious errors or delays after the resume from hibernate:

Gentle.Common.GentleException: select idRecording, idChannel, idSchedule, isRecording, startTime, endTime, title, description, genre, fileName, keepUntil, keepUntilDate, timesWatched, idServer, stopTime, episodeName, seriesNum, episodeNum, episodePart from Recording where isRecording = @isRecording; ---> System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)

I don't understand Polish but that sure looks like it is related to the database connection to me. If you can reproduce when the server hasn't gone to sleep and/or from MP installed on the server then it may be helpful to provide logs for that situation too. I still think it would be helpful to see TV Server logs. Anyhow, you can read the full error and my interpretation of what I think is happening here:

[COLLAPSE]2011-10-15 19:23:51.735185 [Debug][MPMain(1)]: TVHome: HeartBeat Transmitter started. (start of connection to TV Server)
2011-10-15 19:23:51.737185 [Info.][MPMain(1)]: TvNotify: start
2011-10-15 19:23:51.739185 [Info.][TvClient-TvHome: HeartBeat transmitter thread(3)]: TVHome: OnRemotingConnected, recovered from a disconnection (start of delay)
2011-10-15 19:24:25.721128 [Info.][MPMain(1)]: Tv NotifyManager: Exception at timer_tick Error: StatementErrorUnclassified (error)
Gentle.Common.GentleException: select idRecording, idChannel, idSchedule, isRecording, startTime, endTime, title, description, genre, fileName, keepUntil, keepUntilDate, timesWatched, idServer, stopTime, episodeName, seriesNum, episodeNum, episodePart from Recording where isRecording = @isRecording; ---> System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)
w System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
w System.Data.SqlClient.TdsParserStateObject.WriteSni()
w System.Data.SqlClient.TdsParserStateObject.WritePacket(Byte flushMode)
w System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
w System.Data.SqlClient.TdsParser.TdsExecuteRPC(_SqlRPC[] rpcArray, Int32 timeout, Boolean inSchema, SqlNotificationRequest notificationRequest, TdsParserStateObject stateObj, Boolean isCommandProc)
w System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
w System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
w System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
w System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr)
--- Koniec śladu stosu wyjątków wewnętrznych ---
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr)
w Gentle.Framework.PersistenceBroker.Execute(SqlStatement stmt, IDbConnection dbConnection, IDbTransaction dbTransaction)
w Gentle.Framework.SqlStatement.Execute()
w TvDatabase.Recording.ListAllActive()
w TvPlugin.TvNotifyManager.AddActiveRecordings()
w TvPlugin.TvNotifyManager.ProcessRecordings(DateTime preNotifySecs)
w TvPlugin.TvNotifyManager._timer_Tick(Object sender, EventArgs e)System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)
w System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
w System.Data.SqlClient.TdsParserStateObject.WriteSni()
w System.Data.SqlClient.TdsParserStateObject.WritePacket(Byte flushMode)
w System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
w System.Data.SqlClient.TdsParser.TdsExecuteRPC(_SqlRPC[] rpcArray, Int32 timeout, Boolean inSchema, SqlNotificationRequest notificationRequest, TdsParserStateObject stateObj, Boolean isCommandProc)
w System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
w System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
w System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
w System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr) st : w System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
w System.Environment.get_StackTrace()
w TvPlugin.TvNotifyManager._timer_Tick(Object sender, EventArgs e)
w System.Windows.Forms.Timer.OnTick(EventArgs e)
w System.Windows.Forms.Timer.TimerNativeWindow.WndProc(Message& m)
w System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
w System.Windows.Forms.UnsafeNativeMethods.DispatchMessageW(MSG& msg)
w System.Windows.Forms.Application.ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(Int32 dwComponentID, Int32 reason, Int32 pvLoopData)
w System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(Int32 reason, ApplicationContext context)
w System.Windows.Forms.Application.ThreadContext.RunMessageLoop(Int32 reason, ApplicationContext context)
w System.Windows.Forms.Application.Run(Form mainForm)
w MediaPortalApp.Main(String[] args)
2011-10-15 19:26:26.187019 [Info.][MPMain(1)]: Main: Exit requested (you close MP)[/COLLAPSE]

mm

 

[MariuCh]

Hi again

I'm just reporting what I see in the logs. There are no other obvious errors or delays after the resume from hibernate:

Gentle.Common.GentleException: select idRecording, idChannel, idSchedule, isRecording, startTime, endTime, title, description, genre, fileName, keepUntil, keepUntilDate, timesWatched, idServer, stopTime, episodeName, seriesNum, episodeNum, episodePart from Recording where isRecording = @isRecording; ---> System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)

mm

Hi
thx again.
1) Descriptions of errors in English:
- "Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera" - Transport-level error occurred while sending the request to the server.
- "provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna" - provider: Named Pipes Provider, error: 0 - The specified network name is no longer available.
2) I've already written (perhaps illegible) that this error also occurs on the client when the TV Server is running - logs are placed precisely in the situation when the TV Server has working and the client has resumed.

Regards,
MariuCh

 

[mm1352000]

Are you using a MySQL or SQL Server database?

 

[MariuCh]

Are you using a MySQL or SQL Server database?

SQL Server

What client is trying to do at a time when I get the error?

 

[MariuCh]

Promised logs from the client and server from the same time. Server had been up earlier, then the client was resuming.

Regards,
MariuCh

 

[MariuCh]

I made a test (TV Server on another computer still on):
- MediaPortal turned off on the client
- connected the a network resource on the client computer from TV Server's computer
- going sleep a client computer
- resuming client computer - making sure that from the beginning is available connected network resource
As a result, network resource has been available without any problems. In the same way running MediaPortal generates the above-described problem.

ANY IDEAS?

Regards,
MariuCh

 

[mm1352000]

Hi again

The logs that you provided show that the TV Server machine was asleep:

2011-10-16 23:10:08.208870 [PowerEventThread(8)]: dvbtopGraph
2011-10-16 23:10:08.211870 [PowerEventThread(8)]: Stopcard
2011-10-16 23:10:08.212870 [PowerEventThread(8)]: Stopcard
2011-10-16 23:10:08.213870 [PowerEventThread(8)]: dvbtopGraph called
2011-10-16 23:10:08.214870 [PowerEventThread(8)]: tvcard:FreeAllSubChannels
2011-10-16 23:10:08.214870 [PowerEventThread(8)]: Stopcard
2011-10-16 23:10:08.216870 [PowerEventThread(8)]: tvcard:FreeAllSubChannels
2011-10-16 23:10:08.217870 [PowerEventThread(8)]: PowerScheduler: System is going to suspend
2011-10-16 23:10:08.218870 [PowerEventThread(8)]: Controller: epg stop
2011-10-17 18:32:41.507000 [PowerEventThread(8)]: TV service PowerEventThread 30
2011-10-17 18:32:41.507000 [PowerEventThread(8)]: TV service PowerEventThread 30
2011-10-17 18:32:50.784531 [(5)]: DiskManagement: checking free disk space
2011-10-17 18:32:50.785531 [(31)]: DiskManagement: checking free disk space
2011-10-17 18:32:50.786531 [(4)]: DiskManagement: checking free disk space
2011-10-17 18:32:50.787531 [PowerEventThread(8)]: OnPowerEvent: PowerStatus: ResumeAutomatic
2011-10-17 18:32:50.787531 [PowerEventThread(8)]: OnPowerEventHandler: PowerStatus: ResumeAutomatic
2011-10-17 18:32:50.788531 [PowerEventThread(8)]: TvController.OnResume()
2011-10-17 18:32:50.788531 [PowerEventThread(8)]: Controller: setup HeartBeat Monitor
2011-10-17 18:32:50.791531 [HeartBeatMonitor(11)]: Controller: Heartbeat Monitor initiated, max timeout allowed is 30 sec.
2011-10-17 18:32:50.792531 [PowerEventThread(8)]: Scheduler: started
2011-10-17 18:32:50.801532 [PowerEventThread(8)]: Scheduler: loaded 0 schedules
2011-10-17 18:32:50.801532 [PowerEventThread(8)]: Scheduler: thread started.
2011-10-17 18:32:50.802532 [PowerEventThread(8)]: DiskManagement: started
2011-10-17 18:32:50.803532 [PowerEventThread(8)]: PowerScheduler: System has resumed from standby
2011-10-17 18:32:50.806532 [PowerEventThread(8)]: Controller: epg start
2011-10-17 18:32:50.825533 [PowerEventThread(8)]: OnPowerEvent: PowerStatus: ResumeSuspend
2011-10-17 18:32:50.826533 [PowerEventThread(8)]: OnPowerEventHandler: PowerStatus: ResumeSuspend

Note that the wake up time for the server matches the wake up time on the client:

2011-10-17 18:33:25.066004 [Info.][MPMain(1)]: Main: OnResume - set GUIGraphicsContext.State.RUNNING
2011-10-17 18:33:25.067004 [Info.][MPMain(1)]: Main: OnResume - Done
2011-10-17 18:33:59.194956 [Info.][MPMain(1)]: Tv NotifyManager: Exception at timer_tick Error: StatementErrorUnclassified
Gentle.Common.GentleException: select idRecording, idChannel, idSchedule, isRecording, startTime, endTime, title, description, genre, fileName, keepUntil, keepUntilDate, timesWatched, idServer, stopTime, episodeName, seriesNum, episodeNum, episodePart from Recording where isRecording = @isRecording; ---> System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)
w System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
w System.Data.SqlClient.TdsParserStateObject.WriteSni()
w System.Data.SqlClient.TdsParserStateObject.WritePacket(Byte flushMode)
w System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
w System.Data.SqlClient.TdsParser.TdsExecuteRPC(_SqlRPC[] rpcArray, Int32 timeout, Boolean inSchema, SqlNotificationRequest notificationRequest, TdsParserStateObject stateObj, Boolean isCommandProc)
w System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
w System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
w System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
w System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr)
--- Koniec śladu stosu wyjątków wewnętrznych ---
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr)
w Gentle.Framework.PersistenceBroker.Execute(SqlStatement stmt, IDbConnection dbConnection, IDbTransaction dbTransaction)
w Gentle.Framework.SqlStatement.Execute()
w TvDatabase.Recording.ListAllActive()
w TvPlugin.TvNotifyManager.AddActiveRecordings()
w TvPlugin.TvNotifyManager.ProcessRecordings(DateTime preNotifySecs)
w TvPlugin.TvNotifyManager._timer_Tick(Object sender, EventArgs e)System.Data.SqlClient.SqlException: Wystąpił błąd poziomu transportu podczas wysyłania żądania do serwera. (provider: Dostawca nazwanych potoków, error: 0 - Określona nazwa sieciowa już jest niedostępna.)
w System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
w System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
w System.Data.SqlClient.TdsParserStateObject.WriteSni()
w System.Data.SqlClient.TdsParserStateObject.WritePacket(Byte flushMode)
w System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
w System.Data.SqlClient.TdsParser.TdsExecuteRPC(_SqlRPC[] rpcArray, Int32 timeout, Boolean inSchema, SqlNotificationRequest notificationRequest, TdsParserStateObject stateObj, Boolean isCommandProc)
w System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
w System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
w System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
w System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
w System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
w Gentle.Framework.SqlStatement.Execute(IDbConnection conn, IDbTransaction tr) st : w System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
w System.Environment.get_StackTrace()
w TvPlugin.TvNotifyManager._timer_Tick(Object sender, EventArgs e)
w System.Windows.Forms.Timer.OnTick(EventArgs e)
w System.Windows.Forms.Timer.TimerNativeWindow.WndProc(Message& m)
w System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
w System.Windows.Forms.UnsafeNativeMethods.DispatchMessageW(MSG& msg)
w System.Windows.Forms.Application.ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(Int32 dwComponentID, Int32 reason, Int32 pvLoopData)
w System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(Int32 reason, ApplicationContext context)
w System.Windows.Forms.Application.ThreadContext.RunMessageLoop(Int32 reason, ApplicationContext context)
w System.Windows.Forms.Application.Run(Form mainForm)
w MediaPortalApp.Main(String[] args)
2011-10-17 18:35:24.487835 [Info.][MPMain(1)]: TVHome:OnPageLoad
2011-10-17 18:35:24.510836 [Info.][MPMain(1)]: ChannelNavigator::Reload()
2011-10-17 18:35:24.517836 [Info.][MPMain(1)]: get channels from database

These logs still do not prove that the problem is not related to the server/database being asleep. You should check the system and application event logs on the TV Server to check when the database server has finished initialising after waking up. Again, if you can reproduce this when you wake the client and the *TV Server is already awake* then that would be helpful... provide the logs.

mm