Bug #5426
closed
Recording starts twice when using EIT-based timing
Added by Dave Pickles over 6 years ago.
Updated over 6 years ago.
Found in version:
4.3-1663~g552cea0fc-dirty
Description
The attached trace shows the problem. When the 'warmup' time for the timer is reached, the server immediately detects the event as 'running' and starts recording. A short time later it sees the 'not running' status and stops. When the correct 'running' status is eventually detected the recording restarts into a new file.
I added a few extra variables to the trace statements to try to find the fault, but without success.
I don't update my 'production' TVH regularly so I'm not sure when this behaviour started - certainly before December 3. Commit 72ba707d5232bb4569e616c82c563f457826ec9c looks relevant but I don't see how it could cause the problem.
Files
There's 2 seconds delay to detect, if EPG signalize the running status. It seems that the running status is delivered a bit late in your case, thus the recording started.
You may try modify line 'if (start_time + 2 >= gclk()) {' and increase the value there.
It may be also worth to check, if EPG has those big running state signalling window (--trace tbl-eit):
diff --git a/src/epggrab/module/eit.c b/src/epggrab/module/eit.c
index 4304f3b76..c0e8a43e6 100644
--- a/src/epggrab/module/eit.c
+++ b/src/epggrab/module/eit.c
@@ -743,6 +743,7 @@ running:
case 4: run = EPG_RUNNING_NOW; break;
default: run = EPG_RUNNING_STOP; break;
}
+ tvhtrace(mod->subsys, "running for %p set to %d", ebc, run);
*save |= epg_broadcast_set_running(ebc, run);
} else if (sect == 1 && running != 2 && running != 3 && running != 4) {
}
My suggestion is a bit wrong, but the key is why 'real_start <= gclk()' is true, so the epg_running is set. The real_start should be time without the warmup subsctraction.
I added real_start to the trace statements in dvr_rec.c lines 1587 and 1637. The value in the first trace translates to 15:25 which is the scheduled start time of the event. The second is 60 seconds earlier, ie 15:24, and as this is earlier than the clock time the recording starts. real_start is being changed in line 1590
This patch fixes my issue, however I don't know whether it will break #5256.
--- dvr_rec.c.orig 2018-12-13 17:15:41.212915850 +0000
+++ dvr_rec.c 2018-12-13 17:22:56.630831452 +0000
@@ -1587,13 +1587,13 @@
tvhtrace(LS_DVR, "%s - recoding thread started for \"%s\"",
idnode_uuid_as_str(&de->de_id, ubuf), lang_str_get(de->de_title, NULL));
if (!running_disabled && de->de_bcast) {
- real_start = gclk();
+ time_t now = gclk();
switch (de->de_bcast->running) {
case EPG_RUNNING_PAUSE:
- atomic_set_time_t(&de->de_running_pause, real_start);
+ atomic_set_time_t(&de->de_running_pause, now);
/* fall through */
case EPG_RUNNING_NOW:
- atomic_set_time_t(&de->de_running_start, real_start);
+ atomic_set_time_t(&de->de_running_start, now);
break;
}
}
- Status changed from New to Fixed
- % Done changed from 0 to 100
Applied in changeset commit:tvheadend|e37c696ded59fe7c2fbaf3a42944bfeb2dd7ff92.
Thanks, it seems like variable misuse.
Also available in: Atom
PDF