Countdown Final (weird Expire behaviour)

Black Hole

Black Hole

May contain traces of nut
...didn't record yesterday (annoyingly), for no obvious reason (it doesn't even seem to have tried to record). Wednesday's recorded, today's is scheduled to record, so I guess it was a S-CRID issue. Anyone concur/disagree?
 
You didn't state time or service, but presuming the afternoon HD showing, not that I can see (in England):
21 13:10:38 Event 17664:27951 4E:13 started 13:10:00 00:50:00 "Countdown" "/75050/071" "/C4ED0004010516212494" 22 13:10:06 Event 17664:28719 4E:15 started 13:10:00 00:50:00 "Countdown" "/75050/072" "/C4ED0004010516212494" 23 13:10:36 Event 17664:28748 4E:16 started 13:10:00 00:50:00 "Countdown" "/75050/073" "/C4ED0004010516212494" 26 13:10:36 Event 17664:29417 4E:11 started 13:10:00 00:50:00 "Countdown" "/75050/074" "/C4ED0004010516212494" 27 13:10:28 Event 17664:28006 4E:15 started 13:10:00 00:50:00 "Countdown" "/75050/075" "/C4ED0004010516212494" 28 13:10:46 Event 17664:28030 4E:18 started 13:10:00 00:50:00 "Countdown" "/75050/076" "/C4ED0004010516212494" 29 13:10:46 Event 17664:29111 4E:18 started 13:10:00 00:50:00 "Countdown" "/75050/077" "/C4ED0004010516212494" 30 13:10:31 Event 17664:29141 4E:22 started 13:10:00 00:50:00 "Countdown" "/75050/078" "/C4ED0004010516212494"
 
Last edited:
Channel 4 SD from Mynydd Machen (26+), 1410 (I didn't know there's another timeslot!).

The mystery deepens. The activity log shows it recorded, so why can't I find the recording? (rhet.)
 
:oops:

I found it in my recycle bin. I'm sure I haven't watched it, and I don't remember having deleted it, but...
 
Black Hole said:
:oops:

I found it in my recycle bin. I'm sure I haven't watched it, and I don't remember having deleted it, but...
Click to expand...
Senior moment (worrying), the programme was so memorable that you forgot (possible), or your Humax has developed a mind of its own (AI conspiracy).

