Project

General

Profile

Bug #6107

Recording two subsequent shows using REST API is failing

Added by Andreas Maier almost 3 years ago. Updated almost 3 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
PVR / DVR
Target version:
-
Start date:
2021-12-12
Due date:
% Done:

0%

Estimated time:
Found in version:
Build: 4.3-1983~gb8710206e (2021-11-21T16:17:52+0100)
Affected Versions:

Description

TL;DR
Recording using webif works correctly
Recording using REST API does not work correctly in all situations

Hello devteam,

I want to report a bug when using the recorder, it's a little bit difficult to explain, I also made some tests with the API myself and got around it but do not know how to fix it in code.

I am using a TVH client software on my Amazon TV-Stick where I sometimes want to record two different episodes of a show which are broadcasted in direct sequence which is failing.

As said it's a little bit difficult to explain, therefore I will make an example: Lets assume I want to record two episodes of "Super-Cool-Show" which are broadcasted by e.g. "RTL Televsision" the same day in sequence. Please note that the description of the shows are the same but the episodes are really different:

RTL Television, Super-Cool-Show, 01.06.2021 15:30 - 16:30
RTL Television, Super-Cool-Show, 01.06.2021 16:30 - 17:30

Now, I am marking both episodes with my TVH client software in Amazon Fire TV, which will then, if I open up the TVH webif, show nicely under "planned recordings", like this:

Planned >> RTL Television, Super-Cool-Show, 01.06.2021 15:30 - 16:30
Planned >> RTL Television, Super-Cool-Show, 01.06.2021 16:30 - 17:30

So everything is cool right now, but if the time has come to start recording of the first episode of the show the following happens: The second entry which should be recorded an hour later will be recorded, too and if I now take a look into the TVH webif now I see the following entries in the "recording" section:

RECORDING >> RTL Television, Super-Cool-Show, 01.06.2021 15:30 - 16:30
RECORDING >> RTL Television, Super-Cool-Show, 01.06.2021 15:30 - 16:30 !!!!

The second entry which is now also recorded, "morphed" its time from "01.06.2021 16:30 - 17:30" to the first one and also started recording.
If you have no unique recording-filenames, TVHeadend will crash now. Even if you restart the service, since it always want to recreate the same files. You will then have to wait until both shows are over. I managed to make the filenames unique then it is working and you will end up in having recorded the same show (the first one) twice. By the way, if you are recording more subsequent shows you will end up in having the first show recorded multiple times.

If I do the same on the TVH webif (not using the TVH client software) it records fine both shows. Therefore, with this information I first asked the developer of the TV client software because it looked like something is wrong on "his" side).

He told me that he is just using the REST API to create the entries and he never experienced stuff like I reported. So I made some more tests on my side:

If I am using e.g. POSTMAN and the REST-API to create the same entries above using endpoint POST dvr/entry/create with e.g.:

{"start": 1623358800, "stop": 1623360600, "channelname": "Pearl.tv HD Shop", "title": { "ger": "Das Beste aus dem Katalog" }}

