MP froze when recording starts (1 Viewer)

[Mikeyy]

MediaPortal Version: 1.1
MediaPortal Skin: BlackGlass Nova 1.2
Windows Version: Windows 7 Ultimate 32bit
CPU Type: AMD Athlon X2 4200+
HDD: WD 640GB
Memory: 4x512MB (2GB)
Motherboard: ASUS A8N5X
Video Card: ATI SAPPHIRE 4670
Video Card Driver: 9.12
Sound Card: Creative Audigy 4
Sound Card AC3:
Sound Card Driver:
1. TV Card: Terratec 1400 DVB-T
1. TV Card Type: DVB-T
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:
MPEG2 Audio Codec:
h.264 Video Codec:
Satelite/CableTV Provider:
HTPC Case: Silverstone 10M
Cooling:
Power Supply:
Remote: iMON
TV:
TV - HTPC Connection: HDMI 1.3


Attached existing logs, did not reproduce it in debug mode.
Problem is that MP frozes, usualy when recording starts. Sometimes it continue to work again, but that is rare. Usually I have to close MP and start again.
Today it froze without recording starting so I took logs and posted, will try to reproduce bugs and post logs.

Test it with outdated skin BlackGlass Nova 1.2, but same happened with also in RC3-4-5-6 for which this skin was good.

 

[Mikeyy]

Here are logs of freezing after recording had woke up computer from sleep.
Screen was frozen on 10:06 (probably time when htpc went to sleep), recording start at 10:20 -10min (10:10).
This is all on homescreen, but happens in any other screen also.

Only way to defroze it is to close aplication and start again. Luckly recording isn't affected since it's another process.

 

[jameson_uk]

Do you have powerscheduler plugin enabled on both TV server and MP itself? and do both have the same values?

From logs you have

Spoiler

2010-07-27 10:06:22.895507 [Info.][MPMain(1)]: Main: WM_POWERBROADCAST: 4
2010-07-27 10:06:22.895507 [Info.][MPMain(1)]: Main: Windows is suspending
2010-07-27 10:06:22.897460 [Info.][MPMain(1)]: Main: Stopping playback
2010-07-27 10:06:22.899414 [Debug][MPMain(1)]: Main: SaveLastActiveModule - enabled False
2010-07-27 10:06:22.902343 [Info.][MPMain(1)]: Main: Stopping AutoPlay
2010-07-27 10:06:22.906250 [Info.][MPMain(1)]: open folderdatabase
2010-07-27 10:06:22.911132 [Info.][MPMain(1)]: picture database opened
2010-07-27 10:06:22.913085 [Info.][MPMain(1)]: Main: OnSuspend - Done
2010-07-27 10:06:22.913085 [Info.][MPMain(1)]: TVHome.WndProc(): Windows is suspending
2010-07-27 10:06:22.914062 [Debug][MPMain(1)]: TVHome.OnSuspend()
2010-07-27 10:06:22.919921 [Info.][MPMain(1)]: TvNotify: stop
2010-07-27 10:06:22.920898 [Debug][MPMain(1)]: TVHome: HeartBeat Transmitter stopped.
2010-07-27 10:06:33.034179 [Info.][MPMain(1)]: SQLiteClient: Closing database: FanartHandler.db3

but then machine wakes again and you get

Spoiler

