Bug #3971

Constant "mpegts: too much queued table input data (over 2MB), discarding new" warnings causing TVheadend to become unresponsive

Added by Bobby Lockwood 7 months ago. Updated about 1 month ago.

Status:NewStart date:2016-09-09
Priority:NormalDue date:
Assignee:Adam Sutton% Done:

0%

Category:EPG - Grabbers
Target version:-
Found in version:4.1-2236 ~ LibreELEC Tvh-addon v7.0.444 (2016-09-04T03:48:01+0200) Affected Versions:

Description

I often get "mpegts: too much queued table input data (over 2MB), discarding new" warnings during the epggrab.
For example this morning they started at 02:04 when the cron job started and kept going until I rebooted the box at 06:00.
When they occur I am unable to access the webinterface and recordings don't take place.
I'm running TVH on a Wetek Play with Libreelec 7.02
EIT: DVB Grabber and UK: Freesat OTA grabbers.
A logfile is attached.

service.log (362 KB) Bobby Lockwood, 2016-09-09 19:55

2mb.PNG (93.1 KB) saen acro, 2016-12-27 16:13

tvh_debug.rar - thread,linuxdvb,mtimer,gtimer (9.22 KB) saen acro, 2017-01-01 22:22

tvhlog.rar (24.6 KB) saen acro, 2017-01-06 15:56

History

#1 Updated by C K 6 months ago

Getting this error, too.

WebUI/HTSP not responding. Running TVH in a screen session, not responing to a ctrl-c.

#2 Updated by Jaroslav Kysela 6 months ago

Note that the message is only a consequence of something else. It's triggered when the CPU is busy or another problem in tvh, so tvh starts to drop input data.

Please, provide a piece of log when this happen - "--trace gtimer,mtimer" . https://tvheadend.org/projects/tvheadend/wiki/Traces . Note that tvh must be compiled with --enable-gtimer_check (see About dialog - configuration).

#3 Updated by C K 6 months ago

Jaroslav Kysela wrote:

Note that the message is only a consequence of something else. It's triggered when the CPU is busy or another problem in tvh, so tvh starts to drop input data.

Please, provide a piece of log when this happen - "--trace gtimer,mtimer" . https://tvheadend.org/projects/tvheadend/wiki/Traces . Note that tvh must be compiled with --enable-gtimer_check (see About dialog - configuration).

Thanks. Will recompile on next occurrence and run with trace enabled. TVH runs without problems at the moment.

#4 Updated by C K 6 months ago

C K wrote:

Jaroslav Kysela wrote:

Note that the message is only a consequence of something else. It's triggered when the CPU is busy or another problem in tvh, so tvh starts to drop input data.

Please, provide a piece of log when this happen - "--trace gtimer,mtimer" . https://tvheadend.org/projects/tvheadend/wiki/Traces . Note that tvh must be compiled with --enable-gtimer_check (see About dialog - configuration).

Thanks. Will recompile on next occurrence and run with trace enabled. TVH runs without problems at the moment.

Strange. TVH runs fine atm. Will continue logging.

#5 Updated by C K 6 months ago

C K wrote:

C K wrote:

Jaroslav Kysela wrote:

Note that the message is only a consequence of something else. It's triggered when the CPU is busy or another problem in tvh, so tvh starts to drop input data.

Please, provide a piece of log when this happen - "--trace gtimer,mtimer" . https://tvheadend.org/projects/tvheadend/wiki/Traces . Note that tvh must be compiled with --enable-gtimer_check (see About dialog - configuration).

Thanks. Will recompile on next occurrence and run with trace enabled. TVH runs without problems at the moment.

Strange. TVH runs fine atm. Will continue logging.

Here is a short log: https://gist.github.com/ckarrie/a2f226685b1fb343a5aac443cb7e7580

#6 Updated by Jaroslav Kysela 6 months ago

Thanks. Unfortunately, no hint for me where the problem might be. Could you look if CPU is on 100% usage when this situation occurs? Also, it would be really good to analyze backtrace, too. https://tvheadend.org/projects/tvheadend/wiki/Debugging (see chapter 'Dead or Live Lock').

#7 Updated by C K 6 months ago

Jaroslav Kysela wrote:

Thanks. Unfortunately, no hint for me where the problem might be. Could you look if CPU is on 100% usage when this situation occurs? Also, it would be really good to analyze backtrace, too. https://tvheadend.org/projects/tvheadend/wiki/Debugging (see chapter 'Dead or Live Lock').

Note for myself:

Processes:

top -H

