Bug #4573
SAT>IP: RTP-over-TCP crash!
100%
Description
Hi,
I open a new issue, as the previous are very large... #4226 & #4517.
http://www.tvheadend.org/projects/tvheadend/repository/revisions/b829ab46c923f6487dee636b4d4cd1ef61c94826
After this commit the RTP-over-TCP crashes every time. You start the TVH and at the first SETUP request the server crashes. See the log:
2017-09-05 13:41:15.946 [ INFO]:epgdb: seasons 0 2017-09-05 13:41:15.946 [ INFO]:epgdb: episodes 0 2017-09-05 13:41:15.946 [ INFO]:epgdb: broadcasts 0 2017-09-05 13:41:15.946 [ NOTICE]:START: HTS Tvheadend version 0.0.0~unknown started, running as PID:10152 UID:0 GID:0, CWD:/ CNF:/root/tvheadend-20170904/config 2017-09-05 13:41:16.092 [ INFO]:scanfile: DVB-S - loaded 1 regions with 112 networks 2017-09-05 13:41:16.092 [ INFO]:scanfile: DVB-T - loaded 44 regions with 1112 networks 2017-09-05 13:41:16.092 [ INFO]:scanfile: DVB-C - loaded 17 regions with 57 networks 2017-09-05 13:41:16.092 [ INFO]:scanfile: ATSC-T - loaded 2 regions with 11 networks 2017-09-05 13:41:16.092 [ INFO]:scanfile: ATSC-C - loaded 1 regions with 5 networks 2017-09-05 13:41:16.092 [ INFO]:scanfile: ISDB-T - loaded 2 regions with 1297 networks 2017-09-05 13:41:46.235 [ DEBUG]:satips: 3/C4A4DBF1/1: SETUP from 192.168.1.14:42058 DVB-S2 freq 12032000 H sym 27500000 fec 9/10 mod QPSK roff 35 is_id -1 pls_mode ROOT pls_code 0 pids <none> 2017-09-05 13:41:46.235 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - add raw service 2017-09-05 13:41:46.235 [ DEBUG]:service: 1: Stream 224.0.1.5 (12031500) in IPTV Ingest si 0x7f1fdde266a0 <unknown> weight 0 prio 11 error 0 2017-09-05 13:41:46.235 [ INFO]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - tuning on IPTV 2017-09-05 13:41:46.235 [ DEBUG]:satips: RTP streaming to 192.168.1.14:42058 open 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0000 (0) [20/0x7f1fddf11620] 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0001 (1) [16/0x7f1fddf20930] 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0010 (16) [16/0x7f1fddf21db0] 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0011 (17) [20/0x7f1fddf23230] 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0011 (17) [16/0x7f1fddf246b0] 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - started 2017-09-05 13:41:46.238 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0000 (0) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.238 [ INFO]:subscription: 0001: "SAT>IP" subscribing to mux "Stream 224.0.1.5 (12031500)", weight: 100, adapter: "IPTV", network: "IPTV Ingest", service: "Raw PID Subscription", hostname="192.168.1.14" 2017-09-05 13:41:46.271 [ DEBUG]:satips: 3/C4A4DBF1/1: PLAY from 192.168.1.14:42058 DVB-S2 freq 12032000 H sym 27500000 fec 9/10 mod QPSK roff 35 is_id -1 pls_mode ROOT pls_code 0 pids 0,1,16,17,18,8187 2017-09-05 13:41:46.271 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0001 (1) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.271 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0010 (16) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.271 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0011 (17) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.271 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 0012 (18) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.271 [ DEBUG]:mpegts: Stream 224.0.1.5 (12031500) in IPTV Ingest - open PID 1FFB (8187) [2/0x7f1fddee2a00] 2017-09-05 13:41:46.277 [ ALERT]:CRASH: Signal: 6 in PRG: /root/tvheadend-20170904/tvheadend (0.0.0~unknown) [72bd45b2d1cdfad5536f2609244fc62369184b0d] CWD: / 2017-09-05 13:41:46.277 [ ALERT]:CRASH: Fault address 0x27a8 (N/A) 2017-09-05 13:41:46.277 [ ALERT]:CRASH: Loaded libraries: /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 /lib/x86_64-linux-gnu/libpcre.so.3 /lib/x86_64-linux-gnu/libdl.so.2 /lib/x86_64-linux-gnu/libpthread.so.0 /lib/x86_64-linux-gnu/libm.so.6 /lib/x86_64-linux-gnu/librt.so.1 /lib/x86_64-linux-gnu/libc.so.6 /lib/x86_64-linux-gnu/libz.so.1 /lib64/ld-linux-x86-64.so.2 /lib/x86_64-linux-gnu/libnss_compat.so.2 /lib/x86_64-linux-gnu/libnsl.so.1 /lib/x86_64-linux-gnu/libnss_nis.so.2 /lib/x86_64-linux-gnu/libnss_files.so.2 2017-09-05 13:41:46.277 [ ALERT]:CRASH: Register dump [23]: 000000000000000000007f1fda199c6000000000000000080000000000000202000000000000001c00007f1fd31f67400000000000000076000000000000000700000000000027a800000000000027c800007f1fd31f6e60000000000000000000000000000000060000000000000000ffffffffffffffff00007f1fd31f641800007f1fda1c81650000000000000202000000000000003300000000000000000000000000000000fffffffe7ffbba130000000000000000 2017-09-05 13:41:46.277 [ ALERT]:CRASH: STACKTRACE 2017-09-05 13:41:46.299 [ DEBUG]:service: Stream 224.0.1.5 (12031500) in IPTV Ingest: Status changed to [Demuxed packets] 2017-09-05 13:41:46.299 [ DEBUG]:service: Stream 224.0.1.5 (12031500) in IPTV Ingest: Status changed to [Demuxed packets] [Reassembled packets] 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: 0x7f1fdde2bb60: tsid 2A71 (10865) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: nit on pid 0010 (16) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: sid 48DB (18651) on pid 0065 (101) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: sid 48DC (18652) on pid 0066 (102) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: sid 48DD (18653) on pid 0067 (103) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: sid 48DE (18654) on pid 0068 (104) 2017-09-05 13:41:46.300 [ DEBUG]:tbl-base: pat: sid 48DF (18655) on pid 0069 (105) 2017-09-05 13:41:46.413 [ DEBUG]:tbl-base: pat: completed pid 0 table 00000000 / 00000000 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: onid FFF1 (65521) tsid 2A69 (10857) 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: mux Stream 239.164.85.7 (11953500) in IPTV Ingest 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: sid 488B (18571) running 4 free_ca 0 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: sid 488C (18572) running 4 free_ca 0 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: sid 488D (18573) running 4 free_ca 0 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: sid 488E (18574) running 4 free_ca 0 2017-09-05 13:41:46.438 [ DEBUG]:tbl-base: sdt: sid 488F (18575) running 4 free_ca 0
I suggest to rollback the commit rb829ab46.
And I want to make a call to all who can test the RTP-over-TCP (for example using one TVH as a SAT>IP client of another TVH server):
Please, check in your environment if the TCP transport works.
I'm interested in a robust TCP transport with SAT>IP.
Please, help us!
History
Updated by Mono Polimorph over 7 years ago
Jaroslav Kysela wrote:
https://tvheadend.org/projects/tvheadend/wiki/Debugging#Incorrect-not-useable-crash-reports
Sorry! I'll prepare a correct one.
However, please check it in your environment as RTP-over-TCP always fails with the current staging.
Updated by Mono Polimorph over 7 years ago
Mono Polimorph wrote:
Hi,
I open a new issue, as the previous are very large... #4226 & #4517.
http://www.tvheadend.org/projects/tvheadend/repository/revisions/b829ab46c923f6487dee636b4d4cd1ef61c94826
After this commit the RTP-over-TCP crashes every time. You start the TVH and at the first SETUP request the server crashes. See the log:[...]
I suggest to rollback the commit rb829ab46.
Sorry! The commit that fails is rebbbc3b1:
http://www.tvheadend.org/projects/tvheadend/repository/revisions/ebbbc3b1e9c954a19c4aa518d83ccd28d67e6d23
Updated by Mono Polimorph over 7 years ago
Hi Jaros,
You tested the current snapshot with RTP-over-TCP enabled between two TVH instances?
I don't think you did. In all test I do, all the time it crashes!
Any suggestion?
Updated by g siviero over 7 years ago
I also confirm that with tvheadend_4.3-448~g2f07ea0_armhf.deb my tvheadend SAT-IP server (192.168.1.24) crashes and cannot be reached from the TVH SAT-IP client (previous versions continue to respond):
2017-09-08 11:10:36.593 mpegts: 506MHz in DVB-T Italy - tuning on SAT>IP DVB-T Tuner #2 (192.168.1.24:9983) 2017-09-08 11:10:36.593 subscription: 6EF0: "scan" subscribing to mux "506MHz", weight: 6, adapter: "SAT>IP DVB-T Tuner #2 (192.168.1.24:9983)", network: "DVB-T Italy", service: "Raw PID Subscription" 2017-09-08 11:10:36.594 mpegts: 722MHz in DVB-T Italy scan complete 2017-09-08 11:10:36.594 subscription: 6EE4: "scan" unsubscribing 2017-09-08 11:10:36.594 mpegts: 746MHz in DVB-T Italy - tuning on SAT>IP DVB-T Tuner #4 (192.168.1.22:9983) 2017-09-08 11:10:36.595 subscription: 6EF2: "scan" subscribing to mux "746MHz", weight: 6, adapter: "SAT>IP DVB-T Tuner #4 (192.168.1.22:9983)", network: "DVB-T Italy", service: "Raw PID Subscription" 2017-09-08 11:10:36.596 satip: SAT>IP DVB-T Tuner #2 (192.168.1.24:9983) - RTSP error -111 (Connection refused) [6-0] 2017-09-08 11:10:41.592 mpegts: 506MHz in DVB-T Italy - scan no data, failed 2017-09-08 11:10:41.592 subscription: 6EF0: "scan" unsubscribing
Updated by Mono Polimorph over 7 years ago
Jaroslav Kysela wrote:
https://tvheadend.org/projects/tvheadend/wiki/Debugging#Incorrect-not-useable-crash-reports
Hi Jaros,
Impossible to generate any other report that the one printed in the first post.
However, I do this: start tvhe, attach gdb to it and "c", generate the crash (easy, any RTSP-over-TCP call raises a crash), then inside the gdb "thread apply all where"
Here the stack-trace of the thread that raises the crash:
Thread 5 (Thread 0x7fce54d4e700 (LWP 16826)): #0 0x00007fce57bf3165 in raise () from /lib/x86_64-linux-gnu/libc.so.6 #1 0x00007fce57bf63e0 in abort () from /lib/x86_64-linux-gnu/libc.so.6 #2 0x00007fce57c2d39b in ?? () from /lib/x86_64-linux-gnu/libc.so.6 #3 0x00007fce57c36be6 in ?? () from /lib/x86_64-linux-gnu/libc.so.6 #4 0x00007fce57c3b98c in free () from /lib/x86_64-linux-gnu/libc.so.6 #5 0x00007fce5947fa43 in htsbuf_data_free (hq=<optimized out>, hd=0x7fce5aedaa60) at src/htsbuf.c:72 #6 0x00007fce59450db5 in http_extra_flush (hc=0x7fce54549960) at src/http.c:820 #7 0x00007fce594515de in http_extra_send_prealloc (hc=<optimized out>, data=data@entry=0x7fce54d4cf80, data_len=data_len@entry=68) at src/http.c:900 #8 0x00007fce594e3822 in satip_rtp_tcp_data (stream=stream@entry=1 '\001', data=data@entry=0x7fce54d4cf80 "$\001", data_len=data_len@entry=68, rtp=<error reading variable: Unhandled dwarf expression opcode 0xfa>) at src/satip/rtp.c:277 #9 0x00007fce594e53ea in satip_rtcp_thread (aux=<optimized out>) at src/satip/rtp.c:936 #10 0x00007fce59446bb3 in thread_wrapper (p=0x7fce5af0f8b0) at src/wrappers.c:161 #11 0x00007fce583dcb50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0 #12 0x00007fce57c9c95d in clone () from /lib/x86_64-linux-gnu/libc.so.6 #13 0x0000000000000000 in ?? ()
Please, remember that any use of the RTP-over-TCP generates a crash!
Updated by Mono Polimorph over 7 years ago
Hi,
The crash seems to be created by this line of code:
http://www.tvheadend.org/projects/tvheadend/repository/revisions/ebbbc3b1e9c954a19c4aa518d83ccd28d67e6d23/entry/src/htsbuf.c#L70
And the change was introduced in this patch:
http://www.tvheadend.org/projects/tvheadend/repository/revisions/ebbbc3b1e9c954a19c4aa518d83ccd28d67e6d23/diff/src/htsbuf.c
But this patch has completely broken the RTP-over-TCP mode!
Updated by g siviero over 7 years ago
tvheadend_4.3-453~g3391e1d_armhf.deb still crashes.
On TVH SAT>IP client I just run a "force scan" on one of the networks and the server crashes immediately.
Updated by Mono Polimorph over 7 years ago
Jaroslav Kysela wrote:
Try v4.3-453-g3391e1d99 ...
Hi,
Indentical behaviour with this release!
Thread 9 (Thread 0x7ff726059700 (LWP 18171)): #0 0x00007ff728efe165 in raise () from /lib/x86_64-linux-gnu/libc.so.6 #1 0x00007ff728f013e0 in abort () from /lib/x86_64-linux-gnu/libc.so.6 #2 0x00007ff728f3839b in ?? () from /lib/x86_64-linux-gnu/libc.so.6 #3 0x00007ff728f41be6 in ?? () from /lib/x86_64-linux-gnu/libc.so.6 #4 0x00007ff728f4698c in free () from /lib/x86_64-linux-gnu/libc.so.6 #5 0x00007ff72a78a9e3 in htsbuf_data_free (hq=<optimized out>, hd=0x7ff72cb74150) at src/htsbuf.c:72 #6 0x00007ff72a75beb3 in http_extra_flush (hc=0x7ff725050960) at src/http.c:826 #7 0x00007ff72a75c6ce in http_extra_send_prealloc (hc=<optimized out>, data=data@entry=0x7ff726057f80, data_len=data_len@entry=88) at src/http.c:904 #8 0x00007ff72a7ee302 in satip_rtp_tcp_data (stream=stream@entry=1 '\001', data=data@entry=0x7ff726057f80 "$\001", data_len=data_len@entry=88, rtp=<error reading variable: Unhandled dwarf expression opcode 0xfa>) at src/satip/rtp.c:277 #9 0x00007ff72a7efece in satip_rtcp_thread (aux=<optimized out>) at src/satip/rtp.c:935 #10 0x00007ff72a751c93 in thread_wrapper (p=0x7ff72cc1a7c0) at src/wrappers.c:161 #11 0x00007ff7296e7b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0 #12 0x00007ff728fa795d in clone () from /lib/x86_64-linux-gnu/libc.so.6 #13 0x0000000000000000 in ?? ()
You see that the crash is caused by this line of code?
http://www.tvheadend.org/projects/tvheadend/repository/revisions/ebbbc3b1e9c954a19c4aa518d83ccd28d67e6d23/entry/src/htsbuf.c#L70
I appreciate your effort with the development of the TVH. But please take note that the RTP-over-TCP is now completly wroken. If you check the code in your environment... you see that any call using the the RTP-over-TCP crash! The crash starts when the first RTCP packet is sent, that is, when the first Interlaved packet is sent.
Thank you for your support!
Updated by g siviero over 7 years ago
I'm not very familiar with debugging.
I obtained the following info at the moment:
#0 0x75beaf70 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 _sys_result = <optimized out> pd = 0x70bfef60 pid = <optimized out> selftid = 20926 #1 0x75bec324 in __GI_abort () at abort.c:89 save_stage = 2 act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0 <repeats 27 times>, 1891621600, 7, 75, 75, 1891621600}}, sa_flags = 7, sa_restorer = 0x4b} sigs = {__val = {32, 0 <repeats 31 times>}} #2 0x75c26954 in __libc_message (do_abort=<optimized out>, fmt=0x75cdc6e8 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175 ap = {__ap = 0x70bfdc14} fd = 1 on_2 = <optimized out> list = <optimized out> nlist = <optimized out> cp = <optimized out> written = <optimized out> #3 0x75c2cb80 in malloc_printerr (action=1, str=0x75cdc8ec "free(): invalid pointer", ptr=<optimized out>) at malloc.c:4996 buf = "70bfdd24" cp = <optimized out> #4 0x75c2db24 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=56) at malloc.c:3840 size = <optimized out> fb = <optimized out> nextchunk = <optimized out> nextsize = <optimized out> nextinuse = <optimized out> prevsize = <optimized out> bck = <optimized out> fwd = <optimized out> errstr = <optimized out> locked = <optimized out> __func__ = "_int_free" #5 0x54c5d2d8 in htsbuf_data_free (hq=hq@entry=0x54c2d114 <http_extra_flush+400>, hd=hd@entry=0x72d004b8) at src/htsbuf.c:72 No locals. #6 0x54c2d114 in http_extra_flush (hc=0x6bfd07a0) at src/http.c:826 hd = 0x72d004b8 r = <optimized out> serr = 0 #7 0x54c2d284 in http_extra_send_prealloc (hc=<optimized out>, data=data@entry=0x70bfdd24, data_len=data_len@entry=96) at src/http.c:904 No locals. #8 0x54cc42f4 in satip_rtp_tcp_data (rtp=0x74b01428, data_len=96, data=0x70bfdd1c "", stream=1 '\001') at src/satip/rtp.c:277 No locals. #9 satip_rtcp_thread (aux=<optimized out>) at src/satip/rtp.c:935 rtp = 0x74b01428 us = <optimized out> msg = "$\001\000\\\000\000\000\000SES1\000\000\000Over=1.1;tuner=2,220,0,15,754,8,dvbt,8k,qam64,14,,,,;pids=0,1,16,17,18,3002,3003", '\000' <repeats 1325 times> addrbuf = '\000' <repeats 49 times> r = <optimized out> len = 96 err = <optimized out> #10 0x54c22e6c in thread_wrapper (p=0x5c77ca90) at src/wrappers.c:161 ts = 0x5c77ca90 set = {__val = {16388, 0 <repeats 31 times>}} r = <optimized out> #11 0x76ba6e90 in start_thread (arg=0x70bfef60) at pthread_create.c:311 pd = 0x70bfef60 unwind_buf = {cancel_jmp_buf = {{jmp_buf = {1891626952, 1, 2126513284, 338, 1431061564, 1963177152, 0, 1891625628, -60367753, -94151817, 0 <repeats 54 times>}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = 0 pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #12 0x75c8e598 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S:92 from /lib/arm-linux-gnueabihf/libc.so.6 No locals. Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Updated by Jaroslav Kysela over 7 years ago
- Status changed from New to Fixed
- % Done changed from 0 to 100
Applied in changeset commit:tvheadend|95664069c5e1a45ad1fd99c24de4a3d028f7b855.
Updated by g siviero over 7 years ago
I confirm that tvheadend_4.3-471~g219dc8e_armhf.deb is now working as expected (no more crashes) in my SAT>IP client/server configuration.
Thanks.
Updated by Mono Polimorph over 7 years ago
Jaroslav Kysela wrote:
Fixed in v4.3-471-g219dc8e5d.
Thank you! Now RTP-over-TCP doesn't crash.
However, another problem appears:
2017-09-15 16:19:03.239 satip: SAT>IP DVB-S Tuner #1 (192.168.1.22) - RTSP error -90 (Message too long) [5-0] 2017-09-15 16:19:03.721 subscription: 0009: service instance is bad, reason: Tuning failed
When the TCP socket collapses, this problem appears.
I'll open another issue.
Regards.