[mythtv-users] Events at the beginning of a recording

Wed Jan 25 22:46:17 UTC 2023

On Wed, 25 Jan 2023 17:31:36 +0100, you wrote:

>On 24/01/2023 20:46, Ian Cameron wrote:
>> As far as I know, the recording pending events are fired
>> asynchronously.  There is no waiting for them to finish, rather, they
>> are expected to have successfully done their job before MythTV starts
>> recording (including the pre-roll).  On my system I consistently see
>> recording pending events triggered at 94, 60 and 29 seconds before the
>> pre-roll is due to start.
>
>I don't see that. What I see is as follows:
>
>Only one recording-pending event is triggered, not three as you observe
>on your system.
>
>The order I see is as follows:
>
>1. The recording-started event is triggered first, almost simultaneously
>with the mythexternalrecorder's tuner command (at "second 0").
>
>2. The recording-pending event is triggered next, at "second 5". So 5
>seconds after the recording has already started.
>
>Do you know whether these timings are parameters that I may have
>misconfigured in the database? My database is quite old and has been
>upgraded many times over the 15+ years that it has been in use.
>
>Also, assuming I can get these events into the correct order, my
>situation is that I need to power up the set-top box, and it takes quite
>some time to boot to a condition in which it is able to accept infrared
>commands (i.e. able to change channels).

What is supposed to happen is that the recording-pending event happens
first, typically about 60 seconds before the start of the recording.
From that event, you are supposed to start anything that needs
starting, and tune your set top box (or whatever is providing the
signal) to the correct channel.

Then at the exact time the recording starts, the recording-started
event happens.  When this happens depends on the settings for
pre-roll, including the global one (typically 60 seconds) and the one
on the recording rule, which in my case is set according to the
channel and may be 1, 2 or 3 minutes.

On my mother's MythTV box where I used to do FM radio recordings using
these events, that was how it worked, but that was many years ago.  On
the box I still have a script "event_test.sh" that is run by a number
of events (including the "ANY" event) and logs when it happens:

#!/bin/bash

me=$(/usr/bin/basename "${0}")
log=/var/log/mythtv/event_test.log
echo `date` "$me $@" >>$log
exit 0

I also have "event-start-recording.sh" and
"event-finished-recording.sh" scripts on the appropriate events.

The logging shows that the first recording-pending event is happening
well before the recording-started event, but there are multiple
recording-pending events happening.  Here is an example of the
logging:

Wed 25 Jan 2023 19:26:00 NZDT event_test.sh Any REC_PENDING %SENDER%
90 10073 2023-01-25T05:30:00Z 2023-01-25T06:30:00Z
2023-01-25T05:30:00Z 2023-01-25T06:30:00Z 120 0 Default
Wed 25 Jan 2023 19:26:00 NZDT event_test.sh RecordingPending %SENDER%
90 10073 2023-01-25T05:30:00Z 2023-01-25T06:30:00Z
2023-01-25T05:30:00Z 2023-01-25T06:30:00Z 120 0 Default
Wed 25 Jan 2023 19:26:00 NZDT event_test.sh Any SCHEDULER_RAN crw-pvr
%HOSTNAME% %CARDID% 0 %DIR% %FILE% %PROGSTARTISOUTC% %PROGENDISOUTC%
%STARTTIMEISOUTC% %ENDTIMEISOUTC% %SECS% %REACTIVATE% %RECGROUP%
Wed 25 Jan 2023 19:26:00 NZDT event_test.sh SchedulerRan crw-pvr
%HOSTNAME% %CARDID% 0 %DIR% %FILE% %PROGSTARTISOUTC% %PROGENDISOUTC%
%STARTTIMEISOUTC% %ENDTIMEISOUTC% %SECS% %REACTIVATE% %RECGROUP%
Wed 25 Jan 2023 19:26:31 NZDT event_test.sh Any REC_PENDING %SENDER%
90 10073 2023-01-25T05:30:00Z 2023-01-25T06:30:00Z
2023-01-25T05:30:00Z 2023-01-25T06:30:00Z 88 0 Default
Wed 25 Jan 2023 19:26:31 NZDT event_test.sh RecordingPending %SENDER%
90 10073 2023-01-25T05:30:00Z 2023-01-25T06:30:00Z
2023-01-25T05:30:00Z 2023-01-25T06:30:00Z 88 0 Default
Wed 25 Jan 2023 19:27:00 NZDT event_test.sh Any REC_STARTED %SENDER%
crw-pvr 90 10073 GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/crw-pvr
10073_20230125062700.ts 2023-01-25T06:30:00Z 2023-01-25T07:30:00Z
2023-01-25T06:27:00Z 2023-01-25T07:34:00Z %SECS% 0 Default
Wed 25 Jan 2023 19:27:00 NZDT event-start-recording.sh %SENDER%
crw-pvr 90 10073 GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/crw-pvr
10073_20230125062700.ts
Wed 25 Jan 2023 19:27:00 NZDT event-start-recording.sh Exiting now
Wed 25 Jan 2023 19:27:00 NZDT event_test.sh Any REC_PENDING %SENDER%
crw-pvr 90 10073 GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/crw-pvr
10073_20230125062700.ts 2023-01-25T06:30:00Z 2023-01-25T07:30:00Z
2023-01-25T06:27:00Z 2023-01-25T07:34:00Z 0 0 Default
Wed 25 Jan 2023 19:27:00 NZDT event_test.sh RecordingPending %SENDER%
crw-pvr 90 10073 GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/crw-pvr
10073_20230125062700.ts 2023-01-25T06:30:00Z 2023-01-25T07:30:00Z
2023-01-25T06:27:00Z 2023-01-25T07:34:00Z 0 0 Default
Wed 25 Jan 2023 19:27:04 NZDT event_test.sh Any REC_STARTED_WRITING
%SENDER% crw-pvr 90 10073 /mnt/rec3/recordings 10073_20230125062700.ts
2023-01-25T06:30:00Z 2023-01-25T07:30:00Z 2023-01-25T06:27:00Z
2023-01-25T07:34:00Z %SECS% 0 Default
Wed 25 Jan 2023 20:38:00 NZDT event_test.sh Any REC_FINISHED %SENDER%
crw-pvr 90 10073 /mnt/rec3/recordings 10073_20230125062700.ts
2023-01-25T06:30:00Z 2023-01-25T07:30:00Z 2023-01-25T06:27:00Z
2023-01-25T07:38:00Z %SECS% 0 Default
Wed 25 Jan 2023 20:38:00 NZDT event-finished-recording.sh %SENDER%
crw-pvr 90 10073 /mnt/rec3/recordings 10073_20230125062700.ts
Wed 25 Jan 2023 20:38:00 NZDT event_test.sh Any SCHEDULER_RAN crw-pvr
%HOSTNAME% %CARDID% 0 %DIR% %FILE% %PROGSTARTISOUTC% %PROGENDISOUTC%
%STARTTIMEISOUTC% %ENDTIMEISOUTC% %SECS% %REACTIVATE% %RECGROUP%
Wed 25 Jan 2023 20:38:00 NZDT event_test.sh SchedulerRan crw-pvr
%HOSTNAME% %CARDID% 0 %DIR% %FILE% %PROGSTARTISOUTC% %PROGENDISOUTC%
%STARTTIMEISOUTC% %ENDTIMEISOUTC% %SECS% %REACTIVATE% %RECGROUP%

Sorry about all the long lines being wrapped - my email client does
that and it does not have an option to not do it.  I would suggest
copying those lines to an editor and unwrapping them to be able to
read them properly - Each line starts with "Wed 25 Jan".

As well as just the recording-pending and recording-started events,
there are now also events added in more recent versions of MythTV than
when I was using these scripts, which includes a "recording-writing"
event that happens when the recording file is actually being written
to.

If you want to see all the event activity, try adding a script like
mine to the EventCmdAll event:

MariaDB [mythconverg]> select * from settings where value like
'EventCmdAll';
+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+
| value       | data                                                                                                                                                                                               | hostname |
+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+
| EventCmdAll | /usr/local/bin/event_test.sh Any %EVENTNAME% %SENDER% %HOSTNAME% %CARDID% %CHANID% %DIR% %FILE% %PROGSTARTISOUTC% %PROGENDISOUTC% %STARTTIMEISOUTC% %ENDTIMEISOUTC% %SECS% %REACTIVATE% %RECGROUP% | crw-pvr  |
+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+

The %EVENTNAME% parameter will allow the script to log the name of the
event.