GDB:

pid = ps -C tvheadend
sudo gdb build.linux/tvheadend <PID>
(gdb) set logging on
(gdb) set pagination off
(gdb) thread apply all bt full
(gdb) generate-core-file

#8 Updated by saen acro 3 months ago

I have same problem but strange I see is bit-rate it variate,
output it more then input, transcoding not used.

#9 Updated by C K 3 months ago

saen acro wrote:

I have same problem but strange I see is bit-rate it variate,
output it more then input, transcoding not used.

I think that just buffering/timeshifting. Try to run TVH with gdb, see comments above.

#10 Updated by saen acro 3 months ago

C K wrote:

saen acro wrote:

I have same problem but strange I see is bit-rate it variate,
output it more then input, transcoding not used.

I think that just buffering/timeshifting. Try to run TVH with gdb, see comments above.

No timeshift is off, ethernet is gigabit, no cpu peaks [email protected]

but there is a kernel message

TCP: request_sock_TCP: Possible SYN flooding on port 9981. Sending cookies.  Check SNMP counters.

#11 Updated by saen acro 3 months ago

> uname -a
Linux SVER 4.4.0-57-generic #78~14.04.1-Ubuntu SMP Sat Dec 10 00:14:47 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

kernel: [   40.170303] TCP: request_sock_TCP: Possible SYN flooding on port 9981. Sending cookies.  Check SNMP counters.
kernel: [   40.185854] TCP: request_sock_TCP: Possible SYN flooding on port 9982. Sending cookies.  Check SNMP counters.

Tested with various version of TVH and situation is similar.
Even /playlist and /xmltv refuse to open

#12 Updated by saen acro 3 months ago

Update:
There is a problem with kernel 4.4 and up with build in SYN protection
http://tvheadend.org/issues/4152

#13 Updated by saen acro 3 months ago

Some more clues
In browser I see lot not responses
Browser request data from url

:9981/api/status/subscriptions?_dc=1483282972654

but no responce receved
also from
:9981/api/mpegts/network/builders?_dc=1483283030136
:9981/api/idnode/load

all requests from

 :9981/comet/poll

pass corectly

#14 Updated by saen acro 3 months ago

tame taken to get stream

Jan 01 18:24:31: INFO: Starting Astra SM 0.2.85
Jan 01 18:24:32: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:33: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:34: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:35: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:36: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:37: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:38: INFO: Bitrate: 0 Kbit/s
Jan 01 18:24:39: INFO: Bitrate: 4897 Kbit/s
Jan 01 18:24:39: ERROR: CC: PID:18=1 
Jan 01 18:24:40: INFO: Bitrate: 4671 Kbit/s
Jan 01 18:24:41: INFO: Bitrate: 5805 Kbit/s
Jan 01 18:24:42: INFO: Bitrate: 4837 Kbit/s

in same time same channel watched using same tuner

#15 Updated by saen acro 3 months ago

when 2+ clents watching time rise up

 ./astra --analyze http://localhost:9981/stream/channelid/387842520 --debug
