TV recording doesn't start if DVD is playing (2 Viewers)

[cewillis]

Just wondering if anyone else has seen this --.
A scheduled TV recording doesn't start if I have a DVD playing at the time. I don't expect a 'fix', because I'm using 1.2.3 - which is working very well otherwise so I'm not planning to upgrade anytime soon.
This has happened twice recently, but to confuse the issue, it doesn't happen all the time. In fact, I specifically set a recording to start while watching a DVD, and the recording worked.
So has this happened to anyone else? Thanks.

On edit: No logs because there's no reported error, so don't know how I would trigger logs. Besides, just wondering --

 

[mm1352000]

Hello

Playback of a DVD is handled by MP; starting a recording is handled by TV Server. They're basically as unrelated as you can get when it comes to MP.

On edit: No logs because there's no reported error, so don't know how I would trigger logs. Besides, just wondering --

Please let us be the judge when it comes to the log files. Not that I don't believe you - just that sometimes a bit of experience helps, and an error won't always be obvious from the error logs alone.

If you can reproduce the problem on demand then simply use the watchdog with option 1 to gather your log files:
http://wiki.team-mediaportal.com/1_MEDIAPORTAL_1/16_Support/3_Forums/2_Log_Files

Otherwise, ensure MP log level is set to debug:
http://wiki.team-mediaportal.com/1_...ion/00_Configuration/11_General#Log_verbosity

Then next time the problem happens close MP and use the watchdog with option 3 to gather your log files:
http://wiki.team-mediaportal.com/1_..._Non_Reproducible_Problems_within_MediaPortal

Please let us know the date, time, channel name and program name that failed to record.

Thanks
mm

 

[cewillis]

Hello mm, nice to hear from you again! Hope you're doing well.
As you can tell from my lack of 'participation' here, I don't have any real problems with MP. And given that's it's 1.2.3, I'm a little surprised that you'd be interested in this -- but I gladly defer to your expertise, experience, and judgement. (really -- I mean that)
However, as stated, the problem doesn't happen every time -- but I'll see what I can do to narrow it down (or even better, find a repeatable case). What I know so far is that it's been two different clear QAM scheduled recordings, while watching two different DVDs. The last time, the DVD ended just 15 minutes into the scheduled recording time - but the recording did not start. I restarted MP (no reboot), and the recording started.

Cal

(as you may have guessed, I didn't even think of looking at the log files to see if these was a reported error -- sorry. I'll try that too)

 

[cewillis]

Haven't been able to reproduce this yet. Tried a few DVD on hand and one from Netflix, and some different clear QAM channels.
Been kind off busy crawling around my attic replacing the plumbing in my house, but ready to pounce when the problem recurs.

 

[cewillis]

