Didn't record show / Nothing in logs

Beta Community DVR Beta
#1

My DVR didn’t record ‘The Mick’ episode last night in it’s 20:30 timeslot… I don’t see anything in the logs about it but looking at my settings it’s definitely set to record and has the next two episodes on the list to record.

2017/02/07 18:05:21 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 18:33:00 [DVR] Deleting /Volumes/MyBook/DVR/TV/The Tonight Show Starring Jimmy Fallon/2017-02-06-2334 The Tonight Show Starring Jimmy Fallon 2017-02-06 S04E83 Tom Selleck Joe Jonas Kelsea Ballerini.mpg
2017/02/07 18:39:41 [DVR] Waiting 1h20m18.099453854s until next job 1486515600-2
2017/02/07 18:39:47 [DVR] Waiting 1h20m12.762920448s until next job 1486515600-2
2017/02/07 18:56:19 [DVR] Deleting /Volumes/MyBook/DVR/TV/2 Broke Girls/2017-02-06-2130 2 Broke Girls 2017-02-06 S06E15 And the Turtle Sense.mpg
2017/02/07 19:05:21 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 19:54:35 [DVR] Deleting /Volumes/MyBook/DVR/TV/24: Legacy/2017-02-06-2000 24: Legacy 2017-02-06 S01E02 100 PM  200 PM.mpg
2017/02/07 20:00:00 [DVR] Starting job 1486515600-2 The Flash on ch=[804 54.1]
2017/02/07 20:00:00 [DVR] Starting job 1486515600-47 New Girl on ch=[805 45.1]
2017/02/07 20:00:00 [DVR] Waiting 59m59.859998022s until next job 1486519200-5
2017/02/07 20:00:00 [DVR] Recording for job 1486515600-2 from 131F24D4 ch804 into "TV/The Flash/2017-02-07-2000 The Flash 2017-02-07 S03E12 Untouchable.mpg" for 59m59.84243448s
2017/02/07 20:00:00 [DVR] Recording for job 1486515600-47 from 131F24D4 ch805 into "TV/New Girl/2017-02-07-2000 New Girl 2017-02-07 S06E15 Glue.mpg" for 31m29.842418944s
2017/02/07 20:05:21 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 20:31:30 [DVR] Finished job 1486515600-47 New Girl
2017/02/07 20:31:30 [DVR] Waiting 28m29.356747132s until next job 1486519200-5
2017/02/07 20:31:30 [DVR] Processing file-392: TV/New Girl/2017-02-07-2000 New Girl 2017-02-07 S06E15 Glue.mpg
2017/02/07 20:31:30 [DVR] Running commercial detection on file 392 (TV/New Girl/2017-02-07-2000 New Girl 2017-02-07 S06E15 Glue.mpg)
2017/02/07 20:33:32 [DVR] Commercial detection finished with 10 markers.
2017/02/07 20:38:31 [DVR] Deleting /Volumes/MyBook/DVR/TV/Supergirl/2017-02-06-2000 Supergirl 2017-02-06 S02E11 The Martian Chronicles.mpg
2017/02/07 21:00:00 [DVR] Deleting expired job 1486515600-2
2017/02/07 21:00:00 [DVR] Starting job 1486519200-5 DC's Legends of Tomorrow on ch=[54.1]
2017/02/07 21:00:00 [DVR] Waiting 59m59.902385374s until next job 1486522800-40
2017/02/07 21:00:00 [DVR] Recording for job 1486519200-5 from 10485D1E ch54.1 into "TV/DC's Legends of Tomorrow/2017-02-07-2100 DC's Legends of Tomorrow 2017-02-07 S02E11 Turncoat.mpg" for 59m59.902241229s
2017/02/07 21:00:00 [DVR] Finished job 1486515600-2 The Flash
2017/02/07 21:00:00 [DVR] Waiting 59m59.34794788s until next job 1486522800-40
2017/02/07 21:00:00 [DVR] Processing file-391: TV/The Flash/2017-02-07-2000 The Flash 2017-02-07 S03E12 Untouchable.mpg
2017/02/07 21:00:00 [DVR] Running commercial detection on file 391 (TV/The Flash/2017-02-07-2000 The Flash 2017-02-07 S03E12 Untouchable.mpg)
2017/02/07 21:04:16 [DVR] Commercial detection finished with 14 markers.
2017/02/07 21:04:16 [DVR] Deleting /Volumes/MyBook/DVR/TV/New Girl/2017-02-07-2000 New Girl 2017-02-07 S06E15 Glue.mpg
2017/02/07 21:05:21 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 21:39:52 [DVR] Waiting 20m7.309809646s until next job 1486522800-40
2017/02/07 21:50:11 [DVR] Deleting /Volumes/MyBook/DVR/TV/The Flash/2017-02-07-2000 The Flash 2017-02-07 S03E12 Untouchable.mpg
2017/02/07 22:00:00 [DVR] Deleting expired job 1486519200-5
2017/02/07 22:00:00 [DVR] Starting job 1486522800-40 Tosh.0 on ch=[33]
2017/02/07 22:00:00 [DVR] Waiting 1h33m59.864428042s until next job 1486528440-18
2017/02/07 22:00:00 [DVR] Finished job 1486519200-5 DC's Legends of Tomorrow
2017/02/07 22:00:00 [DVR] Waiting 1h33m59.652017869s until next job 1486528440-18
2017/02/07 22:00:00 [DVR] Processing file-393: TV/DC's Legends of Tomorrow/2017-02-07-2100 DC's Legends of Tomorrow 2017-02-07 S02E11 Turncoat.mpg
2017/02/07 22:00:00 [DVR] Running commercial detection on file 393 (TV/DC's Legends of Tomorrow/2017-02-07-2100 DC's Legends of Tomorrow 2017-02-07 S02E11 Turncoat.mpg)
2017/02/07 22:00:00 [DVR] Recording for job 1486522800-40 from 131F24D4 ch33 into "TV/Tosh.0/2017-02-07-2200 Tosh.0 2017-02-07 S09E01.mpg" for 29m59.863990171s
2017/02/07 22:03:57 [DVR] Commercial detection finished with 16 markers.
2017/02/07 22:05:21 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 22:30:00 [DVR] Finished job 1486522800-40 Tosh.0
2017/02/07 22:30:00 [DVR] Waiting 1h3m59.297393807s until next job 1486528440-18
2017/02/07 22:30:00 [DVR] Processing file-394: TV/Tosh.0/2017-02-07-2200 Tosh.0 2017-02-07 S09E01.mpg
2017/02/07 22:30:00 [DVR] Running commercial detection on file 394 (TV/Tosh.0/2017-02-07-2200 Tosh.0 2017-02-07 S09E01.mpg)
2017/02/07 22:30:21 [DVR] Commercial detection finished with 8 markers.
2017/02/07 23:05:22 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/07 23:05:32 [SYS] Created database snapshot: backup-20170207.230519
2017/02/07 23:05:32 [SYS] Removing old backup backup-20170130.165139
2017/02/07 23:34:00 [DVR] Starting job 1486528440-18 The Tonight Show Starring Jimmy Fallon on ch=[11.1]
2017/02/07 23:34:00 [DVR] Recording for job 1486528440-18 from 10485D1E ch11.1 into "TV/The Tonight Show Starring Jimmy Fallon/2017-02-07-2334 The Tonight Show Starring Jimmy Fallon 2017-02-07 S04E84 Ice Cube Rosamund Pike The Band Perry.mpg" for 1h2m59.852846255s
2017/02/08 00:05:22 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/08 00:37:00 [DVR] Finished job 1486528440-18 The Tonight Show Starring Jimmy Fallon
2017/02/08 00:37:00 [DVR] Processing file-395: TV/The Tonight Show Starring Jimmy Fallon/2017-02-07-2334 The Tonight Show Starring Jimmy Fallon 2017-02-07 S04E84 Ice Cube Rosamund Pike The Band Perry.mpg
2017/02/08 00:37:00 [DVR] Running commercial detection on file 395 (TV/The Tonight Show Starring Jimmy Fallon/2017-02-07-2334 The Tonight Show Starring Jimmy Fallon 2017-02-07 S04E84 Ice Cube Rosamund Pike The Band Perry.mpg)
2017/02/08 00:41:50 [DVR] Commercial detection finished with 12 markers.
2017/02/08 01:05:22 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/08 02:05:22 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
2017/02/08 03:05:22 [NAT] Successfully mapped port 69.143.96.26:8089 using natpmp
#2

