Tvheadend

Now on build 3.9.1539~g286509b and still existing. Also noticed stuttering on an unencrypted channel. Could someone please tell me if there's any way to log this in tvheadend? Normal debugging log shows no errors during playback.

Could you provide the whole mux dump ? Use the 'play' link in the mux tab to gather the whole infomation. But only if the contents is not crypted..

I'm sorry but I don't have a FTA channel that's affected. I was wrong.

It seems only some encrypted radio stations are wrong. I can provide you with a mux dump of one of those muxes if that is of any help?

Is there any other information I can give to solve this issue?

Could you grab the output stream from tvheadend using wireshark or tcpdump ? Only the TCP audio stream.. It looks like a timing issue..

Did you spot a cause for this issue in the wireshark file?

Ziggo added a unencrypted Christmas Music Choice channel. Guess what... no stutter in playback. My best guess is there's something wrong with radio stations and encryption.

Could someone please take a look at it again?Version running now is 3.9.2165~g3579d04

Didn't mean unencrypted but unencrypted

Just some notes: Trying to analyze Stutter.ts - it looks like a raw (passthrough) TS file from TVH. There are missing frames in the audio stream:

A python script to analyze frame pts diffs:

import sys

fp = sys.stdin
prev = None
for l in fp.readlines():
  if l.startswith('pkt_pts_time='):
    next = float(l[13:-1])
    if prev:
      print "%.6f (diff %.6f)" % (next, next - prev)
    prev = next

Cmd line:

ffprobe -show_frames ~/Download/Stutter.ts | python a.py

Result:

90132.396111 (diff 0.026000)
90132.422111 (diff 0.026000)
90132.605111 (diff 0.183000) # gap - 1 + 6 missing frames
90132.631111 (diff 0.026000)
90132.683111 (diff 0.052000) # gap - 1 + 1 missing frame
90132.710111 (diff 0.027000)
90132.736111 (diff 0.026000)

90157.369111 (diff 0.026000)
90157.395111 (diff 0.026000)
90157.421111 (diff 0.026000)
90157.604111 (diff 0.183000) # gap - 1 + 6 missing frames
90157.630111 (diff 0.026000)
90157.683111 (diff 0.053000) # gap - 1 + 1 missing frame
90157.709111 (diff 0.026000)
90157.735111 (diff 0.026000)

90182.368111 (diff 0.026000)
90182.394111 (diff 0.026000)
90182.421111 (diff 0.027000)
90182.603111 (diff 0.182000) # gap - 1 + 6 missing frames
90182.630111 (diff 0.027000)
90182.682111 (diff 0.052000) # gap - 1 + 1 missing frame
90182.708111 (diff 0.026000)
90182.734111 (diff 0.026000)

Note that the time difference between gaps is 25 seconds each (descrambling key change?).

Could you provide --trace descrambler,capmt,cwc ?

Could you do same test with this one-line addition ?

diff --git a/src/descrambler/descrambler.c b/src/descrambler/descrambler.c
index d42683e..94f7b3b 100755
--- a/src/descrambler/descrambler.c
+++ b/src/descrambler/descrambler.c
@@ -370,6 +370,7 @@ descrambler_descramble ( service_t *t,
       sbuf_free(&dr->dr_buf);
     }
     ki = tsb[3];
