Bug #5056

Wrongly matched autorec entry when TVHeadend starts up

Added by Frank Rieger 4 months ago. Updated 2 months ago.

Status:NewStart date:2018-04-03
Priority:NormalDue date:
Assignee:Adam Sutton% Done:

0%

Category:PVR / DVR
Target version:-
Found in version:4.3-1221 Affected Versions:

Description

I'm using TVH in Docker on a Synology NAS. My NAS does not run 24x7. Therefore TVH periodically restarts. On every restart I was aware that some recordings (most often autorecs) do not meet the former recording specifications.
Last one occured today morning, see attached picture.

This is from the log during startup procedure:
2018-04-03 04:04:40
stdout
2018-04-03 04:04:40.211 [ NOTICE] START: HTS Tvheadend version 4.3-1221~g25dfdb64f started, running as PID:205 UID:1031 GID:100, CWD:/run/s6/services/tvheadend CNF:/config
2018-04-03 04:04:40
stdout
2018-04-03 04:04:40.209 [   INFO] dvr: "ZDF SPORTreportage" on "RTL": Updated Timer (ostgi)

As you can see an epg record from channel ZDF is matched to a recording/channel from RTL. So the channels are puzzled, but sometimes it occurs also within the same channel. This issue occurs only during startup.
OTA epg is grabbed at 7:04 and there are no issues after grabbing new data.

Wong Autorec.jpg - autorec entry for channel RTL (77.3 KB) Frank Rieger, 2018-04-03 11:59

TVh-autorec-Tagesschau.png (44.6 KB) da h4xX0rz1sT, 2018-04-06 18:00

TVh-autorec-Tagesschau_outside-time-window.png (159 KB) da h4xX0rz1sT, 2018-04-22 11:50

History

#1 Updated by da h4xX0rz1sT 3 months ago

I'm experiencing a very similar problem to Frank's on 4.2.6-14~ga9e00e5, without using docker.

I have an AutoRecording set to record "Tagesschau" (German news) every day, in a time frame from 19:50 to 20:40 (see screen shot).

When starting up, TVh always catches the "Tagesschau" also outside this time frame, in a very unpredictable, irregular way. When it's running and I deleted the recordings outside the time frame, it works reliable and never picks up any broadcast outside the time frame any more.

So I guess something must be fundamentally (or subtly) different in EPG check on startup and when running.

#2 Updated by da h4xX0rz1sT 3 months ago

Having double checked that again, I can no longer reproduce my issue described above. It seems it has been resolved with one of the latest commits on stable branch.

#3 Updated by Frank Rieger 3 months ago

I checked that also today with version 4.3-1236~g518d57bee and cannot reproduce the error. Seems that it is fixed now :)

Many thanks.

#4 Updated by da h4xX0rz1sT 3 months ago

Unfortunately, this bug is NOT fixed.

Formerly, it was reproducible for me on EVERY restart. Since some of the latest commits, this changed. But after a TVh crash yesterday night, the problem reappeared.

The only thing that was noticeable in the log:
Apr 22 07:46:39 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:41 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:41 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:41 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:43 tvhserver tvheadend27109: dvr: "heute-show" on "ZDF": Updated (B)
Apr 22 07:46:43 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:43 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:47 tvhserver tvheadend27109: dvr: "Tagesschau" on "Das Erste": Updated Timer (osiB)
Apr 22 07:46:57 tvhserver tvheadend27109: dvr: "heute-show" on "ZDF": Updated (B)
[...]
Apr 22 07:48:55 tvhserver tvheadend27109: tbl-base: sdt: 738MHz in DVB-T Nbg: invalid checksum (len 398, errors 1)
Apr 22 07:48:55 tvhserver tvheadend27109: tbl-base: cat: 738MHz in DVB-T Nbg: invalid checksum (len 18, errors 1)
Apr 22 07:48:56 tvhserver tvheadend27109: tbl-base: pat: 738MHz in DVB-T Nbg: invalid checksum (len 2240, errors 1)

So it seems like auto recordings are updated BEFORE the integrity of all tables is checked/corrected - this might lead to that error.

(Though that "738MHz in DVB-T Nbg" is NOT the frequency where the affected channel "Das Erste" is.)

I've attached a screen shot where "Tagesschau" was again picked up outside the scheduled time frame, wrong entries are highlighted.

On the second restart no table errors appeared (obviously fixed during first restart), and everything went as expected (without scheduling recordings that don't meet the programmed criteria).

Frank, can you check if you also had table inconsistencies when the error happened?

#5 Updated by Jaroslav Kysela 3 months ago

If you see the invalid checksum, the table contents is dropped. The updated timer is that EPG updated the event (if the epggrab in in the progress) and the changes are propagated to the DVR entry. It might be the culprit, but you need to investigate the EPG import - probably '--trace tbl-eit' . If you see the updated timer messages just after tvh's start (without epggrab) it maybe another issue.

#6 Updated by da h4xX0rz1sT 3 months ago

Hi Jaroslav,

it happened right after startup - epggrab ran before the log entries shown above (I'm using OTA DVB Grabber).

I don't even know why epggrab runs on startup, it is just scheduled for the default time. The weird thing to notice is, epggrab on startup is just triggered for DVB-T, not for DVB-S (I'm using both in parallel, DVB-T from local receivers and DVB-S from SAT>IP box).

But for me this really is a minor issue, currently i'm struggling more with recording issues on encrypted channels - will report on that when I've investigated it so far I can send a useful bug report.

Thank you for all your efforts.

#7 Updated by da h4xX0rz1sT 2 months ago

See also #4454 which describes a problem exactly similar to mine (even the same use case recording "Tagesschau"), but not neccssarily to Frank's.

Also available in: Atom PDF