Jan 01 18:36:16: INFO: Starting Astra SM 0.2.85
Jan 01 18:36:17: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:18: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:19: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:20: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:21: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:22: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:23: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:24: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:25: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:26: ERROR: [analyze] HTTP Error: 0:response timeout
Jan 01 18:36:26: DEBUG: [core] immediate exit requested, rc=1
# ./astra --analyze http://localhost:9981/stream/channelid/387842520 --debug 
Jan 01 18:36:35: INFO: Starting Astra SM 0.2.85
Jan 01 18:36:36: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:37: INFO: Bitrate: 0 Kbit/s
Jan 01 18:36:38: INFO: PAT: tsid: 5
Jan 01 18:36:38: INFO: PAT: pid: 517 PMT pnr: 204
Jan 01 18:36:38: INFO: PAT: crc32: 0x26229128
Jan 01 18:36:38: INFO: PMT: pnr: 204
Jan 01 18:36:38: INFO: PMT: pid: 515 PCR
Jan 01 18:36:38: INFO: VIDEO: pid: 515 type: MPEG-4 AVC/H.264, ISO/IEC 14496-10 (0x1B)
Jan 01 18:36:38: INFO: VIDEO: Stream ID: 24
Jan 01 18:36:38: INFO: VIDEO: descriptor: 0x02031A445F
Jan 01 18:36:38: INFO: VIDEO: descriptor: 0x060102
Jan 01 18:36:38: INFO: VIDEO: Maximum bitrate: 110
Jan 01 18:36:38: INFO: VIDEO: descriptor: 0x28046400283F
Jan 01 18:36:38: INFO: AUDIO: pid: 516 type: MPEG-1 audio, ISO/IEC 11172-3 (0x03)
Jan 01 18:36:38: INFO: AUDIO: Stream ID: 25
Jan 01 18:36:38: INFO: AUDIO: Language: eng
Jan 01 18:36:38: INFO: AUDIO: descriptor: 0x030167
Jan 01 18:36:38: INFO: AUDIO: Maximum bitrate: 329
Jan 01 18:36:38: INFO: AUDIO: pid: 518 type: MPEG-1 audio, ISO/IEC 11172-3 (0x03)
Jan 01 18:36:38: INFO: AUDIO: Stream ID: 26
Jan 01 18:36:38: INFO: AUDIO: Language: bul
Jan 01 18:36:38: INFO: AUDIO: descriptor: 0x030167
Jan 01 18:36:38: INFO: AUDIO: Maximum bitrate: 329
Jan 01 18:36:38: INFO: PMT: crc32: 0x7C2B162B
Jan 01 18:36:38: INFO: Bitrate: 1675 Kbit/s
Jan 01 18:36:38: ERROR: CC: PID:0=1 PID:18=1 PID:515=1 PID:516=1 PID:518=1 
Jan 01 18:36:39: INFO: SDT: tsid: 5
Jan 01 18:36:39: INFO: SDT: sid: 204
Jan 01 18:36:39: INFO: SDT:    Service: National Geographic HD
Jan 01 18:36:39: INFO: SDT:    Provider: BULSATCOM
Jan 01 18:36:39: INFO: SDT: crc32: 0x76CFB843
Jan 01 18:36:39: INFO: Bitrate: 4124 Kbit/s
Jan 01 18:36:39: ERROR: CC: PID:17=1 
Jan 01 18:36:40: INFO: Bitrate: 3321 Kbit/s
Jan 01 18:36:41: INFO: Bitrate: 2983 Kbit/s
Jan 01 18:36:42: INFO: Bitrate: 2789 Kbit/s
Jan 01 18:36:43: INFO: Bitrate: 2870 Kbit/s
Jan 01 18:36:44: INFO: Bitrate: 2905 Kbit/s
Jan 01 18:36:45: INFO: Bitrate: 2702 Kbit/s
Jan 01 18:36:46: INFO: Bitrate: 2971 Kbit/s
Jan 01 18:36:47: INFO: Bitrate: 2832 Kbit/s
Jan 01 18:36:48: INFO: Bitrate: 3334 Kbit/s
Jan 01 18:36:49: INFO: Bitrate: 3693 Kbit/s

#16 Updated by Jaroslav Kysela 3 months ago

Provide tvh log for '--trace thread,linuxdvb,mtimer,gtimer' for the above scenario (2+ clients).

#17 Updated by saen acro 3 months ago

There is a some interesting thing
during log creation i play tv from web interface
each time when new message come
/mpegts: too much queued table input data (over 2MB), discarding new/
web stream stops

#18 Updated by saen acro 3 months ago

@Jaroslav Kysela
Is there anything else to log?

#19 Updated by Jaroslav Kysela 3 months ago

One bad thing (last log) is that it's required approx. 200ms to get the frontend status:

2017-01-01 23:15:15.745 [  TRACE]:linuxdvb: #6 - checking FE status (ready)
2017-01-01 23:15:15.961 [  TRACE]:linuxdvb: #6 - status 1 (001F)

But it should not block tvh too much.

Please, configure and compile tvh with --enable-gtimer_check and provide the traces again (comment 16).

#20 Updated by saen acro 3 months ago

Test started
with last version

http: user_ip: HTTP/1.1 GET /dist/purify.min.js.map -- 1

DevTools failed to parse SourceMap: http://TVH_IP:9981/dist/purify.min.js.map

#21 Updated by Jaroslav Kysela 3 months ago

Hmm.. It seems that linux dvbapi ioctls are too costly (time) on your hardware:

mtimer: src/input/mpegts/linuxdvb/linuxdvb_frontend.c:737:linuxdvb_frontend_monitor duration 1294728us

Which hardware / driver do you use?

Basically, this callback checks for the tuner status and collects the statistics (signal, lost packets in the demodulator, etc.). It should be done in few milliseconds. In your case, the callback takes ~1.3 second and it blocks all other parts in tvheadend which runs with the global lock. It means that the vital parts of tvheadend are blocked.

I think that the driver is wrong.