Finally had the problem repeat - so I stopped MP, set log to DEBUG, deleted old log files, restarted MP, and repeated the same setup.
But the problem then didn't recur.
The sequence is 1) schedule a recording, 2) put the machine in standby, 3) come back later, wake up machine, and start a DVD playing.
(in order not to miss a recording, I've been playing DVDs on another machine - except for this test)

 

[mm1352000]

Hi Cal

Just a quick note to let you know I'm still following...

mm

 

[cewillis]

Finally got another occurrence. But I did not have log level at DEBUG, and I only see one thing in the log files that looks anything like what happened.
A recording was set to start at 8:00 PM on KOLDHD. Was watching a DVD at the time, which ended about 8:45. After ejecting the DVD, there was nothing recording, recorded, or scheduled that corresponded to the 8:00 start. Trying to put the computer in standby did not work. (as if some part of MP is busy) I see several 'standby disallowed' messages in tv.log starting about 20:39 (on 6/13) -- but nothing about recording start anywhere that I can find.
18:04:58 is about when I woke up the computer and started the DVD. I see there are a couple of error.log entries just after that.
Here are the logs. Maybe there's something obvious -- thanks for looking.

 

[mm1352000]

Hello

I can't see anything to indicate a schedule was ever present.

Earlier in the day the schedule list is checked:
[collapse]
2014-06-13 12:09:17.937500 [MPMain(1)]: GetConflictingSchedules: Schedule = The This Old House Hour on 265 6/14/2014 10:00:00 AM - 6/14/2014 11:00:00 AM ID=0
2014-06-13 12:09:17.937500 [MPMain(1)]: GetConflictingSchedules: Cards.Count = 6
2014-06-13 12:09:17.953125 [MPMain(1)]: AssignSchedulesToCard: schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.031250 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2
2014-06-13 12:09:18.046875 [MPMain(1)]: AssignSchedulesToCard: schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.046875 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.046875 [MPMain(1)]: AssignSchedulesToCard: schedule = 24: Live Another Day on 256 6/16/2014 8:00:00 PM - 6/16/2014 9:00:00 PM ID=1061
2014-06-13 12:09:18.046875 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.046875 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.062500 [MPMain(1)]: AssignSchedulesToCard: schedule = CSI: Crime Scene Investigation on 254 6/18/2014 9:00:00 PM - 6/18/2014 10:00:00 PM ID=498
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = 24: Live Another Day on 256 6/16/2014 8:00:00 PM - 6/16/2014 9:00:00 PM ID=1061
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: schedule = Dual Survival on 221 6/18/2014 11:00:00 PM - 6/19/2014 12:00:00 AM ID=1120
2014-06-13 12:09:18.078125 [PowerScheduler poll thread(14)]: ActiveSharesHandler: have not found any matching connections - will allow standby
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: schedule = Hawaii Five-0 on 254 6/20/2014 8:00:00 PM - 6/20/2014 9:00:00 PM ID=615
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = 24: Live Another Day on 256 6/16/2014 8:00:00 PM - 6/16/2014 9:00:00 PM ID=1061
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = CSI: Crime Scene Investigation on 254 6/18/2014 9:00:00 PM - 6/18/2014 10:00:00 PM ID=498
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2
2014-06-13 12:09:18.078125 [MPMain(1)]: AssignSchedulesToCard: schedule = Suits on 204 6/18/2014 9:00:00 PM - 6/18/2014 10:01:00 PM ID=1160
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Dual Survival on 221 6/18/2014 11:00:00 PM - 6/19/2014 12:00:00 AM ID=1120
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: schedule = PowerNation: Truck Tech on 213 6/15/2014 10:00:00 AM - 6/15/2014 10:30:00 AM ID=1161
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Dual Survival on 221 6/18/2014 11:00:00 PM - 6/19/2014 12:00:00 AM ID=1120
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Suits on 204 6/18/2014 9:00:00 PM - 6/18/2014 10:01:00 PM ID=1160
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.093750 [MPMain(1)]: AssignSchedulesToCard: schedule = Rizzoli & Isles on 218 6/17/2014 9:00:00 PM - 6/17/2014 10:00:00 PM ID=1149
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Dual Survival on 221 6/18/2014 11:00:00 PM - 6/19/2014 12:00:00 AM ID=1120
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Suits on 204 6/18/2014 9:00:00 PM - 6/18/2014 10:01:00 PM ID=1160
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = PowerNation: Truck Tech on 213 6/15/2014 10:00:00 AM - 6/15/2014 10:30:00 AM ID=1161
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: schedule = Fixer Upper on 227 6/19/2014 11:00:00 PM - 6/20/2014 12:00:00 AM ID=1141
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Fixer Upper on 227 6/20/2014 12:00:00 AM - 6/20/2014 1:00:00 AM ID=1142
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Perception on 218 6/17/2014 10:00:00 PM - 6/17/2014 11:00:00 PM ID=1158
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 8:00:00 PM - 6/17/2014 9:00:00 PM ID=1148
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Dual Survival on 221 6/18/2014 11:00:00 PM - 6/19/2014 12:00:00 AM ID=1120
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Suits on 204 6/18/2014 9:00:00 PM - 6/18/2014 10:01:00 PM ID=1160
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = PowerNation: Truck Tech on 213 6/15/2014 10:00:00 AM - 6/15/2014 10:30:00 AM ID=1161
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: card 3, ID = 4 has schedule = Rizzoli & Isles on 218 6/17/2014 9:00:00 PM - 6/17/2014 10:00:00 PM ID=1149
2014-06-13 12:09:18.109375 [MPMain(1)]: AssignSchedulesToCard: free on card 3, ID = 4
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: schedule = The This Old House Hour on 265 6/14/2014 10:00:00 AM - 6/14/2014 11:00:00 AM ID=0
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = 24: Live Another Day on 256 6/16/2014 8:00:00 PM - 6/16/2014 9:00:00 PM ID=1061
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = CSI: Crime Scene Investigation on 254 6/18/2014 9:00:00 PM - 6/18/2014 10:00:00 PM ID=498
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Hawaii Five-0 on 254 6/20/2014 8:00:00 PM - 6/20/2014 9:00:00 PM ID=615
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: schedule = The This Old House Hour on 265 6/21/2014 10:00:00 AM - 6/21/2014 11:00:00 AM ID=0
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Crisis on 261 6/15/2014 9:00:00 PM - 6/15/2014 10:00:00 PM ID=979
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = 24: Live Another Day on 256 6/16/2014 8:00:00 PM - 6/16/2014 9:00:00 PM ID=1061
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = CSI: Crime Scene Investigation on 254 6/18/2014 9:00:00 PM - 6/18/2014 10:00:00 PM ID=498
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = Hawaii Five-0 on 254 6/20/2014 8:00:00 PM - 6/20/2014 9:00:00 PM ID=615
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: card 1, ID = 2 has schedule = The This Old House Hour on 265 6/14/2014 10:00:00 AM - 6/14/2014 11:00:00 AM ID=0
2014-06-13 12:09:18.125000 [MPMain(1)]: AssignSchedulesToCard: free on card 1, ID = 2[/collapse]

From that PowerScheduler calculates the next required wakeup time:
2014-06-13 12:09:25.093750 [PowerScheduler poll thread(14)]: PowerScheduler: new next wakeup time 6/14/2014 9:59:00 AM found by
ScheduledRecordingsHandler

...which is for recording "The This Old House Hour". No need to record anything at 8PM.

At 6PM on wakeup we see there are 14 schedules:
2014-06-13 18:04:58.109375 [PowerEventThread(8)]: Scheduler: loaded 14 schedules

...which exactly matches the earlier check. No new schedules.

I don't know what you were expecting to record but it doesn't look like TV Server was aware of any need to record.

mm

 

[cewillis]

Maybe this instance was in my head -- but I sure don't remember deleting the 8:00 program. Sorry about that.
Why do you suppose MP wouldn't go to standby ---?

I shall return, with more evidence next time.

 

[cewillis]

I think I have another instance. This isn't exactly the problem I described before, but very close. While watching a DVD on Sep 19 (9/19), and about 7:15pm (19.15 Hr), I stopped the DVD, scheduled Hawaii Five-0 to record at 20:00 on 9/19, and restarted the DVD.
When the DVD completed at about 8:25, the Scheduled screen positively showed Hawaii Five-0 for 8pm (20:00) on 9/19, and the Active Recordings, and Recorded TV screens positively did not show Hawaii Five-0 recording. I stopped MP and TVserver and saved the current logs ( attached).
In tv.log , I see two references to Hawaii Five-0 at 8pm on 9/19 at 19:16.21; a GetConflictingSchedules (there were no conflicting schedules), and an AssignSchedulesToCard. No other references anywhere that I can find. Since I don't know what I'm looking at, I'll refrain from further commentary.

To repeat, this non-recording of a scheduled show, while a DVD is playing, only very rarely occurs. So it's certainly not a major problem. I've never seen a scheduled show not record otherwise.