Maybe your first port of call should have been the activity log. Perhaps the activity log needs to note deleted files (if it doesn't already - given this appears to be CF my knowledge is nil!)
 
Nope.

It's now rescued from the recycle bin to be watched later, when I will confirm I didn't watch it. In fact, it has the unwatched flag. I don't think I even went into that room yesterday...

There is a very small chink of a possibility: I have a 7 day expire on that folder. Could that have got its wires crossed? Which log would it be in? Auto, I suppose – I'll check.
 
Smoking gun! WTF?:

Code: 
29/06/2023 15:05:17 - expire:autotrigger[2951]:       Countdown_20230629_1408.ts
29/06/2023 15:05:17 - expire:autotrigger[2951]:         19537.5870023 days (cf. 7)
29/06/2023 15:05:17 - expire:autotrigger[2951]:         Removing.
29/06/2023 15:05:18 - expire:autotrigger[2951]:      EXPIRE: removed /media/My Video/[NEWS]/Countdown_20230629_1408.ts
29/06/2023 15:05:18 - expire:autotrigger[2951]:       Countdown_20230629_1408.hmt
29/06/2023 15:05:18 - expire:autotrigger[2951]:         19537.5870023 days (cf. 7)
29/06/2023 15:05:18 - expire:autotrigger[2951]:         Removing.
29/06/2023 15:05:18 - expire:autotrigger[2951]:      EXPIRE: removed /media/My Video/[NEWS]/Countdown_20230629_1408.hmt

Why has it decided that recording is 20,000 days old???

At least my marbles are exonerated!

(I've asked for this thread to be moved to CF)
 
Having put the recording back, there was a risk it would get expired again – but this time:

Code: 
30/06/2023 17:24:18 - expire:      Countdown_20230629_1408.ts
30/06/2023 17:24:18 - expire:        1.0966087963 days (cf. 7)
30/06/2023 17:24:18 - expire:        Too new, skipping.

I think what might have happened is Expire auto-ran in a critical timing window too soon after the recording completed, and ended up computing a negative age which then got aliased to ~20,000 days in the particular number representation used in that section of the code.

Any more data required?
 
EEPhil said:
Maybe your first port of call should have been the activity log.
Click to expand...
Good call.
Perhaps the activity log needs to note deleted files
Click to expand...
That's an interesting thing to consider.
Black Hole said:
At least my marbles are exonerated!
Click to expand...
:D
Black Hole said:
ended up computing a negative age which then got aliased to ~20,000 days in the particular number representation used in that section of the code.
Click to expand...
Definitely not.
Any more data required?
Click to expand...
Needs thought. Certainly looks like a nasty timing thing. 19500+ days has a 1/1/1970 feel to it.
 
prpr said:
19500+ days has a 1/1/1970 feel to it.
Click to expand...
I wondered if that meant the system time and therefore the file timestamp (as opposed to the time embedded in the filename) had somehow been 1970 at the time of recording, but apparently not:
Code: 
-rw-r--r-- 1 root root 2.1K Jun 29 15:05 Countdown_20230629_1408.hmt
-rw-r--r-- 2 root root 2.7M Jun 29 15:05 Countdown_20230629_1408.nts
-rw-rw-rw- 1 root root 1.1G Jun 29 15:05 Countdown_20230629_1408.ts
 
Do the timestamps inside the hmt, as shown by webif details display and/or hmt utility, look reasonable
 
The scheduled start is weird (and the synopsis has grabbed Steph's Packed Lunch), but not so weird as to explain the above:

Code: 
HDRFOX3# hmt Countdown_20230629_1408                                                                                                                                       
Format:SD                                                                                                                                                                   
Title:Countdown                                                                                                                                                             
ITitle:Countdown                                                                                                                                                           
Channel:800 (Channel 4)                                                                                                                                                     
Episode:0,0/0                                                                                                                                                               
Folder:/mnt/hd2/My Video/[NEWS]/                                                                                                                                           
Filename:Countdown_20230629_1408                                                                                                                                           
Genre:Entertainment (48)                                                                                                                                                   
EPG:Steph's joined by Mike Reid and Ravneet Gill. Derry Girls star Siobhán McSweeney chats about her new play. Plus: Sara Cox talks about working with Prince William to tac
kle homelessness. [S,W]                                                                                                                                                     
                                                                                                                                                                            
Recording Status: Valid (OK)                                                                                                                                               
Flags: SD,New,Unlimited Copies,Addetection,                                                                                                                                 
Copy count:0                                                                                                                                                               
                                                                                                                                                                            
Scheduled start:1688036400 (Thu Jun 29 12:00:00 2023)                                                                                                                       
Scheduled duration:7800                                                                                                                                                     
Recording start:1688044081 (Thu Jun 29 14:08:01 2023)                                                                                                                       
Recording end:1688047498 (Thu Jun 29 15:04:58 2023)                                                                                                                         
Duration:3417                                                                                                                                                               
Stored duration:3417                                                                                                                                                       
Play resumes at:0 seconds in.                                                                                                                                               
Timezone offset:3600                                                                                                                                                       
                                                                                                                                                                            
Service ID (SID):8384                                                                                                                                                       
Event ID:29110                                                                                                                                                             
Transport Stream ID (TSID):8205                                                                                                                                             
Originating Network ID (ONID):9018                                                                                                                                         
Programme Map Table PID (PMTPID):1100                                                                                                                                       
Video PID:1101                                                                                                                                                             
Audio PID:1102                                                                                                                                                             
Bookmarks:4 = 195 1025 2028 3105                                                                                                                                           
HDRFOX3#
 
Here is the data for service 8384:
29 11:00:03 Event 8384:29110 4F:17 started 11:00:00 02:10:00 "Live: Steph's Packed Lunch" "/74264/184" "/C4EI0200914162141497" 29 13:10:45 Event 8384:29111 4F:18 started 13:10:00 00:50:00 "Countdown" "/75050/077" "/C4EI0004010516212494" 29 13:59:18 Event 8384:29112 4F:20 started 14:00:00 01:00:00 "A Place in the Sun" "/68253/053" "/C4EI0020722162130639"

Is this on your promiscuous box? Channel 800 is a bit of a give away. I think that's probably the cause of this .hmt weirdness.
 
Black Hole said:
how does that explain the expire weirdness?
Click to expand...
It becomes clear that the only way this can happen is that the "Recording end" field in the .hmt file is 0 at the point that it was read.
So the questions then become: "How should we fix it?" and "Where should we fix it?"
There only seem to be two possible answers to the first: 1) Leave it to something else; or 2) Use the start time if the end time is 0 (or < start time)
And there are three possible answers to the second: 1) in the hmt utility; 2) in the Webif's ts.class code; or 3) in the expire code.

Decisions, decisions...
 
prpr said:
It becomes clear that the only way this can happen is that the "Recording end" field in the .hmt file is 0 at the point that it was read.
So the questions then become: "How should we fix it?" and "Where should we fix it?"
There only seem to be two possible answers to the first: 1) Leave it to something else; or 2) Use the start time if the end time is 0 (or < start time)
And there are three possible answers to the second: 1) in the hmt utility; 2) in the Webif's ts.class code; or 3) in the expire code.

Decisions, decisions...
Click to expand...
Logically recording end time can only be known after the recording has ended creating the small timing window while start time is definitely known so in my opinion the fix is for expire code to always use the start time rather than end time, for most purpose the number of days will be the same and expire doesn't need to be super precise.

Hopefully this would require the coding change to just be a single line of code
 
Why is expire trying to operate on a file where the recording end field has not been set? Isn't the answer to either:
  1. Ensure Expire doesn't look at a recording which has not finished processing, or
  2. If Recording End = 0, defer the expire decision until the next pass (ie treat the recording as zero age).
?

It seems to me option 2 would be a very easy patch.
 
MymsMan said:
Logically recording end time can only be known after the recording has ended
Click to expand...
Testing it, it seems that the Humax software initially puts the Scheduled end time in to the Recording end time. It updates this when the recording stops.
It also updates the "Stored duration" field every 10 secs.
The problem with BH's box is probably caused by being multi-region tuned and the Scheduled end data is not as expected. I might test it at some point tomorrow.
I'm favouring fixing it in ts.class at the moment, as there's a similar vulnerability in sweeper too, and I think the hmt utility should extract what is in the .hmt file without modification.
Black Hole said:
Why is expire trying to operate on a file where the recording end field has not been set?
Click to expand...
Lack of "obvious error" checking.
defer the expire decision until the next pass
Click to expand...
Yes, that's what I was originally thinking of too. It means fixing it in four places rather than just two, but...
 
You must log in or register to reply here.
Back
Top