#22 Updated by saen acro 3 months ago

TBS 6909 with latest crazycat driver
https://bitbucket.org/CrazyCat/linux-tbs-drivers.git
before to close his repo

with same driver Astra work perfect

#23 Updated by Rainer Dorsch 3 months ago

I see the same symptoms here:
- Hardware: cubox-i (armv7l)
- TV adapter: Montage Technology M88DS3103 : DVB-S #0
- OS: xbian
- Kernel: 4.4.19+rt25+ #1 SMP PREEMPT RT
- tvheadend version: 2405

log file:
http://scw.bokomoko.de/~rd/tvheadend.log

Any insight would be welcome.

Thanks
Rainer

#24 Updated by saen acro 3 months ago

@Rainer Dorsch
can you tell what is signal and SNR metered by TVH

In my case, I get Signal 94% Quality 34-44 for few seconds and then lot of time 0/0,
but stream is OK no pixelization or anything.

#25 Updated by saen acro 3 months ago

Switched to https://github.com/tbsdtv/media_build.git
now signal is stable but now signal/snr is 74/62-81
will test more and write later

#26 Updated by saen acro 3 months ago

2017-01-09 19:16:13.740 scanfile: DVB-S - loaded 1 regions with 112 networks
2017-01-09 19:16:13.740 scanfile: DVB-T - loaded 43 regions with 1106 networks
2017-01-09 19:16:13.740 scanfile: DVB-C - loaded 17 regions with 56 networks
2017-01-09 19:16:13.740 scanfile: ATSC-T - loaded 2 regions with 9 networks
2017-01-09 19:16:13.740 scanfile: ATSC-C - loaded 1 regions with 5 networks
2017-01-09 19:16:13.740 scanfile: ISDB-T - loaded 2 regions with 1297 networks
2017-01-09 19:16:16.218 mpegts: 12729V in DVB - tuning on #0
2017-01-09 19:16:16.218 subscription: 0008: "epggrab" unsubscribing
2017-01-09 19:16:16.238 subscription: 000A: "scan" subscribing to mux "12729V", weight: 5, adapter: "#0", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:17.425 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:17.674 linuxdvb: #0 - retune nodata
2017-01-09 19:16:18.771 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:16:18.793 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:18.798 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:16:18.804 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:18.804 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:18.805 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:16:18.805 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:19.095 linuxdvb: #5 - retune nodata
2017-01-09 19:16:19.147 linuxdvb: #6 - retune nodata
2017-01-09 19:16:19.251 linuxdvb: #3 - retune nodata
2017-01-09 19:16:19.294 linuxdvb: #4 - retune nodata
2017-01-09 19:16:19.460 linuxdvb: #2 - retune nodata
2017-01-09 19:16:19.486 linuxdvb: #1 - retune nodata
2017-01-09 19:16:19.652 linuxdvb: #7 - retune nodata
2017-01-09 19:16:19.812 mpegts: 12606H in DVB scan complete
2017-01-09 19:16:19.812 mpegts: 12647V in DVB - tuning on #1
2017-01-09 19:16:19.812 subscription: 0007: "epggrab" unsubscribing
2017-01-09 19:16:19.903 subscription: 000C: "scan" subscribing to mux "12647V", weight: 5, adapter: "#1", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:19.903 mpegts: 12688H in DVB scan complete
2017-01-09 19:16:19.903 mpegts: 12647H in DVB scan complete
2017-01-09 19:16:20.047 mpegts: 11135V in DVB - tuning on #2
2017-01-09 19:16:20.048 subscription: 0006: "epggrab" unsubscribing
2017-01-09 19:16:20.094 subscription: 000D: "scan" subscribing to mux "11135V", weight: 5, adapter: "#2", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:20.308 subscription: 0001: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" unsubscribing from "NOVA", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:20.537 mpegts: 12524H in DVB - tuning on #7
2017-01-09 19:16:20.654 subscription: 000E: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "bTV", weight: 150, adapter: "#7", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "bTV", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:21.059 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:21.158 linuxdvb: #1 - retune nodata
2017-01-09 19:16:21.288 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:21.457 linuxdvb: #2 - retune nodata
2017-01-09 19:16:21.733 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:21.958 linuxdvb: #7 - retune nodata
2017-01-09 19:16:25.085 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:25.818 linuxdvb: #0 - retune nodata
2017-01-09 19:16:26.227 mpegts: 12729V in DVB - scan no data, failed
2017-01-09 19:16:26.227 subscription: 000A: "scan" unsubscribing
2017-01-09 19:16:26.227 mpegts: 11012V in DVB - tuning on #0
2017-01-09 19:16:26.298 subscription: 0010: "scan" subscribing to mux "11012V", weight: 5, adapter: "#0", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:26.431 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:16:26.450 linuxdvb: #5 - retune nodata
2017-01-09 19:16:26.453 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:26.459 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:16:26.465 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:16:26.502 linuxdvb: #6 - retune nodata
2017-01-09 19:16:26.564 linuxdvb: #4 - retune nodata
2017-01-09 19:16:26.670 linuxdvb: #3 - retune nodata
2017-01-09 19:16:27.551 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:27.701 linuxdvb: #0 - retune nodata
2017-01-09 19:16:28.720 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:28.948 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:29.209 linuxdvb: #1 - retune nodata
2017-01-09 19:16:29.394 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:29.697 linuxdvb: #2 - retune nodata
2017-01-09 19:16:29.949 mpegts: 12647V in DVB - scan no data, failed
2017-01-09 19:16:29.949 subscription: 000C: "scan" unsubscribing
2017-01-09 19:16:30.078 linuxdvb: #7 - retune nodata
2017-01-09 19:16:30.078 mpegts: 11135V in DVB - scan no data, failed
2017-01-09 19:16:30.078 subscription: 000D: "scan" unsubscribing
2017-01-09 19:16:30.631 mpegts: 12524H in DVB - scan no data, failed
2017-01-09 19:16:31.079 mpegts: 11135V in DVB - tuning on #2
2017-01-09 19:16:31.079 subscription: 0012: "epggrab" subscribing to mux "11135V", weight: 4, adapter: "#2", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:31.079 mpegts: 12647V in DVB - tuning on #1
2017-01-09 19:16:31.236 subscription: 0013: "epggrab" subscribing to mux "12647V", weight: 4, adapter: "#1", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:31.272 subscription: 000E: service instance is bad, reason: No input detected
2017-01-09 19:16:31.272 mpegts: 12524H in DVB - tuning on #1
2017-01-09 19:16:31.272 subscription: 0013: "epggrab" unsubscribing
2017-01-09 19:16:31.390 subscription: 000E: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "bTV", weight: 150, adapter: "#1", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "bTV", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:32.167 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:32.242 mpegts: 12647V in DVB - tuning on #7
2017-01-09 19:16:32.334 subscription: 0015: "epggrab" subscribing to mux "12647V", weight: 4, adapter: "#7", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:32.421 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:32.491 linuxdvb: #2 - retune nodata
2017-01-09 19:16:32.788 linuxdvb: #1 - retune nodata
2017-01-09 19:16:33.540 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:33.730 linuxdvb: #7 - retune nodata
2017-01-09 19:16:34.091 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:16:34.114 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:34.119 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:16:34.125 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:16:34.678 linuxdvb: #5 - retune nodata
2017-01-09 19:16:34.731 linuxdvb: #6 - retune nodata
2017-01-09 19:16:35.013 linuxdvb: #4 - retune nodata
2017-01-09 19:16:35.091 linuxdvb: #3 - retune nodata
2017-01-09 19:16:35.211 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:36.034 linuxdvb: #0 - retune nodata
2017-01-09 19:16:36.237 mpegts: 11012V in DVB - scan no data, failed
2017-01-09 19:16:36.237 subscription: 0010: "scan" unsubscribing
2017-01-09 19:16:36.757 subscription: 000E: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" unsubscribing from "bTV", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:36.771 mpegts: 12524H in DVB - tuning on #1
2017-01-09 19:16:36.828 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "NOVA", weight: 150, adapter: "#1", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "NOVA", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:37.757 mpegts: 11012V in DVB - tuning on #0
2017-01-09 19:16:37.829 subscription: 0018: "epggrab" subscribing to mux "11012V", weight: 4, adapter: "#0", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:37.884 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:38.192 linuxdvb: #1 - retune nodata
2017-01-09 19:16:38.892 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:39.129 linuxdvb: #0 - retune nodata
2017-01-09 19:16:39.786 mpegts: 12565H in DVB - scan timed out (26/5 tables)
2017-01-09 19:16:39.828 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:40.550 linuxdvb: #2 - retune nodata
2017-01-09 19:16:41.200 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:41.751 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:16:41.758 linuxdvb: #5 - retune nodata
2017-01-09 19:16:41.774 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:41.779 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:16:41.786 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:16:42.026 linuxdvb: #6 - retune nodata
2017-01-09 19:16:42.078 linuxdvb: #7 - retune nodata
2017-01-09 19:16:42.283 linuxdvb: #4 - retune nodata
2017-01-09 19:16:42.309 linuxdvb: #3 - retune nodata
2017-01-09 19:16:45.544 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:46.529 linuxdvb: #1 - retune nodata
2017-01-09 19:16:46.552 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:47.218 linuxdvb: #0 - retune nodata
2017-01-09 19:16:47.488 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:47.709 linuxdvb: #2 - retune nodata
2017-01-09 19:16:47.847 subscription: 0017: service instance is bad, reason: No input detected
2017-01-09 19:16:47.847 mpegts: 12524H in DVB - tuning on #0
2017-01-09 19:16:47.847 subscription: 0018: "epggrab" unsubscribing
2017-01-09 19:16:47.958 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "NOVA", weight: 150, adapter: "#0", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "NOVA", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:48.847 mpegts: 11012V in DVB - tuning on #1
2017-01-09 19:16:48.860 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:48.913 subscription: 001A: "epggrab" subscribing to mux "11012V", weight: 4, adapter: "#1", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:48.987 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:49.184 linuxdvb: #7 - retune nodata
2017-01-09 19:16:49.236 linuxdvb: #0 - retune nodata
2017-01-09 19:16:49.411 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:16:49.434 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:49.439 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:16:49.446 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:16:49.490 linuxdvb: #4 - retune nodata
2017-01-09 19:16:49.721 epggrab: Bulsatcom: Bula 39E - data completion timeout for 12606H in DVB
2017-01-09 19:16:49.721 epggrab: EIT: DVB Grabber - data completion timeout for 12606H in DVB
2017-01-09 19:16:49.721 subscription: 0003: "epggrab" unsubscribing
2017-01-09 19:16:49.721 epggrab: EIT: DVB Grabber - data completion timeout for 12565H in DVB
2017-01-09 19:16:49.721 epggrab: Bulsatcom: Bula 39E - data completion timeout for 12565H in DVB
2017-01-09 19:16:49.721 subscription: 0002: "epggrab" unsubscribing
2017-01-09 19:16:49.821 epggrab: Bulsatcom: Bula 39E - data completion timeout for 12688H in DVB
2017-01-09 19:16:49.821 epggrab: EIT: DVB Grabber - data completion timeout for 12688H in DVB
2017-01-09 19:16:49.821 subscription: 0005: "epggrab" unsubscribing
2017-01-09 19:16:49.822 epggrab: Bulsatcom: Bula 39E - data completion timeout for 12647H in DVB
2017-01-09 19:16:49.822 epggrab: EIT: DVB Grabber - data completion timeout for 12647H in DVB
2017-01-09 19:16:49.822 subscription: 0004: "epggrab" unsubscribing
2017-01-09 19:16:49.987 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:50.210 linuxdvb: #1 - retune nodata
2017-01-09 19:16:50.821 mpegts: 12729V in DVB - tuning on #6
2017-01-09 19:16:50.898 subscription: 001C: "epggrab" subscribing to mux "12729V", weight: 4, adapter: "#6", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:16:51.939 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:52.186 linuxdvb: #6 - retune nodata
2017-01-09 19:16:55.149 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:16:55.759 linuxdvb: #2 - retune nodata
2017-01-09 19:16:56.520 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:16:56.647 linuxdvb: #0 - poll TIMEOUT
2017-01-09 19:16:57.372 linuxdvb: #7 - retune nodata
2017-01-09 19:16:57.421 linuxdvb: #0 - retune nodata
2017-01-09 19:16:57.646 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:16:58.343 linuxdvb: #1 - retune nodata
2017-01-09 19:16:58.861 subscription: 0017: service instance is bad, reason: No input detected
2017-01-09 19:16:58.862 mpegts: 12524H in DVB - tuning on #5
2017-01-09 19:16:58.908 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "NOVA", weight: 150, adapter: "#5", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "NOVA", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:16:59.599 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:16:59.967 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:17:00.206 linuxdvb: #5 - retune nodata
2017-01-09 19:17:00.284 linuxdvb: #6 - retune nodata
2017-01-09 19:17:02.809 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:17:02.830 linuxdvb: #2 - retune nodata
2017-01-09 19:17:04.180 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:17:04.499 linuxdvb: #7 - retune nodata
2017-01-09 19:17:05.307 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:17:05.439 linuxdvb: #1 - retune nodata
2017-01-09 19:17:07.259 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:17:07.366 linuxdvb: #6 - retune nodata
2017-01-09 19:17:07.627 linuxdvb: #5 - poll TIMEOUT
2017-01-09 19:17:08.311 linuxdvb: #5 - retune nodata
2017-01-09 19:17:08.960 subscription: 0017: service instance is bad, reason: No input detected
2017-01-09 19:17:08.961 mpegts: 12524H in DVB - tuning on #4
2017-01-09 19:17:09.027 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "NOVA", weight: 150, adapter: "#4", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "NOVA", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:17:10.054 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:17:10.283 linuxdvb: #4 - retune nodata
2017-01-09 19:17:10.469 linuxdvb: #2 - poll TIMEOUT
2017-01-09 19:17:10.886 linuxdvb: #2 - retune nodata
2017-01-09 19:17:11.079 subscription: 0012: "epggrab" unsubscribing
2017-01-09 19:17:11.840 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:17:12.243 subscription: 0015: "epggrab" unsubscribing
2017-01-09 19:17:12.967 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:17:13.523 linuxdvb: #1 - retune nodata
Loglevel debug: enabled
2017-01-09 19:17:14.919 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:17:15.467 linuxdvb: #6 - retune nodata
2017-01-09 19:17:17.714 linuxdvb: #4 - poll TIMEOUT
2017-01-09 19:17:18.365 linuxdvb: #4 - retune nodata
2017-01-09 19:17:20.243 subscription: 0017: service instance is bad, reason: No input detected
2017-01-09 19:17:20.244 mpegts: 12524H in DVB - tuning on #3
2017-01-09 19:17:20.290 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" subscribing on channel "NOVA", weight: 150, adapter: "#3", network: "DVB", mux: "12524H", provider: "BULSATCOM", service: "NOVA", profile="htsp", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:17:20.627 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:17:20.636 linuxdvb: #1 - retune nodata
2017-01-09 19:17:21.335 linuxdvb: #3 - poll TIMEOUT
2017-01-09 19:17:21.606 linuxdvb: #3 - retune nodata
2017-01-09 19:17:22.580 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:17:23.052 subscription: 0017: "94.xxx.xxx.8 [ saen | Kodi Media Center ]" unsubscribing from "NOVA", hostname="94.xxx.xxx.8", username="saen", client="Kodi Media Center" 
2017-01-09 19:17:23.543 linuxdvb: #6 - retune nodata
2017-01-09 19:17:24.044 mpegts: 12524H in DVB - tuning on #7
2017-01-09 19:17:24.109 subscription: 001D: "epggrab" subscribing to mux "12524H", weight: 4, adapter: "#7", network: "DVB", service: "Raw PID Subscription" 
2017-01-09 19:17:25.193 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:17:25.458 linuxdvb: #7 - retune nodata
2017-01-09 19:17:28.287 linuxdvb: #1 - poll TIMEOUT
2017-01-09 19:17:28.774 linuxdvb: #1 - retune nodata
2017-01-09 19:17:28.904 subscription: 001A: "epggrab" unsubscribing
2017-01-09 19:17:30.240 linuxdvb: #6 - poll TIMEOUT
2017-01-09 19:17:30.615 linuxdvb: #6 - retune nodata
2017-01-09 19:17:30.861 subscription: 001C: "epggrab" unsubscribing
2017-01-09 19:17:32.854 linuxdvb: #7 - poll TIMEOUT
2017-01-09 19:17:33.491 linuxdvb: #7 - retune nodata