Same here, didn’t record and nothing in the logs.

Seems like maybe the guide database didn’t have it marked as New, so it never matched and setup a job.

#3

Checked the provider DB and yesterday’s airing was definitely marked New.

Very strange… I had a bunch of other shows record last night without issue…

Do you remember seeing The Mick listed on the schedule for yesterday?

#4

I don’t remember seeing it on the schedule, but I didn’t look yesterday only Monday night so I could be misremembering. I didn’t actually notice The Mick was supposed to be on last night until I got to the end of New Girl and it went into the beginning of The Mick.

#5

And yeah, I had a bunch of stuff record last night too without an issue. This is the first time I’ve seen something not record.

1 Like
#6

It didn’t record Modern family tonight. It wasn’t listed on the schedule, but it was showing as queued on the web app (still just showing as queue). The logs don’t show anything.

#7

What is the last message in the log that’s like “Waiting … until next job”?

I wonder if you hit the same bug as DVR Missed Recording First 1.5 hrs of the Oscars

#8

Email [email protected] with recent logs and output of http://127.0.0.1:8089/debug/stack

#9

Sent, thanks for looking into it.

#10

Oh it’s not on the schedule? Interesting…

If you click on the “queued” what does it say?

#11

It’s gone now so I can’t click it. It showed as Queued on the Passes section, and in the Guide, but in scheduled it wasn’t there. I looked before and after the updated DVR from today.

