2012-09-03, 03:11 PM
Hi, I'm having a problem where if I cancel a "recurring season" and then choose to record it again, NPVR thinks that the episodes are already recording and fails to add them to the pending recordings. Note that the first time I record a season it works fine. The error only occurs when I cancel and then choose to record it again. The logfile reads:
2012-09-03 07:40:16.449 [INFO][1] UpdateRecurringRecording(81, 'NOVA'):
<Rules>
<EPGTitle>NOVA</EPGTitle>
<ChannelOID>7191</ChannelOID>
<ChannelName>OPBPlus</ChannelName>
<StartTime>2012-09-04T11:00:00.0000000Z</StartTime>
<EndTime>2012-09-04T12:00:00.0000000Z</EndTime>
<PrePadding>0</PrePadding>
<PostPadding>0</PostPadding>
<Quality>0</Quality>
<Keep>0</Keep>
</Rules>
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0288
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0288
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0220
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0220
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0221
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0221
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : SH00329558.0000
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01126304.0697
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0619.2/4
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01518354.0001
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003710.0860
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0042
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01518354.0002
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00000439.0455
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0576
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0576
2012-09-03 07:40:16.479 [DEBUG][1] LoadListingsMatchingTitle(channel=7191,title=NOVA)
2012-09-03 07:40:16.481 [DEBUG][1] - Potential episode at: 9/4/2012 4:00:00 AM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0619.2/4
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:16.484 [DEBUG][1] - Potential episode at: 9/9/2012 1:03:00 PM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0576
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:16.484 [DEBUG][1] - Potential episode at: 9/11/2012 4:00:00 AM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0576
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:17.191 [DEBUG][10] TV Listings: RecordingSchedule: update procedure starting.
2012-09-03 07:40:17.200 [DEBUG][10] TV Listings: RecordingSchedule: detected change in recurring recordings.
2012-09-03 07:40:17.217 [DEBUG][10] TV Listings: RecordingSchedule: finished updating recording schedule, broadcasting changes.
2012-09-03 07:40:17.217 [DEBUG][10] TV Recordings: Panel: recording schedule changed, updating.
2012-09-03 07:40:17.492 [DEBUG][1] TV Listings: Got event RELOAD_RECORDINGS
2012-09-03 07:40:17.565 [DEBUG][1] ActivatePopup: null
2012-09-03 07:40:17.565 [DEBUG][1] deactivating old popup: ScheduleRecordingPopup
2012-09-03 07:40:17.565 [DEBUG][1] Going to dispose popup at end of animation
2012-09-03 07:40:17.607 [DEBUG][1] OnKeyDown() done. Took 1217.06958007813 ms
2012-09-03 07:40:17.825 [DEBUG][1] Calling dispose on old popup(2): ScheduleRecordingPopup
2012-09-03 07:40:17.825 [DEBUG][1] ScheduleRecordingPopup.Dispose()
2012-09-03 07:40:17.826 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:30.506 [DEBUG][1] storing Position (1):1912,-8
2012-09-03 07:40:30.506 [DEBUG][1] storing Size (1):1936,1216
2012-09-03 07:40:30.506 [DEBUG][1] TV Listings: Got event EXITING
2012-09-03 07:40:30.507 [INFO][1] TV Listings: RecordingSchedule: deactivated.
2012-09-03 07:40:30.511 [INFO][1] Exiting...
2012-09-03 07:40:30.511 [INFO][1] Done.
Thanks!
-Ed
2012-09-03 07:40:16.449 [INFO][1] UpdateRecurringRecording(81, 'NOVA'):
<Rules>
<EPGTitle>NOVA</EPGTitle>
<ChannelOID>7191</ChannelOID>
<ChannelName>OPBPlus</ChannelName>
<StartTime>2012-09-04T11:00:00.0000000Z</StartTime>
<EndTime>2012-09-04T12:00:00.0000000Z</EndTime>
<PrePadding>0</PrePadding>
<PostPadding>0</PostPadding>
<Quality>0</Quality>
<Keep>0</Keep>
</Rules>
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0288
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0288
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0220
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0220
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00575702.0289
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0221
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00550252.0221
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : SH00329558.0000
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01126304.0697
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0619.2/4
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01518354.0001
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003710.0860
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0043
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01071913.0042
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP01518354.0002
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00000439.0455
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0576
2012-09-03 07:40:16.454 [DEBUG][1] - recently deleted episode : EP00003163.0576
2012-09-03 07:40:16.479 [DEBUG][1] LoadListingsMatchingTitle(channel=7191,title=NOVA)
2012-09-03 07:40:16.481 [DEBUG][1] - Potential episode at: 9/4/2012 4:00:00 AM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0619.2/4
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:16.484 [DEBUG][1] - Potential episode at: 9/9/2012 1:03:00 PM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0576
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:16.484 [DEBUG][1] - Potential episode at: 9/11/2012 4:00:00 AM
2012-09-03 07:40:16.484 [DEBUG][1] ...check IsValid()
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode: EP00003163.0576
2012-09-03 07:40:16.484 [DEBUG][1] ...already got this episode scheduled
2012-09-03 07:40:17.191 [DEBUG][10] TV Listings: RecordingSchedule: update procedure starting.
2012-09-03 07:40:17.200 [DEBUG][10] TV Listings: RecordingSchedule: detected change in recurring recordings.
2012-09-03 07:40:17.217 [DEBUG][10] TV Listings: RecordingSchedule: finished updating recording schedule, broadcasting changes.
2012-09-03 07:40:17.217 [DEBUG][10] TV Recordings: Panel: recording schedule changed, updating.
2012-09-03 07:40:17.492 [DEBUG][1] TV Listings: Got event RELOAD_RECORDINGS
2012-09-03 07:40:17.565 [DEBUG][1] ActivatePopup: null
2012-09-03 07:40:17.565 [DEBUG][1] deactivating old popup: ScheduleRecordingPopup
2012-09-03 07:40:17.565 [DEBUG][1] Going to dispose popup at end of animation
2012-09-03 07:40:17.607 [DEBUG][1] OnKeyDown() done. Took 1217.06958007813 ms
2012-09-03 07:40:17.825 [DEBUG][1] Calling dispose on old popup(2): ScheduleRecordingPopup
2012-09-03 07:40:17.825 [DEBUG][1] ScheduleRecordingPopup.Dispose()
2012-09-03 07:40:17.826 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.828 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.829 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:17.830 [DEBUG][1] UiStatic.Dispose()
2012-09-03 07:40:30.506 [DEBUG][1] storing Position (1):1912,-8
2012-09-03 07:40:30.506 [DEBUG][1] storing Size (1):1936,1216
2012-09-03 07:40:30.506 [DEBUG][1] TV Listings: Got event EXITING
2012-09-03 07:40:30.507 [INFO][1] TV Listings: RecordingSchedule: deactivated.
2012-09-03 07:40:30.511 [INFO][1] Exiting...
2012-09-03 07:40:30.511 [INFO][1] Done.
Thanks!
-Ed