Project

General

Profile

Bug #4573

SAT>IP: RTP-over-TCP crash!

Added by Mono Polimorph over 7 years ago. Updated over 7 years ago.

Status:
Fixed
Priority:
Normal
Category:
SAT>IP
Target version:
-
Start date:
2017-09-05
Due date:
% Done:

100%

Estimated time:
Found in version:
edge-2017-09-04 (after revision b829ab46)
Affected Versions:

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

#2

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.

#3

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

#4

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?

#5

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
#6

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!

#8

Updated by Jaroslav Kysela over 7 years ago

Try v4.3-453-g3391e1d99 ...

#9

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.

#10

Updated by g siviero over 7 years ago

tvheadend_4.3-460~g3e2ac87_armhf.deb still crashes.

#12

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!

#13

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?)
#14

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.

#15

Updated by Jaroslav Kysela over 7 years ago

Fixed in v4.3-471-g219dc8e5d.

#16

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.

#17

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.

Also available in: Atom PDF