Bug #4401
Use EITp/f outside the EPG event database (move fuzzy match from DVR to EPG routines)
0%
Files
History
Updated by Jaroslav Kysela over 7 years ago
Provide '--trace dvr,tbl-eit' log. https://tvheadend.org/projects/tvheadend/wiki/Traces
Updated by Eric Valette over 7 years ago
- File tvheadend.log tvheadend.log added
Here is a small extract. Tell me if you have enough info...
Updated by Eric Valette over 7 years ago
Only thing I noticed is the absence on accentuated characters in the traces...
Updated by Eric Valette over 7 years ago
Eric Valette wrote:
Only thing I noticed is the absence on accentuated characters in the traces...
And also I have no clue about the eit time offset correct value. It is currently set to UTC. UI see +200 both in dvr traces and eit traces...
Updated by Jaroslav Kysela over 7 years ago
I don't see any active recordings in the log. I need the log for the operation which does not work.
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
I don't see any active recordings in the log. I need the log for the operation which does not work.
OK but at the requested trace level, it created a 2 MB file in a couple of minutes, so doing it on true recording will create a GB file that I will be unable to upload. I will need to try test recording of really small thing...
Updated by Jaroslav Kysela over 7 years ago
The log for start of recordings (warmup time + one minute of recordings) should be enough. Use bzip2 or gzip to compress the log file.
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
The log for start of recordings (warmup time + one minute of recordings) should be enough. Use bzip2 or gzip to compress the log file.
Ok then. Will do when back home after work.
Updated by Eric Valette over 7 years ago
- File tvheadend.log.gz tvheadend.log.gz added
Eric Valette wrote:
Jaroslav Kysela wrote:
The log for start of recordings (warmup time + one minute of recordings) should be enough. Use bzip2 or gzip to compress the log file.
Ok then. Will do when back home after work.
So here it is. I programmed a record for an Arte program called "Identités douloureuses" whose original scheduling time was 22h55. With a prerecording time of 2 minutes, it effectively started recording at 22h53. I was lucky because the real start shifted to to 22h58 (at least this is what I saw using epg information display on TV set while recording it using another tuner). The trace shows that a change related to this program was found in the eit at 22:58:50.460. Probably previously, you have other traces related to this program but it should be when it is still the next program.
Note that eit has only "current" and "next" in France for most programs.
A stat of the file show that it has been created on 22:53:00
stat /pvrRecords/Identites-douloureuses-Arte2017-05-30.mkv
Fichier : /pvrRecords/Identites-douloureuses-Arte2017-05-30.mkv
Taille : 239731417 Blocs : 468240 Blocs d'E/S : 4096 fichier
Périphérique : 811h/2065d Inœud : 55 Liens : 1
Accès : (0664/-rw-rw-r--) UID : ( 118/ hts) GID : ( 44/ video)
Accès : 2017-05-30 22:53:00.010831090 +0200
Modif. : 2017-05-30 23:01:04.325111038 +0200
Changt : 2017-05-30 23:01:04.325111038 +0200
Créé : -
And playing the recorded file shows that if effectively started pushing tv stream to the file at 22h53 instead of 22h58. So it exhibit the wrong behavior.
grep -i doulou /pvrRecords/tvheadend.log (search for douloureuse)
2017-05-30 22:46:46.195 [ INFO]:dvr: entry 65467e80ef3dac166cbe6ee483ecb7d2 "Identités douloureuses" on "Arte" starting at 2017-05-30 22:52:30, scheduled for recording by "valette"
2017-05-30 22:52:30.002 [ INFO]:dvr: "Identités douloureuses" on "Arte" recorder starting
2017-05-30 22:52:30.003 [ INFO]:subscription: 0009: "DVR: Identités douloureuses" subscribing on channel "Arte", weight: 300, adapter: "DiBcom 7000PC : DVB-T #0", network: "TNT", mux: "698MHz", provider: "Multi4", service: "Arte", profile="matroska"
2017-05-30 22:52:30.980 [ TRACE]:tbl-eit: 65 6E 74 69 74 E9 73 20 64 6F 75 6C 6F 75 72 65 entit.s douloure
2017-05-30 22:52:43.307 [ TRACE]:tbl-eit: 49 64 65 6E 74 69 74 E9 73 20 64 6F 75 6C 6F 75 Identit.s doulou
2017-05-30 22:53:00.010 [ DEBUG]:dvr: File "/pvrRecords/Identites-douloureuses-Arte2017-05-30.mkv" -- No such file or directory -- Using for recording
2017-05-30 22:53:00.346 [ INFO]:dvr: /pvrRecords/Identites-douloureuses-Arte2017-05-30.mkv from adapter: "DiBcom 7000PC : DVB-T #0", network: "TNT", mux: "698MHz", provider: "Multi4", service: "Arte"
2017-05-30 22:58:50.460 [ TRACE]:tbl-eit: 65 6E 74 69 74 E9 73 20 64 6F 75 6C 6F 75 72 65 entit.s douloure
2017-05-30 23:01:04.254 [ ERROR]:dvr: Recording stopped: "/pvrRecords/Identites-douloureuses-Arte2017-05-30.mkv": Subscription overridden
2017-05-30 23:01:04.384 [ INFO]:subscription: 0009: "DVR: Identités douloureuses" unsubscribing from "{name-not-set}"
Updated by Jaroslav Kysela over 7 years ago
It seems that the program starts at 22:58:33, right?
2017-05-30 22:52:30.980 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 27, tbl=4e, running=1, start=2017-05-30;22:58:33(+0200), stop=2017-05-30;23:54:05(+0200), ebc=(nil) 2017-05-30 22:52:31.463 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 26, tbl=4e, running=4, start=2017-05-30;22:45:30(+0200), stop=2017-05-30;22:58:33(+0200), ebc=(nil) .... 2017-05-30 22:58:36.446 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 26, tbl=4e, running=4, start=2017-05-30;22:45:30(+0200), stop=2017-05-30;22:58:33(+0200), ebc=(nil) 2017-05-30 22:58:36.941 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 27, tbl=4e, running=1, start=2017-05-30;22:58:33(+0200), stop=2017-05-30;23:54:05(+0200), ebc=(nil) 2017-05-30 22:58:37.449 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 26, tbl=4e, running=4, start=2017-05-30;22:45:30(+0200), stop=2017-05-30;22:58:33(+0200), ebc=(nil) 2017-05-30 22:58:50.460 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 27, tbl=4e, running=4, start=2017-05-30;22:58:33(+0200), stop=2017-05-30;23:54:05(+0200), ebc=(nil) .... ^^^^ eid 27 active now (running=4) 2017-05-30 22:58:50.969 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 28, tbl=4e, running=1, start=2017-05-30;23:54:05(+0200), stop=2017-05-31;00:53:39(+0200), ebc=(nil) 2017-05-30 23:00:18.476 [ TRACE]:tbl-eit: svc='Arte', ch='Arte', eid= 27, tbl=4e, running=4, start=2017-05-30;22:58:33(+0200), stop=2017-05-30;23:54:05(+0200), ebc=(nil)
The ebc=(nil) means that other grabber created event with a bigger priority, so this event is ignored. What's the source of your EPG events (you said that the broadcaster sends only "current" and "next" events through EIT)?
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
It seems that the program starts at 22:58:33, right?
[...]
The ebc=(nil) means that other grabber created event with a bigger priority, so this event is ignored. What's the source of your EPG events (you said that the broadcaster sends only "current" and "next" events through EIT)?
I have two grabbers : xmltv one with priority 5 (this is the one that has been used to setup the recording) and DVB EIT at priority one. Can'y send you the epg module config image right now...
Updated by Eric Valette over 7 years ago
Eric Valette wrote:
Jaroslav Kysela wrote:
It seems that the program starts at 22:58:33, right?
[...]
The ebc=(nil) means that other grabber created event with a bigger priority, so this event is ignored. What's the source of your EPG events (you said that the broadcaster sends only "current" and "next" events through EIT)?
I have two grabbers : xmltv one with priority 5 (this is the one that has been used to setup the recording) and DVB EIT at priority one. Can'y send you the epg module config image right now...
NB as I program the recording usually long before the eit has information about the program (e.g I program a recording for 2 am at 10 pm) I most of the time will end up using the xmltv EPG. But what I expected is that it use the eit to start recording and end it when eit says it is really happening. Its not unusual to have up to 20 min lateness and even if I can add +20 min at the end of the recording I do not want to have to manually edit the mkv to remove the 2 min before and the 20 min after...
Updated by Eric Valette over 7 years ago
Eric Valette wrote:
Jaroslav Kysela wrote:
It seems that the program starts at 22:58:33, right?
Yes. Its the time it really started.
Updated by Jaroslav Kysela over 7 years ago
Try to set the EIT grabber priority to 10, so it will overwrite the XMLTV events. When the event is replaced in EPG and the title and time (in some margin) match with the old event, it should be handled correctly in DVR.
Perhaps, we should add a special priority for current/next events in EIT to separate the running state (accurate recordings) from the rest of EIT.
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
Try to set the EIT grabber priority to 10, so it will overwrite the XMLTV events. When the event is replaced in EPG and the title and time (in some margin) match with the old event, it should be handled correctly in DVR.
I was under the impression that priority 1 was support to 5 (wrong web help on the field) and as mentioned in the thread https://tvheadend.org/boards/5/topics/26631?r=26644#message-26644. At least it is what I remmeber but cannot check right now.
Perhaps, we should add a special priority for current/next events in EIT to separate the running state (accurate recordings) from the rest of EIT.
Then I do not understand what "accurate recording means". It should alway check only EIT status indépendently of epg priority (and again I'm not sure from memory that what you suggest is coherent with online web page help for priority) especially because with only current and next in most countries, you cannot rely on EIT to setup your EPG.
Updated by Eric Valette over 7 years ago
Eric Valette wrote:
Jaroslav Kysela wrote:
Try to set the EIT grabber priority to 10, so it will overwrite the XMLTV events. When the event is replaced in EPG and the title and time (in some margin) match with the old event, it should be handled correctly in DVR.
I was under the impression that priority 1 was support to 5 (wrong web help on the field) and as mentioned in the thread https://tvheadend.org/boards/5/topics/26631?r=26644#message-26644. At least it is what I remmeber but cannot check right now.
Perhaps, we should add a special priority for current/next events in EIT to separate the running state (accurate recordings) from the rest of EIT.
Then I do not understand what "accurate recording means". It should alway check only EIT status indépendently of epg priority (and again I'm not sure from memory that what you suggest is coherent with online web page help for priority) especially because with only current and next in most countries, you cannot rely on EIT to setup your EPG.
In other words I was expecting something like:
1) Start the recording thread at original epg time, or at least tune to the correct channel to get the packets and eit,
2) When receiving valid TS packets, drop them as long as eit->current name is not equal to epg programed name,
3) when eit->current changes, close the recording immediately or wait until end but do not record any more ts packets,
A bit naive maybe...
Updated by Mark Clarkstone over 7 years ago
Eric Valette wrote:
Jaroslav Kysela wrote:
Try to set the EIT grabber priority to 10, so it will overwrite the XMLTV events. When the event is replaced in EPG and the title and time (in some margin) match with the old event, it should be handled correctly in DVR.
I was under the impression that priority 1 was support to 5 (wrong web help on the field) and as mentioned in the thread https://tvheadend.org/boards/5/topics/26631?r=26644#message-26644. At least it is what I remmeber but cannot check right now.
Perhaps, we should add a special priority for current/next events in EIT to separate the running state (accurate recordings) from the rest of EIT.
Then I do not understand what "accurate recording means". It should alway check only EIT status indépendently of epg priority (and again I'm not sure from memory that what you suggest is coherent with online web page help for priority) especially because with only current and next in most countries, you cannot rely on EIT to setup your EPG.
It's what many providers here [the UK] use as a non-technical term for "EITp/f". And to check, I've updated my version to 4.3-184 and started a recording. From my limited testing it appears that EITp/f is working correctly, at least for me..
2017-05-31 12:02:47.150 [ DEBUG]:dvr: dvr entry 8d93a3514a0482854e62c7128e8e4264 event Money for Nothing on BBC One HD - EPG marking start 2017-05-31 12:02:47.208 [ DEBUG]:dvr: File "/md0/tvheadend/dvr/BBC One HD/Money for Nothing2017-05-31.ts" -- No such file or directory -- Using for recording 2017-05-31 12:02:47.209 [ INFO]:dvr: /md0/tvheadend/dvr/BBC One HD/Money for Nothing2017-05-31.ts from adapter: "Silicon Labs Si2168 : DVB-T #0 CC", network: "DVB-T - Waltham", mux: "770MHz", provider: "<N/A>$ 2017-05-31 12:02:47.209 [ INFO]:dvr: # type lang resolution aspect ratio sample rate channels 2017-05-31 12:02:47.209 [ INFO]:dvr: 1 H264 1920x1080 ? 2017-05-31 12:02:47.209 [ INFO]:dvr: 2 AAC eng ? ? 2017-05-31 12:02:47.209 [ INFO]:dvr: 3 AAC eng ? ? 2017-05-31 12:02:47.209 [ INFO]:dvr: 4 DVBSUB eng 2017-05-31 12:02:57.894 [ DEBUG]:tbl-eit: eit: completed pid 18 table 00000000 / 00000000
And this is with my machine's time being out by 15-18 mins!
I've now corrected the time & have started another recording, will report back if I find anything amiss.
Updated by Eric Valette over 7 years ago
Mark Clarkstone wrote:
From my limited testing it appears that EITp/f is working correctly, at least for me..
As you see its not working for me. You have all the trace and Jaroslav confirm the non correct behavior at least for me :-).
Updated by Mark Clarkstone over 7 years ago
Eric Valette wrote:
Mark Clarkstone wrote:
From my limited testing it appears that EITp/f is working correctly, at least for me..
As you see its not working for me. You have all the trace and Jaroslav confirm the non correct behavior at least for me :-).
I'm not saying you don't have a problem, The point of my post was to show that it is indeed working as intended for me, hence the "at least for me" part.
Updated by Eric Valette over 7 years ago
Mark Clarkstone wrote:
I'm not saying you don't have a problem, The point of my post was to show that it is indeed working as intended for me, hence the "at least for me" part.
The real goal is to make it work for both of us. From your post, it is not clear for me if you have a complete epg or just a current/next version (not englsih native), or if when you program the recording do you have already the eit for the target available?
That seems to be the problem in my case. I will never have it since before film in France that start around 9pm, you have a lot of 5 min stuff before enabling to maximize the volume of advertisement without infringing the not more than x min advertisement in a raw... So I will not get the correct epg via eit before around 5 mins before film start and I do not want to wait for it.
Updated by Mark Clarkstone over 7 years ago
Eric Valette wrote:
Mark Clarkstone wrote:
I'm not saying you don't have a problem, The point of my post was to show that it is indeed working as intended for me, hence the "at least for me" part.
The real goal is to make it work for both of us.
Of course it should work for everyone!
From your post, it is not clear for me if you have a complete epg or just a current/next version (not englsih native), or if when you program the recording do you have already the eit for the target available?
I have four OTA grabbers enabled.
[DVB-S] OpenTV Sky UK = 1 Freesat = 2 [DVB-T] Freeview = 3 [ANY] EIT = 4
My channels from DVB-T and -S are merged together & I've set the DVB-T tuners to be used first. In my case I suspect the EIT now/next data overrides the data from the other grabbers. I see this when watching via Kodi as the data before I play a channel changes slightly. I suppose this is because they both almost match.
That seems to be the problem in my case. I will never have it since before film in France that start around 9pm, you have a lot of 5 min stuff before enabling to maximize the volume of advertisement without infringing the not more than x min advertisement in a raw...
They do the same thing here in the UK, but they also split very long programmes (such as movies) into two which means they can be classed as two separate programmes & throw in more advertisements.
So I will not get the correct epg via eit before around 5 mins before film start and I do not want to wait for it.
It's up to the broadcaster as to when they send these flags, you can't control when they do, some send the flags earlier so that adverts and bumpers get included.
Updated by Jaroslav Kysela over 7 years ago
- Subject changed from accurate recording does not work + EIT prority should be automatically maximum to Use EITp/f outside the EPG event database (move fuzzy match from DVR to EPG routines)
OK, I see the point. The EITp/f (accurate recordings) info should be handled completely at the EPG level without the requirement of the event replacement in the EPG database. In this way, only one EPG source may be active (events are not overwritten), but the additional information (running status) can be sent to DVR.
Current behaviour:
XMLTV events (lower priority) -> DB updates EIT events (higher priority) -> DB overwrites, sent EITp/f (running status) to DVR through those events
New behaviour:
XMLTV events (higher priority) -> DB updates EIT events (lower priority) -> no DB updates (ignoring info), but add fuzzy check for the event match (title, time margin) - matches - sent EITp/f (running status) info to DVR
Is this clear?
Updated by Eric Valette over 7 years ago
Mark Clarkstone wrote:
[ANY]
EIT = 4
So you have a higher number for EIT here when I have a lower one as the guy that initially reported the problem...
But as said, priority of EIT for EPG and using EIT for "accurate recordings" could be something else. From memory on DVB-S you get full EPG via dvb-S tunners in France.
Will try to change the priority order to see if something change.
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
OK, I see the point. The EITp/f (accurate recordings) info should be handled completely at the EPG level without the requirement of the event replacement in the EPG database. In this way, only one EPG source may be active (events are not overwritten), but the additional information (running status) can be sent to DVR.
Current behaviour:
[...]
New behaviour:
[...]
Is this clear?
Yes crystal clear and I agree it is a much more intuitive solution.
Updated by Mark Clarkstone over 7 years ago
Jaroslav Kysela wrote:
OK, I see the point. The EITp/f (accurate recordings) info should be handled completely at the EPG level without the requirement of the event replacement in the EPG database. In this way, only one EPG source may be active (events are not overwritten), but the additional information (running status) can be sent to DVR.
Current behaviour:
[...]
New behaviour:
[...]
Is this clear?
I think this may break EITp/f for us here in the UK to some degree. Under certain circumstances [I'm thinking of the recent bombing in Manchester] the broadcaster will often replace or extend programming, they will also update the EITp/f to reflect the changes, title, description, times, the works basically. At present TVH handles this perfectly (Kodi on the other hand not so much).
Updated by Jaroslav Kysela over 7 years ago
Code (mostly untested) is in v4.3-185-g3c44ff2 . It is activated only if EIT grabber has lower priority than other source (like XMLTV).
Updated by Eric Valette over 7 years ago
Jaroslav Kysela wrote:
Code (mostly untested) is in v4.3-185-g3c44ff2 . It is activated only if EIT grabber has lower priority than other source (like XMLTV).
Thanks Jaroslav. I will test it when back home. Side question, If you select "precise recording", why do you still need to select eit as an EPG source and give it a prority? Having an eit as EPG source is indeed fine for people that have the chance to get a full epg via EIT but with only current/next by many broadcaster, it's of no use as an epg except for this precise use case...
Nerveless thanks again for your time and I will test ASAP (long week-end here).
Updated by saen acro over 7 years ago
after this code added
tvh:mi-table[30668]: segfault at 90 ip 00005596b5f1b030 sp 00007fe09de94d18 error 4 in tvheadend[5596b5d38000+1100000]