2010-07-27 10:06:33.034179 [Info.][MPMain(1)]: SQLiteClient: Closing database: FanartHandler.db3
2010-07-27 10:08:04.201171 [Info.][MPMain(1)]: Main: WM_POWERBROADCAST: 18
2010-07-27 10:08:04.202148 [Info.][MPMain(1)]: Main: Windows has resumed from standby or hibernate mode to handle a requested event
2010-07-27 10:08:04.204101 [Debug][MPMain(1)]: Main: OnResumeAutomatic - set lock for syncronous inits
2010-07-27 10:08:04.205078 [Info.][MPMain(1)]: Main: OnResumeAutomatic - Done
2010-07-27 10:55:25.581054 [Debug][MPMain(1)]: GUIFont:texture disposing:0 debug
2010-07-27 10:55:25.583007 [Debug][MPMain(1)]: GUIFont:texture disposing:1 font9
2010-07-27 10:55:25.583007 [Debug][MPMain(1)]: GUIFont:texture disposing:2 font10
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:3 font11
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:4 font12
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:5 font13
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:6 font14
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:7 font16
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:8 font18
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:9 font20
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:10 font22
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:11 font24
2010-07-27 10:55:25.586914 [Debug][MPMain(1)]: GUIFont:texture disposing:12 font28
2010-07-27 10:55:25.586914 [Debug][MPMain(1)]: GUIFont:texture disposing:13 font32
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:14 font40
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:15 dingbats
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:16 fontSVT
2010-07-27 10:55:25.590820 [Info.][MPMain(1)]: TexturePacker: disposing texture:1999
2010-07-27 10:55:25.805664 [Info.][MPMain(1)]: TexturePacker: disposing texture:1998
2010-07-27 10:55:25.823242 [Info.][MPMain(1)]: TexturePacker: disposing texture:1997
2010-07-27 10:55:25.826171 [Info.][MPMain(1)]: TexturePacker: disposing texture:1970
2010-07-27 10:55:25.853515 [Info.][MPMain(1)]: TvNotify: stop
2010-07-27 10:55:25.854492 [Debug][MPMain(1)]: Main: SaveLastActiveModule - enabled False
2010-07-27 10:55:25.855468 [Info.][MPMain(1)]: Main: Exiting
2010-07-27 10:55:25.855468 [Info.][MPMain(1)]: Remotes: Stop was called without Init - exiting
2010-07-27 10:55:25.856445 [Info.][MPMain(1)]: PlugInManager.Stop()
2010-07-27 10:55:25.856445 [Info.][MPMain(1)]: PluginManager: stopping FanartHandler.FanartHandlerSetup
2010-07-27 10:55:35.857421 [Info.][MPMain(1)]: PluginManager: stopping MediaPortal.Audioscrobbler.AudioscrobblerPlugin
2010-07-27 10:55:35.862304 [Info.][MPMain(1)]: PluginManager: stopping ProcessPlugins.ShortCuter.ShortCuter
2010-07-27 10:55:35.863281 [Info.][MPMain(1)]: ShortCut'er plugin disabled
2010-07-27 10:55:35.863281 [Info.][MPMain(1)]: fonts.SafeDispose()
2010-07-27 10:55:35.864257 [Debug][MPMain(1)]: TextureManager: Dispose()
2010-07-27 10:55:35.865234 [Info.][MPMain(1)]: TexturePackerispose()
2010-07-27 10:55:35.866210 [Debug][MPMain(1)]: Windowmanager: closing current window
2010-07-27 10:55:35.867187 [Debug][MPMain(1)]: Window: WindowPlugins.home.GUIBasicHome deinit
2010-07-27 10:55:35.871093 [Debug][MPMain(1)]: TextureManager: CleanupThumbs()
2010-07-27 10:55:36.159179 [Info.][(2)]: SQLiteClient: Closing database: PictureDatabase.db3
2010-07-27 10:55:36.159179 [Info.][(2)]: SQLiteClient: Closing database: FolderDatabase3.db3
2010-07-27 10:55:36.164062 [Info.][(2)]: TvCropManager: Stopped
2010-07-27 10:55:36.164062 [Info.][(2)]: SQLiteClient: Closing database: TVSeriesDatabase4.db3
2010-07-27 10:55:36.167968 [Info.][(2)]: SQLiteClient: Closing database: movingpictures.db3
2010-07-27 10:55:36.170898 [Info.][(2)]: Playlist: Saving default playlist default.m3u
2010-07-27 10:55:36.171875 [Info.][(2)]: SQLiteClient: Closing database: MusicDatabaseV11.db3
2010-07-27 10:55:36.175781 [Info.][(2)]: SQLiteClient: Closing database: VideoDatabaseV5.db3

So machine appears to have gone to sleep at 10:06 but MP was not actually closed down properly. Machine then woke up at 10:08 and at 10:55 it started closing down properly. There is nothing between 10:08 and 10:55, what happened during this time??

Also you have lots and lots of plugins installed. Other than checking powerscheduler settings you really need to try and replicate this without all those plugins enabled.

 

[Mikeyy]

Do you have powerscheduler plugin enabled on both TV server and MP itself? and do both have the same values?

From logs you have

Spoiler

