Tvheadend

Quick update.

I installed tvheadend_4.3-1857~g221c29b40~raspbianbuster_armhf.deb and the problem persists.

Then I removed the Pi4 & switched back to the Pi 3 [with its untouched SD card]. I still get the same problem - WTF? The only thing the 2 systems have in common is the external HDD containing the recordings.

Are you shure user profile is OK?

I have no reason to think that's a problem.
I created a new user for the kodi client, but same result.

Post selected settings in proffile.

Default user:

{
"index": 2,
"enabled": true,
"username": "*",
"prefix": "0.0.0.0/0,::/0",
"change": [
"change_rights",
"change_chrange",
"change_chtags",
"change_dvr_configs",
"change_profiles",
"change_conn_limit",
"change_lang",
"change_lang_ui",
"change_theme",
"change_uilevel"
],
"uilevel": 0,
"uilevel_nochange": 0,
"streaming": [
"basic",
"advanced",
"htsp"
],
"profile": [
],
"dvr": [
"basic",
"htsp",
"all",
"all_rw"
],
"htsp_anonymize": false,
"dvr_config": [
],
"webui": false,
"admin": false,
"conn_limit_type": 0,
"conn_limit": 0,
"channel_min": 0,
"channel_max": 0,
"channel_tag_exclude": false,
"channel_tag": [
],
"comment": "New entry",
"wizard": false
}

New kodi user: {
"index": 1,
"enabled": true,
"username": "kodi",
"prefix": "0.0.0.0/0,::/0",
"change": [
"change_rights",
"change_chrange",
"change_chtags",
"change_dvr_configs",
"change_profiles",
"change_conn_limit",
"change_lang",
"change_lang_ui",
"change_theme",
"change_uilevel"
],
"uilevel": 1,
"uilevel_nochange": 1,
"lang": "eng_GB",
"streaming": [
"advanced",
"htsp"
],
"profile": [
],
"dvr": [
"htsp",
"all_rw"
],
"htsp_anonymize": false,
"dvr_config": [
],
"webui": false,
"admin": false,
"conn_limit_type": 0,
"conn_limit": 0,
"channel_min": 0,
"channel_max": 0,
"channel_tag_exclude": false,
"channel_tag": [
],
"comment": "New entry",
"wizard": false
}

{
        "index": 2,
        "enabled": true,
        "username": "kodi",
        "prefix": "0.0.0.0/0,::/0",
        "change": [
                "change_rights",
                "change_chrange",
                "change_chtags",
                "change_dvr_configs",
                "change_profiles",
                "change_conn_limit",
                "change_lang",
                "change_lang_ui",
                "change_theme",
                "change_uilevel" 
        ],
        "uilevel": 0,
        "uilevel_nochange": 0,
        "streaming": [
                "basic",
                "advanced",
                "htsp" 
        ],
        "profile": [
        ],
        "dvr": [
        ],
        "htsp_anonymize": false,
        "dvr_config": [
        ],
        "webui": false,
        "admin": false,
        "conn_limit_type": 1,
        "conn_limit": 0,
        "channel_min": 0,
        "channel_max": 0,
        "channel_tag_exclude": false,
        "channel_tag": [
        ],
        "xmltv_output_format": 0,
        "htsp_output_format": 0,
        "comment": "New entry",
        "wizard": false
}

That solves the TVH quitting problem, however when I use this profile, none of my
recordings showed up.

When I changed the 'video recorder' tab to 'view all', the problem returned.

Could this be something to do with permissions on the pvr drive? Seems to be the only thing in common between the two systems... Except the pi 3 was working fine for ages.

Both system is different, just start from ZERO on new board.

If I start from zero, I'll lose all my recordings. Spousal unit will not be happy.

Why would TVH barf on a user profile created with the default settings?

You have the same problem?

I've had some time to try & debug this.

I've cleared all config on the old server [that was working] and then set up a minimal TVH config, so far so good.

The problems start if I try to connect a client after copying in my old files from tvheadend/dvr - currently I have just
3 entries in tvheadend/dvr/log, and when a client connects TVH reads one of these files and barfs, though I can't see anything
particularly odd about the contents, and after all TVH created it in the 1st place.

Without this file in dvr/logs, the others are parsed with no problems.
I could delete this one entry, but if I copy all my recording logs in, it just barfs on something else.

Here's the relevant tracelog:

2020-01-03 12:38:25.326 [ TRACE] htsp-ans: 192.168.1.142 [ | TVHClient ] - answer '{"id":160001537,"enabled":1,"channelName":"Channel 4","autorecId":"f63774345a56d405bb1b50b155b47f5c","start":1576809300,"stop":1576812900,"startExtra":3,"stopExtra":3,"retention":2147483646,"removal":1096,"priority":2,"contentType":0,"playcount":0,"playposition":0,"title":"George Clarke's Amazing Spaces","subtitle":"(Sign Language)","description":"The architect pays a visit to airline enthusiast Vince.","episode":"Season 7.Episode 3/16","owner":"admin","creator":"admin","comment":"Auto recording: Created from EPG query","files":[{"filename":"/George-Clarke's-Amazing-Spaces/George-Clarke's-Amazing-Spaces2019-12-20.ts","info":[{"type":"H264","width":29281,"height":30367,"duration":3746854690,"aspect_num":0,"aspect_den":0},{"type":"AAC-LATM","language":"eng","audio_type":0}],"start":1576809120,"stop":1576813080,"fsid":0,"size":789774840}],"path":"/George-Clarke's-Amazing-Spaces/George-Clarke's-Amazing-Spaces2019-12-20.ts","state":"completed","dataErrors":45,"da
Aborted

Any insight into why this might be happening appreciated.

Stack trace FYI:

#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1 0x74f9e824 in __GI_abort () at abort.c:89
#2 0x0055cbb4 in htsmsg_binary_write (
ptr=0x4 <error: Cannot access memory at address 0x4>,
ptr@entry=0x6ef006f7 "\003\004", msg=<optimized out>)
at src/htsmsg_binary.c:258
#3 0x0055cb68 in htsmsg_binary_write (ptr=0x6ef006f7 "\003\004",
ptr@entry=0x6ef006f1 "\001", msg=<optimized out>)
at src/htsmsg_binary.c:275
#4 0x0055cb68 in htsmsg_binary_write (ptr=0x6ef006f1 "\001",
ptr@entry=0x6ef0068e "\003\b", msg=<optimized out>)
at src/htsmsg_binary.c:275
#5 0x0055cb68 in htsmsg_binary_write (ptr=0x6ef0068e "\003\b",
ptr@entry=0x6ef00688 "\001", msg=<optimized out>)
at src/htsmsg_binary.c:275
#6 0x0055cb68 in htsmsg_binary_write (ptr=0x6ef00688 "\001",
ptr@entry=0x6ef00474 "\002\002", msg=<optimized out>)
at src/htsmsg_binary.c:275
#7 0x0055ccac in htsmsg_binary_serialize (msg=<optimized out>,
datap=datap@entry=0x644f0820, lenp=lenp@entry=0x644f0824,
maxlen=maxlen@entry=2147483647) at src/htsmsg_binary.c:324
#8 0x00551030 in htsp_write_scheduler (aux=0x64cf16a8)
at src/htsp_server.c:3226
#9 0x00528c28 in thread_wrapper (p=0x6e5008f8) at src/wrappers.c:159
#10 0x7514cfc4 in start_thread (arg=0x644f0ef0) at pthread_create.c:458
#11 0x75043038 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:76
from /lib/arm-linux-gnueabihf/libc.so.6

So it looks like I'm seeing a corrupt linked list.

I suspect this arose on a system that had been working flawlessly for months because I did an apt-get upgrade, which would tend to suggest a shared library as the culprit.

I do wonder though why it's happening on a fresh buster install with 4.3-1857~g221c29b40~raspbianbuster_armhf.deb.

Further debugging shows that in htsmsg_binary_write() I'm frequently seeing f->hmf_type set to 6 [HMF_DBL],
which is not handled in the switch() statement.

Still no clues why this should suddenly start happening.

Problem solved - sort of.

Turns out I had 6 files in dvr/log containing this:

"duration": 3746854690,

These recordings all came from the same channel [Channel 4 UK] over the period 16/12/19 to 24/12/19.

It seems that when TVH was serving this data to clients from memory, it was OK, but once I restarted TVH,
the data was read from disk, and I surmise this vale was read as a double instead of an integer.

When a client connects, there is no case in the switch statement in htsmsg_binary_write() to handle
a double, so it hits abort().

Seems there is a bug here. TVH should not be writing such large values to disk, and the input parser
shouldn't be putting doubles into the data stream when there's no mechanism in htsmsg_binary_write() to
handle them.

Editing the duration to a sane value like 3600 fixes the problem.

I'd be interested to know if anyone else has these large duration values lurking, because if you
re-start TVH, it will die when you try to connect a client.