Detecting start of recordings

I am running Recmon 2.0.3-4 with no updates shown as available and I am still getting start notifications for some, but not all, recordings.
In the example below Titanic did receive a notification but Gadget Man did not - both recordings were started and stopped via the webif IR package
Code:
325 detectads: -stop {/media/My Video/Titanic_20150607_1216-dec}
324 07/06/2015 12:23:25 : -stop {/media/My Video/Titanic_20150607_1216-dec}
323 detectads: -stop {/media/My Video/Titanic_20150607_1216-dec}
322 07/06/2015 12:21:57 : -stop {/media/My Video/Titanic_20150607_1216-dec}
321 /media/My Video/Titanic_20150607_1216-dec.hmt: No such file or directory
320 detectads: -stop {/media/My Video/Titanic_20150607_1216}
319 07/06/2015 12:21:33 : -stop {/media/My Video/Titanic_20150607_1216}
318 detectads: -start {/media/My Video/Titanic_20150607_1216}
317 07/06/2015 12:16:52 : -start {/media/My Video/Titanic_20150607_1216}
316 detectads: -stop {/media/My Video/Gadget Man_20150607_1204}
315 07/06/2015 12:13:41 : -stop {/media/My Video/Gadget Man_20150607_1204}

Has there been any progress in detecting why some recordings miss receiving start notifications?

My suspicion is that there is a timing window problem going on and that recmon is checking with some other source of information (Redring?) to attempt to determine if the newly created .ts file is from a genuine recording or one generated by a webif package and on some occasions this other information is slightly delayed.
For my purposes it is not vital that I receive instant notification of recording start so would prefer a reliable if slightly delayed notification rather than instant but intermittent so a short pause before checking recording status would be a good idea.

I very rarely see stop notifications for the .ts files created by detectads but today two were generated for the -dec (decrypt whilst recording) file for Titanic, I think it must somehow be related to the recording being so short (I don't start decryption until five minute after recording starts)
 
Some more examples of missing recording start notifications;
I can see no obvious rhyme or reason to explain when the notifications are missing

I see the same thing on my boxes.
The way this currently works is that it watches for the creation of a .nts file at the top of the My Video tree or one level down.
It then tries to open the associated .hmt file in order to check that the start time recorded in there is within two minutes of the current time.
I know that a .hmt file is periodically rewritten whilst a recording is in progress. What is probably happening here is that there is a race condition where the .nts file has been created but sometimes the associated .hmt is not yet there. I will add a loop and some retries to the .hmt opening code.
 
Also, I wondered about those "0" errors and it turns out that "ts fetch" returns either this or an object, but there is no test for the former, so I added one:
I'll add this to the next version, thanks.
 
I see the same thing on my boxes.
The way this currently works is that it watches for the creation of a .nts file at the top of the My Video tree or one level down.
It then tries to open the associated .hmt file in order to check that the start time recorded in there is within two minutes of the current time.
I know that a .hmt file is periodically rewritten whilst a recording is in progress. What is probably happening here is that there is a race condition where the .nts file has been created but sometimes the associated .hmt is not yet there. I will add a loop and some retries to the .hmt opening code.

Have these changes been made yet?

I am still missing some -start events and I haven't seen a recent update for the recmon package.

Are there similar time checks on the recording end times in hmt files when generating -stop events? If I get the crop process working in parallel with recording I could be generated fully processed recording within a few seconds of recording end so there might be an increased chance of spurious -stop notifications. Perhaps they should not be generated if the file is already flagged as decrypted.
 
There was an update on the 15th of June which added the retries. Time for plan C?
Yes, there is a similar end-time check for recording stops..

If you aren't already, running recmon with the -d flag might help track down the problem. I'll set mine up that way and keep an eye on it.
 
Last edited:
There was an update on the 15th of June which added the retries. Time for plan C?
Yes, there is a similar end-time check for recording stops..

If you aren't already, running recmon with the -d flag might help track down the problem. I'll set mine up that way and keep an eye on it.

Which file do I need to edit to add the -d flag?
 
Yes, just add -d before the -D so that the line looks like:
Code:
/mod/sbin/recmon -d -D "$dir" \
  >> /mod/tmp/recmon.log 2>&1  &
 
It would appear there might be a timing window that is sometimes missing the creation events for the recording files
Code:
2015-06-30 18:58:12 Event - [/media/My Video/The One Show]
2015-06-30 18:58:12         [CREATE,ISDIR]
2015-06-30 18:58:12         Adding watch.
2015-06-30 18:58:12 30/06/2015 18:58:12 : -stop {/media/My Video/South Today/South Today_20150630_1829}
2015-06-30 18:58:12 detectads: -stop {/media/My Video/South Today/South Today_20150630_1829}
2015-06-30 18:58:13 Event - [/media/My Video/ITV News & Weather/ITV News & Weather_20150630_1829.hmt]
2015-06-30 18:58:13         [CLOSE_WRITE,CLOSE]
2015-06-30 18:58:13 Event - [/media/My Video/South Today/South Today_20150630_1829.hmt]
2015-06-30 18:58:13         [CLOSE_WRITE,CLOSE]
2015-06-30 18:58:14 Event - [/media/My Video/South Today/.series]
2015-06-30 18:58:14         [DELETE]
2015-06-30 18:58:14 Event - [/media/My Video/South Today]
2015-06-30 18:58:14         [DELETE,ISDIR]
2015-06-30 18:58:14 Event - [/media/My Video/South Today/]
2015-06-30 18:58:14         [IGNORED]
2015-06-30 18:58:19 Event - [/media/My Video/The One Show/The One Show_20150630_1858.hmt]
2015-06-30 18:58:19         [CLOSE_WRITE,CLOSE]

The window exists between the creation of the recording directory and the successful establishment of the new watches.

The question is why the initial watches aren't being set up with the -r recursive option?

For comparison a successful start detection
Code:
2015-06-30 18:29:24 Event - [/media/My Video/South Today]
2015-06-30 18:29:24         [CREATE,ISDIR]
2015-06-30 18:29:24         Adding watch.
2015-06-30 18:29:24 Event - [/media/My Video/South Today/.series]
2015-06-30 18:29:24         [CREATE]
2015-06-30 18:29:24 Event - [/media/My Video/South Today/.series]
2015-06-30 18:29:24         [CLOSE_WRITE,CLOSE]
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.hmt]
2015-06-30 18:29:25         [CREATE]
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.hmt]
2015-06-30 18:29:25         [CLOSE_WRITE,CLOSE]
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.ts]
2015-06-30 18:29:25         [CREATE]
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.nts]
2015-06-30 18:29:25         [CREATE]
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.hmt]
2015-06-30 18:29:25         [CLOSE_WRITE,CLOSE]
2015-06-30 18:29:25 detectads: -start {/media/My Video/South Today/South Today_20150630_1829}
2015-06-30 18:29:25 30/06/2015 18:29:25 : -start {/media/My Video/South Today/South Today_20150630_1829}
2015-06-30 18:29:25 Event - [/media/My Video/South Today/South Today_20150630_1829.hmt]
2015-06-30 18:29:25         [CLOSE_WRITE,CLOSE]
 