2010-07-27 10:06:22.895507 [Info.][MPMain(1)]: Main: WM_POWERBROADCAST: 4
2010-07-27 10:06:22.895507 [Info.][MPMain(1)]: Main: Windows is suspending
2010-07-27 10:06:22.897460 [Info.][MPMain(1)]: Main: Stopping playback
2010-07-27 10:06:22.899414 [Debug][MPMain(1)]: Main: SaveLastActiveModule - enabled False
2010-07-27 10:06:22.902343 [Info.][MPMain(1)]: Main: Stopping AutoPlay
2010-07-27 10:06:22.906250 [Info.][MPMain(1)]: open folderdatabase
2010-07-27 10:06:22.911132 [Info.][MPMain(1)]: picture database opened
2010-07-27 10:06:22.913085 [Info.][MPMain(1)]: Main: OnSuspend - Done
2010-07-27 10:06:22.913085 [Info.][MPMain(1)]: TVHome.WndProc(): Windows is suspending
2010-07-27 10:06:22.914062 [Debug][MPMain(1)]: TVHome.OnSuspend()
2010-07-27 10:06:22.919921 [Info.][MPMain(1)]: TvNotify: stop
2010-07-27 10:06:22.920898 [Debug][MPMain(1)]: TVHome: HeartBeat Transmitter stopped.
2010-07-27 10:06:33.034179 [Info.][MPMain(1)]: SQLiteClient: Closing database: FanartHandler.db3

Nope, only in TV server, plugin Power Scheduler. I have it enbled since I though MP will not wake up HTPC to record without it. If MP will wake HTPC up for recording without that plugin I can turn it off.

but then machine wakes again and you get

Spoiler

2010-07-27 10:06:33.034179 [Info.][MPMain(1)]: SQLiteClient: Closing database: FanartHandler.db3
2010-07-27 10:08:04.201171 [Info.][MPMain(1)]: Main: WM_POWERBROADCAST: 18
2010-07-27 10:08:04.202148 [Info.][MPMain(1)]: Main: Windows has resumed from standby or hibernate mode to handle a requested event
2010-07-27 10:08:04.204101 [Debug][MPMain(1)]: Main: OnResumeAutomatic - set lock for syncronous inits
2010-07-27 10:08:04.205078 [Info.][MPMain(1)]: Main: OnResumeAutomatic - Done
2010-07-27 10:55:25.581054 [Debug][MPMain(1)]: GUIFont:texture disposing:0 debug
2010-07-27 10:55:25.583007 [Debug][MPMain(1)]: GUIFont:texture disposing:1 font9
2010-07-27 10:55:25.583007 [Debug][MPMain(1)]: GUIFont:texture disposing:2 font10
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:3 font11
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:4 font12
2010-07-27 10:55:25.583984 [Debug][MPMain(1)]: GUIFont:texture disposing:5 font13
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:6 font14
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:7 font16
2010-07-27 10:55:25.584960 [Debug][MPMain(1)]: GUIFont:texture disposing:8 font18
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:9 font20
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:10 font22
2010-07-27 10:55:25.585937 [Debug][MPMain(1)]: GUIFont:texture disposing:11 font24
2010-07-27 10:55:25.586914 [Debug][MPMain(1)]: GUIFont:texture disposing:12 font28
2010-07-27 10:55:25.586914 [Debug][MPMain(1)]: GUIFont:texture disposing:13 font32
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:14 font40
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:15 dingbats
2010-07-27 10:55:25.588867 [Debug][MPMain(1)]: GUIFont:texture disposing:16 fontSVT
2010-07-27 10:55:25.590820 [Info.][MPMain(1)]: TexturePacker: disposing texture:1999
2010-07-27 10:55:25.805664 [Info.][MPMain(1)]: TexturePacker: disposing texture:1998
2010-07-27 10:55:25.823242 [Info.][MPMain(1)]: TexturePacker: disposing texture:1997
2010-07-27 10:55:25.826171 [Info.][MPMain(1)]: TexturePacker: disposing texture:1970
2010-07-27 10:55:25.853515 [Info.][MPMain(1)]: TvNotify: stop
2010-07-27 10:55:25.854492 [Debug][MPMain(1)]: Main: SaveLastActiveModule - enabled False
2010-07-27 10:55:25.855468 [Info.][MPMain(1)]: Main: Exiting
2010-07-27 10:55:25.855468 [Info.][MPMain(1)]: Remotes: Stop was called without Init - exiting
2010-07-27 10:55:25.856445 [Info.][MPMain(1)]: PlugInManager.Stop()
2010-07-27 10:55:25.856445 [Info.][MPMain(1)]: PluginManager: stopping FanartHandler.FanartHandlerSetup
2010-07-27 10:55:35.857421 [Info.][MPMain(1)]: PluginManager: stopping MediaPortal.Audioscrobbler.AudioscrobblerPlugin
2010-07-27 10:55:35.862304 [Info.][MPMain(1)]: PluginManager: stopping ProcessPlugins.ShortCuter.ShortCuter
2010-07-27 10:55:35.863281 [Info.][MPMain(1)]: ShortCut'er plugin disabled
2010-07-27 10:55:35.863281 [Info.][MPMain(1)]: fonts.SafeDispose()
2010-07-27 10:55:35.864257 [Debug][MPMain(1)]: TextureManager: Dispose()
2010-07-27 10:55:35.865234 [Info.][MPMain(1)]: TexturePackerispose()
2010-07-27 10:55:35.866210 [Debug][MPMain(1)]: Windowmanager: closing current window
2010-07-27 10:55:35.867187 [Debug][MPMain(1)]: Window: WindowPlugins.home.GUIBasicHome deinit
2010-07-27 10:55:35.871093 [Debug][MPMain(1)]: TextureManager: CleanupThumbs()
2010-07-27 10:55:36.159179 [Info.][(2)]: SQLiteClient: Closing database: PictureDatabase.db3
2010-07-27 10:55:36.159179 [Info.][(2)]: SQLiteClient: Closing database: FolderDatabase3.db3
2010-07-27 10:55:36.164062 [Info.][(2)]: TvCropManager: Stopped
2010-07-27 10:55:36.164062 [Info.][(2)]: SQLiteClient: Closing database: TVSeriesDatabase4.db3
2010-07-27 10:55:36.167968 [Info.][(2)]: SQLiteClient: Closing database: movingpictures.db3
2010-07-27 10:55:36.170898 [Info.][(2)]: Playlist: Saving default playlist default.m3u
2010-07-27 10:55:36.171875 [Info.][(2)]: SQLiteClient: Closing database: MusicDatabaseV11.db3
2010-07-27 10:55:36.175781 [Info.][(2)]: SQLiteClient: Closing database: VideoDatabaseV5.db3