signal stable no data received
Configure arguments:
  --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --libexecdir=${prefix}/lib/tvheadend --disable-maintainer-mode --disable-dependency-tracking

Compiler:
  Using C compiler:                        cc
  Using LD flags:                           -ldvben50221 -ldvbapi -lucsi
  Build for arch:                          x86_64

Binaries:
  Using PYTHON:                            python
  Using GZIP:                              gzip
  Using BZIP2:                             bzip2

Options:
  pie                                      yes
  ccdebug                                  no
  cwc                                      yes
  capmt                                    yes
  constcw                                  yes
  linuxdvb                                 yes
  satip_server                             yes
  satip_client                             yes
  hdhomerun_client                         yes
  hdhomerun_static                         yes
  iptv                                     yes
  tsfile                                   yes
  dvbscan                                  yes
  timeshift                                yes
  trace                                    yes
  imagecache                               yes
  avahi                                    yes
  zlib                                     yes
  libav                                    yes
  ffmpeg_static                            yes
  libx264                                  yes
  libx264_static                           yes
  libx265                                  yes
  libx265_static                           yes
  libvpx                                   yes
  libvpx_static                            yes
  libtheora                                yes
  libtheora_static                         yes
  libvorbis                                yes
  libvorbis_static                         yes
  libfdkaac                                yes
  libfdkaac_static                         yes
  nvenc                                    no
  qsv                                      no
  libmfx_static                            no
  inotify                                  yes
  epoll                                    yes
  uriparser                                yes
  ccache                                   no
  tvhcsa                                   yes
  bundle                                   no
  dvbcsa                                   no
  dvben50221                               yes
  kqueue                                   no
  dbus_1                                   yes
  android                                  no
  tsdebug                                  no
  gtimer_check                             yes
  slow_memoryinfo                          no
  libsystemd_daemon                        no
  bintray_cache                            yes
  execinfo                                 yes
  mmx                                      yes
  sse2                                     yes
  W_unused_result                          yes
  getloadavg                               yes
  atomic64                                 yes
  atomic_time_t                            yes
  bitops64                                 yes
  lockowner                                yes
  qsort_r                                  yes
  stime                                    yes
  gmtoff                                   yes
  recvmmsg                                 yes
  sendmmsg                                 yes
  libdvben50221                            yes
  ifnames                                  yes
  py_gzip                                  yes
  bin_pkg_config                           yes
  bin_xgettext                             yes
  bin_msgmerge                             yes
  bin_gzip                                 yes
  bin_bzip2                                yes
  ssl                                      yes
  linuxdvbapi                              yes
  upnp                                     yes
  bin_cmake                                yes
  stdcpp                                   yes
  libogg_static                            yes
  inotify_h                                yes
  linuxdvb_ca                              yes
  mpegts                                   yes
  mpegts_dvb                               yes