It would appear there might be a timing window that is sometimes missing the creation events for the recording files
The window exists between the creation of the recording directory and the successful establishment of the new watches.

Nice catch. I'll ponder...

The question is why the initial watches aren't being set up with the -r recursive option?

Do you mean the -r option that tools like inotifywatch provide? That behaves in the same way as recmon, adding new watches whenever a new directory is created. inotify doesn't have a mechanism for an automatic recursive watch.
recmon only monitors the top level directories in /My Video/ as that's where new recordings will appear. It's also important to keep memory usage down as each watch consumes 540 bytes of kernel memory and we don't have a lot to play with!
 
Nice catch. I'll ponder...



Do you mean the -r option that tools like inotifywatch provide? That behaves in the same way as recmon, adding new watches whenever a new directory is created. inotify doesn't have a mechanism for an automatic recursive watch.
recmon only monitors the top level directories in /My Video/ as that's where new recordings will appear. It's also important to keep memory usage down as each watch consumes 540 bytes of kernel memory and we don't have a lot to play with!

Ah, I didn't realise that -r wasn't in the base inotify - I have only played a little with imotifywait from the command line. That would have been the simplest option for implementation!

Instead after setting up the watch on the new directory you could check whether any files had already been created in the directory and create pseudo-events for them, the complexity is knowing whether the watch had been created before or after the files to avoid duplicate -start notifications, you might need to use a lock or other mechanism to prevent this.

On saving memory do you need to monitor [Deleted items] and other special folders - although many programs are rubbish I doubt many users record directly into the dustbin!
 
There's a delay in there that I can remove by moving the start/stop processing into separate threads. That may be enough to fix this. I'll test it for a couple of days before publishing.
 
The new test version doesn't appear to suffer from the gap between a folder being created and a recording starting but it is falling into another where it reads the .hmt too early and sees a zero start time.

Code:
Event - [/media/My Video/Formula 1_ Rewind - Great Britain_20150705_1114.nts]
  [CREATE]
Start: 0 (0)
Now: 1436091242 (5599036a)
Time mismatch.

Now testing a version with a fix for this!
 
2.0.6 released - has spotted 100% here over the past two days so hopefully...!
 
I don't know what recmon.log is supposed to contain but all mine has in it in umpteen lines like this:

/media/My Video/path/file.hmt: No such file or directory

Is there meant to be something useful in here? It seems rather pointless as it is.
 
The hmt not found messages are not much help since it is not clear what process couldn't find them, when or why it was even looking since many seem to be for files in the dustbin!

One way to put some information into the log so that you have some clue as to when the other message occur is create a small executable file in the recmon.d directory, name is not important e.g. /mod/etc/recmon.d/logit
Code:
#!/mod/bin/jimsh
puts "[clock format [clock seconds] -format "%d/%m/%Y %H:%M:%S"] : $argv"
return
That will give you a time stamped message at the start and end of every recording
 
Last edited:
Back
Top