#12

Gotcha.

What does it say on http://127.0.0.1:8089/dvr/programs/EP011581240210

#13

Exactly the same thing happened to me - Modern Family tonight was showing in the guide as if it would be recorded (yellow on Apple TV, red icon on web), but it was not listed in the DVR section. Nothing in the logs at the time the recording should have started.

I’m not sure the sequence of events, but at one point I clicked the “queued” drop down on the web, and I think it said something like “job not found”.

I ended up cancelling the recording, deleting my season pass, and created a new pass, just so it would record,so I might have destroyed whatever evidence you’d want. :slight_smile:

#14

Whoa! This happened to me tonight too. Modern Family didn’t record as it was supposed to. Aman, I should still have the logs if you want to see them.

#15

A few pics from the time:

#16

Would like to know what that URL says for everyone too.

http://127.0.0.1:8089/dvr/programs/EP011581240210

Email in logs if you have them.

Interestingly, I added a pass for Modern Family after seeing this thread and tonight’s episode recorded fine (when it aired on the west coast).

#17

Mine says: “queued-1487826000-1”

#18

“”

:joy:

#19

Okay, I think I figured out what happened here.

Every episode has a unique ID, and the DVR uses that to keep track of what’s recorded or queued already to avoid making multiple recordings of the same episode. The ID for yesterday’s episode was EP011581240210.

In this case, it seems like the guide data was incorrect a few weeks ago. The episode that aired on 2/22 was originally listed as EP011581240210 but was fixed before the episode actually aired. This caused a stale entry in the database which made the DVR think that that episode had been queued up to record, even though the job it was referred to 1) was for another episode and 2) had already expired.

I’ve made a fix to prevent this from happening again.

#20

Glad you could track it down, thanks!