(and also the second call with different times, don't have the json anymore, it is basically the same with different start/stop)

It results in the failed behaviour. So this is failing.

If I use the endpoint dvr/entry/create_by_event which is using UUIDs to record the shows. It is working fine.

Also interresting, if I create the two "failing" record-entries, either with the TVH client software or the TVH REST API (well basically it is the same), and afterwards editing the entries with the TVH webif (changing something irrelevant) the entries are somehow corrected then. Then the shows are recorded fine. It looks like the webif correctes something while saving the entries.

The change of the other, subsequent entries, will be changed let's say 5 seconds after the first, regular show and entry, starts.

I am running debian 10 and using tvh docker-images made by the linuxserver.io guys. Therefore I am always relatively up-to-date. I am observing this behaviour since about one year, I am not sure how long this behaviour exists. Some years ago I used KODI and also TVH on a debian backend, here I am very sure, it worked fine. But maybe the guys at KODI are not using the REST API but the "tvhclient binary hstp" protocol? Not sure here though, but this was TVH 4.0 afair.


Files

shot1.png (16.1 KB) shot1.png Andreas Maier, 2021-12-14 21:36
shot2.png (12 KB) shot2.png Andreas Maier, 2021-12-14 21:37
shot3.png (22.1 KB) shot3.png Andreas Maier, 2021-12-14 21:42
shot4.PNG (33.7 KB) shot4.PNG Andreas Maier, 2021-12-14 21:44
shot5.png (9.07 KB) shot5.png Andreas Maier, 2021-12-14 21:49
shot6.PNG (42.4 KB) shot6.PNG Andreas Maier, 2021-12-16 20:25

History

#1

Updated by Dave Pickles almost 3 years ago

What is reported in the TVH log file when these timers are created and when the recordings start?

What are the contents of the DVR log files for the timers before the recordings start (/home/hts/.hts/tvheadend/dvr/log/*.log)?

When you "change something irrelevant", how does the timer's log file change?

#2

Updated by Andreas Maier almost 3 years ago

Hello Dave,

thanks, I made a test again to gather all information you are asking for:

I want to record the following two subsequent entries:

If I do that using the TVH client and go back to the Webif, I can see now the following entries:

The following two log-entries were created in dvr/log/

{
    "enabled": true,
    "create": 1639509741,
    "watched": 0,
    "start": 1639513800,
    "start_extra": 0,
    "stop": 1639515600,
    "stop_extra": 0,
    "channel": "2fc94917be3501da78a76d7d97382639",
    "channelname": "Pearl.tv HD Shop",
    "title": {
        "ger": "Das Beste aus dem Katalog" 
    },
    "subtitle": {
        "ger": "24-Stunden Bestellhotline: 0800- 51  51  444 (gebührenfrei)\n\nEgal wie oft Sie an einem Tag bestellen, Sie bezahlen nur einmal die Versandkosten und ab 150 Euro Warenwert liefern wir sogar versandkostenfrei!" 
    },
    "pri": 2,
    "retention": 0,
    "removal": 0,
    "playposition": 0,
    "playcount": 0,
    "config_name": "7a5edfbe189851e5b1d1df19c93962f0",
    "owner": "tvadmin",
    "creator": "tvadmin",
    "errorcode": 0,
    "errors": 0,
    "data_errors": 0,
    "dvb_eid": 0,
    "noresched": false,
    "norerecord": false,
    "fileremoved": 0,
    "autorec": "",
    "timerec": "",
    "parent": "",
    "child": "",
    "content_type": 0,
    "copyright_year": 0,
    "broadcast": 0,
    "comment": "Created by dream Player for TVheadend" 
}
{
    "enabled": true,
    "create": 1639509748,
    "watched": 0,
    "start": 1639515600,
    "start_extra": 0,
    "stop": 1639517400,
    "stop_extra": 0,
    "channel": "2fc94917be3501da78a76d7d97382639",
    "channelname": "Pearl.tv HD Shop",
    "title": {
        "ger": "Das Beste aus dem Katalog" 
    },
    "subtitle": {
        "ger": "24-Stunden Bestellhotline: 0800- 51  51  444 (gebührenfrei)\n\nEgal wie oft Sie an einem Tag bestellen, Sie bezahlen nur einmal die Versandkosten und ab 150 Euro Warenwert liefern wir sogar versandkostenfrei!" 
    },
    "pri": 2,
    "retention": 0,
    "removal": 0,
    "playposition": 0,
    "playcount": 0,
    "config_name": "7a5edfbe189851e5b1d1df19c93962f0",
    "owner": "tvadmin",
    "creator": "tvadmin",
    "errorcode": 0,
    "errors": 0,
    "data_errors": 0,
    "dvb_eid": 0,
    "noresched": false,
    "norerecord": false,
    "fileremoved": 0,
    "autorec": "",
    "timerec": "",
    "parent": "",
    "child": "",
    "content_type": 0,
    "copyright_year": 0,
    "broadcast": 0,
    "comment": "Created by dream Player for TVheadend" 
}

When the time has come to record the first entry the Webif log outputs this (sorry I only have a screenshot):

... and then some times later, when the time morphed for the second entry this:

Now TVHeadend is dead, until the second show is over, I forgot to configure so that the second filename is unique, so I cannot make a screenshot of how the table above looks like. I edited the screenshot so you get an idea how it would look:

In dvr/log/ there are no new or altered files.

Just for the "when I change something" which corrects somehow the entry I do not have log-files. I try to make some - have to wait now for the second show to end :-D - so that TVH is talking again to me ;-)

#3

Updated by Dave Pickles almost 3 years ago

Interesting. I don't claim to understand all the code, but this is what I think is happening.

The API /dvr/entry/create creates the timers from the data supplied, it does not check this data against the EPG.

When the first timer begins recording, the EPG grabber is also triggered. The grabber detects a change in the currently-running show on the channel and passes this to DVR in case any timers need updating.

DVR checks the update against its list of timers using function dvr_entry_fuzzy_match(). Your timers do not have broadcast ID or dvb_eid set and both have the same title. The fuzzy match also allows the start and end times to vary (up to the limit set in "EPG Update Window"). There is another function epg_match_event_fuzzy() which may be involved. So DVR believes that the second show has already begun and starts the recording.

I cannot see any recent code change which could have produced this behaviour. There is a possible workaround; set "EPG Update Window" in Configuration -> Recording -> EPG/Autorec Settings to less than one hour.

Re the duplicate filename crash, do you have "Format String" in Configuration -> Recording -> Filesystem Settings set to the default ($t$n.$x)?.

#4

Updated by Andreas Maier almost 3 years ago

Hello Dave,

well, now this is interesting and actually makes perfect sense. I tried your proposal and set the EPG/Autorec setting to 30Min, which did not have an effect. Then I completely disabled it and it recorded now both shows correctly o_O. Thanks for this suggestion. Very strange, I was rather sure in my "desperation" that time I already tried/played with all these entries.

Just for my understanding: having disabled this settings means now that if I program something to be recorded and the EPG changes (to be recorded show will move to another time) my recorder-entry will not move accordingly, right? So this would be "the price to pay".

Also, just having this complete in this thread: Here is a screenshot of two log entries, one made with my TVH client software (right) and one made with the TVH webif (left). One can clearly see the differences (what you mentioned):

Thanks for all the input and suggestions. Maybe it is possible in the future to have the fuzzy_match adapted let's see :-)

#5

Updated by Dave Pickles almost 3 years ago

Just for my understanding: having disabled this settings means now that if I program something to be recorded and the EPG changes (to be recorded show will move to another time) my recorder-entry will not move accordingly, right? So this would be "the price to pay".

I believe that's correct, yes.

Maybe it is possible in the future to have the fuzzy_match adapted let's see :-)

I've looked at these functions in the past when working on a different problem. I suspect that it would be impossible to create a 'fuzzy match' to work correctly with the wide range of input and EPG sources that TVH is able to handle.

Also available in: Atom PDF