Packages:
  openssl                                  1.0.1f
  zlib                                     1.2.8
  liburiparser                             0.7.5
  avahi-client                             0.6.31
  dbus-1                                   1.6.18

Installation paths:
  Prefix:                                  /usr
  Binaries:                                ${prefix}/bin
  Libraries:                               ${prefix}/lib
  Data files:                              ${prefix}/share
  Man pages:                               /usr/share/man

#27 Updated by Rainer Dorsch 3 months ago

I see a signal strength of -26.1 dB and a SNR of 10 dB. Numbers change though if I change the channel, e.g. another one has -30.8 dB/12.6 dB or even if I switch back to the original channel.

The numbers are from the status->stream tab.

I see pretty consistent breaks, e.g. I recorded 3 days in a row all recording broke up after about 400 MB. If it would be depended on a signal issue, I would expect impact of the weather and a more random behavior. But I am just speculating here...

#28 Updated by Jan Schröter about 1 month ago

I often get "mpegts: too much queued table input data (over 2MB), discarding new" warnings during the epggrab.

I had the exactly same problems for a long time. During several months i changed several things like for example went from direct attached TBS6205 to Tvheadend as an SAT>IP client of minisatip. In all these constellations watching tv worked fine, parallel recording of several streams an zapping worked fine. But when the epg grabber (ota) started it was a matter of time, when this error occures. Same symptoms - no more webinterface, no more reactions on SIGTERM - only SIGKILL works.

