Bug #5056
Wrongly matched autorec entry when TVHeadend starts up
0%
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
[36m2018-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[0m
2018-04-03 04:04:40
stdout
[32m2018-04-03 04:04:40.209 [ INFO] dvr: "ZDF SPORTreportage" on "RTL": Updated Timer (ostgi)[0m
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.
Files
History
Updated by da h4xX0rz1sT over 6 years ago
Updated by 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.
Updated by da h4xX0rz1sT over 6 years 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.
Updated by Frank Rieger over 6 years ago
Updated by I checked that also today with version 4.3-1236~g518d57bee and cannot reproduce the error. Seems that it is fixed now 
Many thanks.
Updated by da h4xX0rz1sT over 6 years ago
- File TVh-autorec-Tagesschau_outside-time-window.png TVh-autorec-Tagesschau_outside-time-window.png added
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?
Updated by Jaroslav Kysela over 6 years ago
Updated by 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.
Updated by da h4xX0rz1sT over 6 years 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.
Updated by da h4xX0rz1sT over 6 years 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.
Updated by Arne Drees almost 6 years ago
Updated by 
I'm having the same issues (Tagesschau ) with tvh 4.2.7. I've had the idea to develop a small python script that updates all autorecs without really changing anything (because this helps). This could be a workaround until this (old) bug get fixed. You can get the script here: https://github.com/arneman/tvh_upd_autorec
Updated by da h4xX0rz1sT almost 6 years ago
Arne,
as far I can tell, this issue is gone here since I'm on master branch, that's starting from tvheadend_4.3-1468~g3f74523d2.
Frank has reported it for 4.3-1221~g25dfdb64f, so I guess it has been fixed somewhere in between, maybe without even being noticed, just as a side effect of some other fix.
This issue seems to be fixed, at least on master - haven't seen it for quite some while.
If I run into that issue again, I'll give your script a try and report here...
HTH,
/HXZ
Updated by Arne Drees almost 6 years ago
da h4xX0rz1sT wrote:
Arne,
as far I can tell, this issue is gone here since I'm on master branch, that's starting from tvheadend_4.3-1468~g3f74523d2.
Frank has reported it for 4.3-1221~g25dfdb64f, so I guess it has been fixed somewhere in between, maybe without even being noticed, just as a side effect of some other fix.
I'm running tvheadend in a productive environment - that's why I use the stable release, not development. I'm hoping that the fix will be in the stable releases soon.
BTW: Maybe someone can update this issue ticket, if it is already fixed.
Regards
Arne