+    tvhtrace("descrambler", "ki = %02x", ki);
     if ((ki & 0x80) != 0x00) {
       if (key_valid(dr, ki) == 0) {
         if (tvhlog_limit(&dr->dr_loglimit_key, 10))

Which CSA do you use ?

$ grep CSA .config.mk 
CONFIG_TVHCSA = yes
CONFIG_DVBCSA = no

xbmc@mediacenter:~/tvheadend$ grep CSA .config.mk
CONFIG_TVHCSA = yes
CONFIG_DVBCSA = no

Another debug code:

diff --git a/src/descrambler/descrambler.c b/src/descrambler/descrambler.c
index d42683e..d838b1d 100755
--- a/src/descrambler/descrambler.c
+++ b/src/descrambler/descrambler.c
@@ -326,6 +326,9 @@ descrambler_descramble ( service_t *t,

   lock_assert(&t->s_stream_mutex);

+  static int didx = 0;
+  tvhtrace("descrambler", "descramble ts packet %i (PID %i)", didx++, st->es_pid);
+
   if (dr == NULL)
     return -1;
   count = failed = 0;
diff --git a/src/input/mpegts/tsdemux.c b/src/input/mpegts/tsdemux.c
index 2b4f7e0..d3016e3 100644
--- a/src/input/mpegts/tsdemux.c
+++ b/src/input/mpegts/tsdemux.c
@@ -256,6 +256,10 @@ ts_recv_packet2(mpegts_service_t *t, const uint8_t *tsb)
   elementary_stream_t *st;
   int pid = (tsb[1] & 0x1f) << 8 | tsb[2];

+  static int didx = 0;
+  tvhtrace("descrambler", "output ts packet %i PID %i", didx++, pid);
+  tvhlog_hexdump("descrambler", tsb, 188);
+
   if((st = service_stream_find((service_t*)t, pid)) != NULL)
     ts_recv_packet0(t, st, tsb);
 }

OK. No descrambled TS packets are lost. So, it appears that the packets are missing before they enter to the descrambler.

Could you try simultaneous streaming the whole mux while the radio service is used, if it changes something? (Something like 'wget -O /dev/null <mux_play_url_from_the_mux_grid>'.)

Just tried, no changes.

I need to implement a way to insert the descrambling keys to the whole mux stream and also implement the re-play functionality, so I can do testing directly on my machine. It may take some time.

Ok, thanks very much! Please say when you need more info from me.

OK. Grab latest sources. Use --enable-tsdebug as the configure option. Then run tvheadend with "--tsdebug <directory>" arguments. Then run the test and you should see in directory two files. I need them for analyze what's going wrong. One file is raw input from the linuxdvb subsystem and the second file is almost same (tvh does some processing - no contents change) but with added descrambler keys.

Tried to re-play and guess what - no packets are lost, but I had to fix a little issue with the PCR extraction - v3.9-2214-g8668734 for tsfile.

I don't think that it's related for the live playback, but could you test the recent code ?

Could you try this ?

diff --git a/src/descrambler/descrambler.c b/src/descrambler/descrambler.c
index a15aa64..0706c9b 100755
--- a/src/descrambler/descrambler.c
+++ b/src/descrambler/descrambler.c
@@ -179,6 +179,8 @@ descrambler_keys ( th_descrambler_t *td, int type,
   if (tvhcsa_set_type(&dr->dr_csa, type) < 0)
     return;

+  usleep(500000);
+
   pthread_mutex_lock(&t->s_stream_mutex);

   LIST_FOREACH(td2, &t->s_descramblers, td_service_link)

BTW: Also the second re-play was successful (no gaps in the output stream).

TVH crashes with that code added. Do you need a crashlog and where can I find it?

diff --git a/src/descrambler/cwc.c b/src/descrambler/cwc.c
index bac4aa4..a36c8c2 100755
--- a/src/descrambler/cwc.c
+++ b/src/descrambler/cwc.c
@@ -809,7 +809,9 @@ forbid:
       es->es_keystate = ES_RESOLVED;
       es->es_resolved = 1;

+      pthread_mutex_unlock(&ct->cs_cwc->cwc_mutex);
       descrambler_keys((th_descrambler_t *)ct, DESCRAMBLER_DES, msg + 3, msg + 3 + 8);
+      pthread_mutex_lock(&ct->cs_cwc->cwc_mutex);
     } else {
       tvhlog(LOG_DEBUG, "cwc",
            "Received ECM reply%s for service \"%s\" " 
diff --git a/src/descrambler/descrambler.c b/src/descrambler/descrambler.c
index a15aa64..0706c9b 100755
--- a/src/descrambler/descrambler.c
+++ b/src/descrambler/descrambler.c
@@ -179,6 +179,8 @@ descrambler_keys ( th_descrambler_t *td, int type,
   if (tvhcsa_set_type(&dr->dr_csa, type) < 0)
     return;

+  usleep(500000);
+
   pthread_mutex_lock(&t->s_stream_mutex);

   LIST_FOREACH(td2, &t->s_descramblers, td_service_link)

I'm very happy to tell you this seemed to fix the issue. Tested multiple radio channels en playback seems fine again. Thanks very much for your time and effort!

It's not a fix, but just a debug code. It looks like a timing issue (wrong key is used for decoding some frames for a short period). The patch just delays the new key processing by 500 ms.

Ok I understand. If there's something to test please say so.

I found the real issue. Basically, the key was changed too quickly and tvh buffers some TS packets for the DES decoder. These buffered TS packets must be flushed (processed) before key changes, otherwise they are decoded with the new key which is invalid for them (thus some pieces of the audio stream weren't parsed properly). I'm working on a fix. I only wonder, why we haven't noted before, because this bug is really serious.

I made a forum post here asking if anybody else was having this issue, no replies. I also asked on tweakers.net in the tvheadend topic if anyone else noticed... no one. Guess I'm the only one left here listening to radio.

The above commit contains the proper fix for your issue. Could you test ?

Tested and confirmed to fix the issue. Thanks again!

J H wrote:

I made a forum post here asking if anybody else was having this issue, no replies. I also asked on tweakers.net in the tvheadend topic if anyone else noticed... no one. Guess I'm the only one left here listening to radio.

I think that the problem was that most of radio stations on SAT are not encrypted (at least it's true for my country and I think also for most of European countries).