So machine appears to have gone to sleep at 10:06 but MP was not actually closed down properly. Machine then woke up at 10:08 and at 10:55 it started closing down properly. There is nothing between 10:08 and 10:55, what happened during this time??

Also you have lots and lots of plugins installed. Other than checking powerscheduler settings you really need to try and replicate this without all those plugins enabled.

Yes, iMon remote is setup so power button puts HTPC to sleep. In 10:06 putted HTPC into sleep.
In 10:08 he woke up for recording which started at 10:10.
All that is fine, but MP is stuck on screen with time stamp 10:06, when I putted it to sleep and I cannot do anything with it until I close it (ALT+F4) and then start it again.
From 10:08 to 10:55 it was recording, I closed MP at 10:55 to take logs.

Will try to reproduce it with all plugins off.

 

[jameson_uk]

You need to enable powerscheduler inside on MP.

Then let MP sleep on its own (ie. do not manually put to sleep via remote but just let MP sleep when it is ready to do so)

 

[Mikeyy]

Here is another log with everything on and one with basic MP, blue skin. Still frozen.
Every time I pressed MP button for sleep (in top menu), did not force sleep with remote.
Computer wakes up for recording, it starts recording but it blocks MP totally. Cannot do anything, everything forzen on screen that was on when MP went to sleep.

Attacked picture as proof also.

Log from 19_07 is with everything, all plugins.
Log from 19_32 is with debugmode first option.

 

[jameson_uk]

2010-07-26 23:15:11.582031 [(5)]: plugin:xmltv StartImport - File [D:\Instalacije\Xmltv download - MediaPortal\rtl.hr.xml] doesn't have read access : The process cannot access the file 'D:\Instalacije\Xmltv download - MediaPortal\rtl.hr.xml' because it is being used by another process.

which looks odd but you also seem to have some other messages about EPG grabbing. Do you have DVB EPG grabbing enabled?

Either way you do need the powerscheduler plugin enabled in MP as well as TV config

 

[Mikeyy]

Don't have EPG grabbing with MP since Croatia isn't included properly.
I have setup external grabber for epg which saves files in D:\Instalacije\Xmltv download - MediaPortal\ , after that MP imports it with XMLTV plugin in TV Server.

How should I setup power plugins, not sure what should I do there.
Screenshot of plugin in TvServer included, only other option which is ON is "Reinitialize service on wakeup (also reinitialize tuner)".

 

[OnkelChris]

AW: MP froze when recording starts

sometimes I have a similar situation. sending HTPC to sleep via remote, then htpc wakes up automatically for record. Screen stays black until the record finished, then MP is working again. But till the record is ended, nothing responds, just black screen (first 3-4 times using remote buttons, the sound appears, but later remote button clicks don'T give sound.)

unfortunately, the logs are the same. last entry when going to sleep, next entry, when record is finished....

 

[Mikeyy]

Yea, that's what I'm talking about. Sometimes is black, sometimes I can see last screen that was on before HTPC went to sleep. Common thing is that I can't do anything until recording stops, or I can close MP and start again, then it works.