Failed some scheduled recordings and other rare issues (1 Viewer)

[mrspock]

MediaPortal Version: 1.1.1
MediaPortal Skin: StreamedMP
Windows Version: W7 pro 64b
CPU Type: Intel core 2, 2.40GHz
HDD: Western Digital 1Tb
Memory: 3Gb
Motherboard: Intel DG965WH
Video Card: Nvidia GeForce 6600
Video Card Driver: 8.17.11.9713
Sound Card: motherboard
Sound Card AC3:
Sound Card Driver: High Definition Audio 6.1.7600.16385
1. TV Card: Pinnacle Dual PCI DVBT
1. TV Card Type: DVB-T
1. TV Card Driver: 4.2.0.0
2. TV Card: Technisat Skystar 2
2. TV Card Type: DVB-S
2. TV Card Driver: 4.6.0
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: MS DTV-DVD Video Decoder
MPEG2 Audio Codec: ffdshow
h.264 Video Codec: MainConcept AVC
Satelite/CableTV Provider: 19.2ºE Astra, 28.2ºE Eurobird, 30ºW Hispasat, 13ºE Hot Bird
HTPC Case: Thermaltake Bach
Cooling:
Power Supply:
Remote: imon 7.85.0222 (firm 0x30)
TV: Loewe
TV - HTPC Connection: S-video

Hi. (Please, my apologies for this really big post.)

After changing my skin to StreamedMP and adding some plugins, I am having several issues with MP (not experimented before). I don’t really know the reasons of the issues, so I’ve been testing it, enabling and disabling different things.
Usually, the scenario is the following:
1. MP returns for standby at around 22:00 to retrieve the EPG
2. I usually watch some live TV or some TV recordings after 22:00.
3. At around midnight a TV recording is scheduled (one or two programs).
4. In the morning, another TV recording (one program) is also scheduled: this is usually NOT recorded, so I reset computer and MP to record it.

I am attaching several logs with different configurations from different days, using MP WatchDog (2nd option with plugins). I wish anybody could have enough time to have a look to them and tell me what is happening… and how I can solve it.

1st log: I found MP frozen (clock stopped, RSS ticker stopped, weather icons stopped, menu not working…). Pressing Alt-F4 MP exited (after waiting a couple of minutes), but MP WatchDog did not detected: in the windows task manager the MP process is still on, so I kill it and WatchDog starts to record the logs (during this, the PC goes to sleep so I wake it up).

2nd log: I restart the computer, remove all the RSS except MP RSS from InfoService and run MP. It records two night shows. At 9:39 I noticed that the scheduled program is not being recorded. I exit MP but then I have to kill it again.

3rd log: 9:42: I run again MP, but it stops at “Initializing input devices”, so I have to kill it. After that I notice that the windows task bar has disappeared.

4th log: I restart the PC, run MP, it records the morning show, it wake up at 22h and goes to sleep around 30 minutes after. At 22:32 I switch the computer on: it was frozen (the clock was 22:27) but after a few seconds it comes to live again… but the interface was not correct (no backgrounds, not vertical line near menu, not lines around RSS ticker…): see photo 1. I exit at 22:41 and this time the logs are immediately obtained.

5th log: 22:45: I restart the PC, disable InfoService plugin, and start MP (see photo 2 to compare with photo 1). At 1:57 was recording a show, but the weather icons were not displayed (see photo 3). At 9:45 it was not recording and again the interface was corrupted. I close MP to obtain logs.

6th log: I remove RSS ticker from the BasicHome. 9:50: I restart and the recording starts. Next morning at 10:05 it is not recording. I close MP.

7th log: I disable all the plugins (except default plugins and short’cutter). I restart PC. At 9:58 MP was frozen with no answer to keys and the interface stopped (clock was 3:33). I close MP pressing Alt-F4.

8th log: I disable StreamedMP skin, using Blue3Wide. I restart. Today morning program is scheduled at 14:00, but although the PC wakes up, it does not record the program; in fact, I go to EPG, and click the program that should be recording to watch it, but MP hangs. Pressing Alt-F4 nothing happens so I have to kill it (again, the windows task bar is missing).

9th log: I restart PC. I run MP with WatchDog 1st option (without plugins). After a good weekend, it finnally refused to record the morning show.

10th log: again the same...

Without StreamedMP skin and plug-ins, I am having the same issues (after these tests, for instance, I found MP frozen in the morning when it woke up...).