I was running epg grabber every 30 Minutes (*/30 * * * *) and had set a timeout of 300 seconds. All 4 tuners where activated for OTA grabber. With this settings it was a question of hours until when the error occurs.

Now my tvheadend Server is running stable for days an shows not a single sign of changing this. I hadn't changed my usage profile, but epg grabber settings as following:
- default grabber times (4 2 * * * / 4 14 * * *)
- 30 seconds timeout
- only one tuner activated for ota grabbing

This brings me to the question if the problems could maybe lie in some kind of race condition or blocking in epg-grabber itself?

#29 Updated by Jaroslav Kysela about 1 month ago

Jan Schröter wrote:

I often get "mpegts: too much queued table input data (over 2MB), discarding new" warnings during the epggrab.

I had the exactly same problems for a long time. During several months i changed several things like for example went from direct attached TBS6205 to Tvheadend as an SAT>IP client of minisatip. In all these constellations watching tv worked fine, parallel recording of several streams an zapping worked fine. But when the epg grabber (ota) started it was a matter of time, when this error occures. Same symptoms - no more webinterface, no more reactions on SIGTERM - only SIGKILL works.

If you have TVH in this condition, you should provide the full backtrace - https://tvheadend.org/projects/tvheadend/wiki/Debugging - to analyze, if there are some mutex issues.

Also available in: Atom PDF