If you need any other log, or to do any aditional test, please juste tell me.

Thanks a lot if you are reading all this. I hope that somebody could help me to identify the problem(s) or, even better, to solve it… because it's quite frustrating...

 

[jameson_uk]

That is a lot of information... can you try and break this down into the problems you are experiencing? Is it basically that some recordings are not taking place and that sometimes MP is freezing on you?

For failed recordings can you provide the program it was meant to record, the time it was on and the channel.

In case someone else recognises this fontengine.log from one set of logs has

16-11-2010 22:21:27.267 [9ac]ERROR FontEngine:Ran out of textures!

 

[mrspock]

Thanks for your interest.
The main problems are:

1. MP freezing (logs # 1, 4, 7)
2. MP really does not close so I have to kill it using Windows task manager (logs # 1, 2)
3. MP interface corrupted or incomplete (logs # 4, 5)
4. Failed scheduled recordings (logs # 2, 5, 6, 7, 8, 9). I think that recordings are ok if I turn on the PC, if I am using it, or if it is the first time recording something… The scheduled programs were:
   • Title: “Más allá del límite”, channel: “NITRO”, scheduled time: it varies; it usually starts between 9 and 10am in weekdays (recording usually failed).
   • Title: “Más allá del límite”, channel: “NITRO”, scheduled time: it varies; it usually starts between 11:30pm and 1am in weekdays.
   • Title: “ALFRED HITCHCOCK PRESENTA”, channel: “VEO7”, scheduled time: it varies; there is a show scheduled at around 2pm on Saturdays (recording usually failed); it is also scheduled some weekdays starting before midnight.

Edit: This night a new MP frozen happened: I started MP at 21:22 and I did nothing else. It was supposed to suspend in 33 minutes and wake up at 21:55 to EPG grabbing (as comnfigured in Power Scheduler). When I turn on TV at around 22:13, MP was frozen and the clock showing a wrong time (at around 21:55). So I had to Alt-F4 to close and get the attached new log. Watchdog was working using first option.

Thanks again.

 

[mrspock]

Just to add updated information and cleaner logs.

I thought that one of the pluggins/skin installed was the cause of failed recordings. So I went back to a diskimage previous to the installation of skin and plugins. So I started again from clean MP 1.1.1, but updated to MP 1.1.2 (with no extra plugins except Short'cut'r). But I know that the issue is not caused by those plugins. It failed again.

So I run MP debug system, option 1 (excluding plugins). The steps taken and events were exactly the following:

1. 23:54: MP starts
2. 23:55: MP goes to sleep (forced by me)
3. 00:30-01:30: a program is scheduled for recording: channel: NITRO; program name: "Más allá del límite". The program is being recording. After that, MP goes to sleep
4. 09:30-11:00: a program is scheduled for recording: channel: NITRO; program name: "Más allá del límite". The program is NOT being recording
5. 09:31: I close MP to collect logs

I have looked at the logs, but I cannot find any error or suspicious message. Has anybody any idea?

Thanks a lot for any information / idea you could tell me to help solve this...

 

[jameson_uk]

Your logs just end at the point we need some info...

2010-12-07 09:23:55.569335 [PowerScheduler Waiter(19)]: PowerScheduler: OnResume
2010-12-07 09:23:55.888671 [Powerscheduler Timer(20)]: PowerScheduler: System changed from idle state to busy state
2010-12-07 09:23:56.458984 [PowerEventThread(8)]: OnPowerEvent: PowerStatus: ResumeAutomatic
2010-12-07 09:23:56.467773 [PowerEventThread(8)]: OnPowerEventHandler: PowerStatus: ResumeAutomatic
2010-12-07 09:23:56.471679 [PowerEventThread(8)]: PowerScheduler: System has resumed automatically from standby
2010-12-07 09:24:09.867187 [PowerEventThread(8)]: OnPowerEvent: PowerStatus: ResumeSuspend
2010-12-07 09:24:09.872070 [PowerEventThread(8)]: OnPowerEventHandler: PowerStatus: ResumeSuspend
2010-12-07 09:24:09.910156 [PowerEventThread(8)]: PowerScheduler: System has resumed from standby
2010-12-07 09:24:09.920898 [WinController exit thread(18)]: WindowsController: ExitWindows performed, result: True
2010-12-07 09:25:10.925781 [scheduler thread(9)]: Scheduler: Time to record NITRO 9:25-11:00 Más allá del límite
2010-12-07 09:25:10.929687 [scheduler thread(9)]: Controller: find free card for channel NITRO
2010-12-07 09:25:10.934570 [scheduler thread(9)]: Controller:   got 1 tuning details for NITRO
2010-12-07 09:25:10.937500 [scheduler thread(9)]: Controller:   channel #1 DVBT:tv:ANTENA3 NITRO Freq:698000 ONID:8916 TSID:16 SID:147 PMT:0x64 FTA:True LCN:10000 BandWidth:8 
2010-12-07 09:25:10.944335 [scheduler thread(9)]: Controller:    card:3 type:DvbT is available priority:5 #users:0 same transponder:True
2010-12-07 09:25:10.950195 [scheduler thread(9)]: Controller:    card:4 type:DvbT is available priority:4 #users:0 same transponder:True
2010-12-07 09:25:10.955078 [scheduler thread(9)]: Controller:    card:2 type:DvbS cannot tune to channel
2010-12-07 09:25:10.957031 [scheduler thread(9)]: Controller:    card:1 type:DvbIP is disabled
2010-12-07 09:25:10.959960 [scheduler thread(9)]: Controller:    card:5 type:RadioWebStream is disabled
2010-12-07 09:25:10.962890 [scheduler thread(9)]: Controller: found 2 available
2010-12-07 09:25:10.965820 [scheduler thread(9)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 36 msec
2010-12-07 09:25:10.968750 [scheduler thread(9)]: Scheduler : record on free card:3 priority:5
2010-12-07 09:25:10.971679 [scheduler thread(9)]: Controller: epg stop
2010-12-07 09:25:10.980468 [scheduler thread(9)]: user:epg remove
2010-12-07 09:25:10.983398 [scheduler thread(9)]: Scheduler : record, first tune to channel
2010-12-07 09:25:10.986328 [scheduler thread(9)]: card: Tune 3 to NITRO
2010-12-07 09:25:10.989257 [scheduler thread(9)]: card: user: scheduler53:3:-1 tune DVBT:tv:ANTENA3 NITRO Freq:698000 ONID:8916 TSID:16 SID:147 PMT:0x64 FTA:True LCN:10000 BandWidth:8
2010-12-07 09:25:10.996093 [scheduler thread(9)]: dvbt: Tune:DVBT:tv:ANTENA3 NITRO Freq:698000 ONID:8916 TSID:16 SID:147 PMT:0x64 FTA:True LCN:10000 BandWidth:8
2010-12-07 09:25:10.999023 [scheduler thread(9)]: dvb:Submiting tunerequest Channel:NITRO subChannel:-1 
2010-12-07 09:25:11.002929 [scheduler thread(9)]: dvb:Getting new subchannel
2010-12-07 09:25:11.005859 [scheduler thread(9)]: dvb:GetNewSubChannel:0 #0

So it woke up at 09:23 and said it was time to record and starts tuning but then logs just end...

 

[mrspock]

Thanks again, jameson_uk, for your interest and support.

It should start recording 5 mins. before the program is scheduled. That means that the recording should start at 9:25. I closed MP at 9:31 because there were 6 recording minutes missing (and to get my program recorded ).

I have repeated the test this night, with the same result. I am attaching these new logs. I closed MP at 10:10 to leave more time to try recording and collect logs. But I also have noticed that logs ends at 9:25...

So maybe this could be the issue. Is it possible that the module/process/thread that should do the recordings and that should write the logs dead/crashes/hangs at the recording time? Else, why the log ends?

When this happens, if I try to turn on TV, MP hangs... See 8th log from my first post.

If you think further or different tests are needed, just ask. Thanks again.

 

[jameson_uk]

You are grabbing DVB EPG yes? If so can you turn this off before and try the same?

 

[mrspock]

Yes, I was grabbing DVB EPG, but just for DVBT channels. I had to stop grabbing DVBS channels because of https://forum.team-mediaportal.com/bugreports-74/another-tvservice-lost-issue-88059/.

So I have deactivated the 5 checkboxes of DVB EPG and deselected also all the channels from TV EPG Grabber.

I did it two days ago and all the programs have been properly recorded, so maybe you are right: issue seem to be caused by DVB EPG.

Of course, I need EPG to record my programs, so what can we test now to try to find if a bug exists and where and why and...?

Do you need the logs for the last two days?

 

[mrspock]

Is there any idea why MP refuses recording programs when DVB EPG is on?