Segfault: 3pcc with optional first recv makes sendMode schizofrenic

[sharkwsk]

I am trying to establish a basic call scenario

• A: register and call B
• B: register and wait for call
• refresh registrations periodically for User A & B

I am using 3pcc scenario for a "register and wait for INVITE" for B party
However when the sendCmd is sends the trigger, the B party scenario crashes with "segmentation fault"

Have attached all the scenarios (A party, B party, 3PCC trigger to B party scenario)
scenarios.zip

Version: SIPp v3.7-dev-9-ga284f3a-PCAP-RTPSTREAM-RTPCHECK

[sharkwsk]

Any feedback on this issue ?

[wdoekes]

It's good that you're asking attention for bugs.

But, the amount of time we can dedicate to this differs wildly. Any additional info you can get on your own, helps.

Add -g -O0 and try to get a backtrace from gdb:

$ cmake -DDEBUG=1 [optional other args..] .
$ make
$ gdb ./sipp
(gdb) run [arguments to sipp...]

When it crashes, you can do bt and bt full and info locals and all sorts of nice debug stuff.

[sharkwsk]

Thanks for your feedback, and apologies for my ignorance. I am pretty novice when it comes to debugging C/C++ applications :(

I managed to recompile with deubg option and run with gdb, here is the details. Note that I have masked the IPs for obvious reasons

Starting program: /home/sipp/sipp_full 10.10.10.1 -3pcc 192.168.1.1:9001 -i 10.10.10.1 -p 5060 -nd -t t1 -sf ./receive.xml -inf ./B_user.csv -trace_msg

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0x0000555555631bdd in process_message(SIPpSocket*, char*, long, sockaddr_storage*) ()
#0  0x0000555555631bdd in process_message(SIPpSocket*, char*, long, sockaddr_storage*) ()
#1  0x0000555555637222 in SIPpSocket::pollset_process(int) ()
#2  0x000055555564cacb in traffic_thread(int&, int&) ()
#3  0x0000555555651441 in main ()
#0  0x0000555555631bdd in process_message(SIPpSocket*, char*, long, sockaddr_storage*) ()
#1  0x0000555555637222 in SIPpSocket::pollset_process(int) ()
#2  0x000055555564cacb in traffic_thread(int&, int&) ()
#3  0x0000555555651441 in main ()

[sharkwsk]

I could not make much of the debug messages, Is it related to some socket connectivity issues ?

[wdoekes]

Me neither. It looks as if the -g didn't quite stick. We should at least see filenames and linenumbers in that backtrace.

[sharkwsk]

I did the following

1. Re-build sipp after adding -DDEBUG=1 flag on top of the --full section in build.sh script

2. Executed below for B party
   gdb ./sipp
   set logging on
   run 10.10.10.1 -3pcc 192.168.1.1:9001 -i 10.10.10.1 -p 5060 -nd -t t1 -sf ./receive.xml -inf ./B_user.csv -trace_msg
   bt
   bt full
   info locals

3. Executed the Aparty using another script

Am I doing anything obviously wrong :(

[wdoekes]

Not something obvious, no.

$ make VERBOSE=1
...

Look for -g in the c++ commands.

Or do:

$ touch src/*.cpp; make VERBOSE=1 2>&1 | grep --color=yes -- -g

The binary should have lots of debug symbols (and therefore be big):

$ ls -lh sipp
-rwxrwxr-x 1 walter walter 6.4M okt 19 11:32 sipp

$ gdb ./sipp
...
(gdb) print process_message
$1 = {void (SIPpSocket *, char *, ssize_t, sockaddr_storage *)} 0xe517a <process_message(SIPpSocket*, char*, long, sockaddr_storage*)>
(gdb) quit

$ addr2line -Cfe ./sipp 0xe517a
process_message(SIPpSocket*, char*, long, sockaddr_storage*)
sipp/src/socket.cpp:1102

[sharkwsk]

Here is the revised gdb log

Starting program: /home/sipp/sipp_full 10.10.10.1 -3pcc 192.168.1.1:9001 -i 10.10.10.1 -p 5060 -nd -t t1 -sf ./receive.xml -inf ./B_user.csv -trace_msg
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0x0000555555631bdd in process_message (socket=0x555555b74be0, msg=0x7ffffffbdbe0 "Call-ID: [email protected]\r\nContact: sip:[email protected]:48568;transport=UDP\r\nUser-Agent: SIPp\r\n\r\n", msg_size=113,
src=0x7ffffffbdb60) at /root/sipp/sipp/src/socket.cpp:1170
1170 /root/sipp/sipp/src/socket.cpp: No such file or directory.
$1 = {void (SIPpSocket , char , ssize_t, sockaddr_storage )} 0x5555556317ce <process_message(SIPpSocket, char, long, sockaddr_storage)>

#addr2line -Cfe ./sipp 0x5555556317ce
??
??:0

[sharkwsk]

I was trying to check the socket.cpp file existing under src directory and it is. So I am not sure what is the actual fault of this error

src=0x7ffffffbdb60) at /root/sipp/sipp/src/socket.cpp:1170
1170 /root/sipp/sipp/src/socket.cpp: No such file or directory.

[wdoekes]

Well.. that line is probably correct, 1170 in socket.cpp.

But you're really only giving us minimal info.

info locals
and
bt
and
bt full
would give a lot more.

With 1170, we know that:

                    case T_TLS:
                        new_ptr->associate_socket(tcp_multiplex);
                        tcp_multiplex->ss_count++;            /* 1170: it crashes here */
                        break;
                    }

And that's because tcp_multiplex is bad. But we don't know in what kind of bad state it is. It is probably NULL (0x0), but we cannot tell from just the words Segmentation fault.

Help us help yourself.

[sharkwsk]

Apologies again, I will try my best to get the necessary logs. I have re-run with above commands and logs again...
If any further info needed, do let me know how I could extract them. I am more than happy to re-run the test

---

Program received signal SIGSEGV, Segmentation fault.
                                                    0x0000555555631bdd in process_message (socket=0x555555b74be0, msg=0x7ffffffbdbe0 "Call-ID: [email protected]\r\nContact: <sip:[email protected]:36526;transport=UDP>\r\nUser-Agent: SIPp\r\n\r\n", msg_size=114, 
    src=0x7ffffffbdb60) at /root/sipp/sipp/src/socket.cpp:1170
1170    /root/sipp/sipp/src/socket.cpp: No such file or directory.

(gdb) bt
#0  0x0000555555631bdd in process_message (socket=0x555555b74be0, msg=0x7ffffffbdbe0 "Call-ID: [email protected]\r\nContact: <sip:[email protected]:36526;transport=UDP>\r\nUser-Agent: SIPpTester\r\n\r\n", msg_size=114, 
    src=0x7ffffffbdb60) at /root/sipp/sipp/src/socket.cpp:1170
#1  0x0000555555637222 in SIPpSocket::pollset_process (wait=1) at /root/sipp/sipp/src/socket.cpp:2995
#2  0x000055555564cacb in traffic_thread (rtp_errors=@0x7fffffffdd98: 0, echo_errors=@0x7fffffffdd9c: 0) at /root/sipp/sipp/src/sipp.cpp:601
#3  0x0000555555651441 in main (argc=16, argv=0x7fffffffe268) at /root/sipp/sipp/src/sipp.cpp:2161

(gdb) bt full
#0  0x0000555555631bdd in process_message (socket=0x555555b74be0, msg=0x7ffffffbdbe0 "Call-ID: [email protected]\r\nContact: <sip:[email protected]:36526;transport=UDP>\r\nUser-Agent: SIPpTester\r\n\r\n", msg_size=114, 
    src=0x7ffffffbdb60) at /root/sipp/sipp/src/socket.cpp:1170
        new_ptr = 0x555555b75d10
        call_id = 0x5555558f0660 <get_call_id(char const*)::call_id> "[email protected]"
        listener_ptr = 0x0
        currentTime = {tv_sec = 1603358235, tv_usec = 457858}
#1  0x0000555555637222 in SIPpSocket::pollset_process (wait=1) at /root/sipp/sipp/src/socket.cpp:2995
        msg = <error reading variable msg (value requires 262144 bytes, which is more than max-value-size)>
        src = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}
        len = 114
        sock = 0x555555b74be0
        ret = 114
        old_pollnfds = 4
        poll_idx = 3
        events = 1
        event_idx = 0
        rs = 1
        __PRETTY_FUNCTION__ = "static void SIPpSocket::pollset_process(int)"
#2  0x000055555564cacb in traffic_thread (rtp_errors=@0x7fffffffdd98: 0, echo_errors=@0x7fffffffdd9c: 0) at /root/sipp/sipp/src/sipp.cpp:601
        running_tasks = 0x555555a71200 <running_tasks[abi:cxx11]>
        loops = 1000
        last = 0x0
        iter = 0x1
        L_file_name = "receivereg_15547_screen.log\000\000\000\000\000\000\022\247U\020\000\000\000\a\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\200\000\256UUU\000\000 \001\000\000\000\000\000\000\220\377\377\377\377\377\377\377\004\000\000\000\000\000\000\000\020\000\000\000\064", '\000' <repeats 27 times>, "|\000\000\000w\000\000\000n\000\000\000[", '\000' <repeats 19 times>, "\370\000\000\000\000\000\000\000\220\377\377\377\377\377\377\377\v\000\000\000\000\000\000\000`\342\377\377\377\177", '\000' <repeats 18 times>...
        __PRETTY_FUNCTION__ = <optimised out>
#3  0x0000555555651441 in main (argc=16, argv=0x7fffffffe268) at /root/sipp/sipp/src/sipp.cpp:2161
        argi = 16
        pthread2_id = 0
        pthread3_id = 0
        generic_count = 0
        slave_masterSet = false
        rtp_errors = 0
        echo_errors = 0
        __PRETTY_FUNCTION__ = "int main(int, char**)"

(gdb) info locals
argi = 16
pthread2_id = 0
pthread3_id = 0
generic_count = 0
slave_masterSet = false
rtp_errors = 0
echo_errors = 0
__PRETTY_FUNCTION__ = "int main(int, char**)"
(gdb) 
argi = 16
pthread2_id = 0
pthread3_id = 0
generic_count = 0
slave_masterSet = false
rtp_errors = 0
echo_errors = 0
__PRETTY_FUNCTION__ = "int main(int, char**)"
(gdb) print process_message
$1 = {void (SIPpSocket *, char *, ssize_t, sockaddr_storage *)} 0x5555556317ce <process_message(SIPpSocket*, char*, long, sockaddr_storage*)>

(gdb) quit
A debugging session is active.

        Inferior 1 [process 15547] will be killed.

Quit anyway? (y or n) y

# addr2line -Cfe ./sipp 0x5555556317ce
??
??:0

[sharkwsk]

Any findings based on the above logs. I could read below messages related to size, is there any maximum limit my message is exceeding and causing the crash ?

error reading variable msg (value requires 262144 bytes, which is more than max-value-size

[sharkwsk]

@wdoekes - Any hints on what I could check and try. Unfortunately I am not that familiar with SIPp code to try things out...

Thanks

[wdoekes]

So, I tried to spend a little time on this now.

But I found:

• no B_users.csv
• no example invocations of sipp
• IP addresses that I don't have (try using 127.x.x.x for IPs on localhost)

.. faith .. humanity ..

I hate to sound disappointed, but again: if you want our help, you need to make it possible for us to help you.

Please:
(a) add all files we need to reproduce this
(b) describe all steps we need to reproduce this
(c) ensure we can reproduce this on localhost, without conjuring up 10.x and 192.x networks

[sharkwsk]

Happy to share the actual files and commands one-to-one via an email if possible....

[wdoekes]

So, you're saying it's hard to reproduce with generic (non-private) details?

[sharkwsk]

No, it can be reproduced all the time. Issue is the IPs and specific system specific details, I am unable to share over public forum unless I mask it

[sharkwsk]

Here is the revised logs with scenario & input files (again screened for actual IPs)
test2.zip

[wdoekes]

Minimal test case recv.xml:

<?xml version="1.0" encoding="ISO-8859-1"?>
<scenario>
<recv request="INFO" optional="true"/>
<recvCmd/>
<send>
<![CDATA[
  SIP/2.0 501 Problem
  From: <sip:[service]@127.0.0.1>;tag=[call_number]
  To: <sip:[service]@127.0.0.1>
  Call-ID: [call_id]
  CSeq: [cseq] INFO 
  Content-Length: 0
]]>
</send>
</scenario>

send.xml:

<?xml version="1.0" encoding="ISO-8859-1"?>
<scenario>
<send>
<![CDATA[
  INFO sip:whatever SIP/2.0
  From: <sip:[service]@127.0.0.1>;tag=[call_number]
  To: <sip:[service]@127.0.0.1>
  Call-ID: [call_id]
  CSeq: [cseq] INFO 
  Content-Length: 0
]]>
</send>
<sendCmd>
<![CDATA[
  Call-ID: [call_id]
]]>
</sendCmd>
</scenario>

Exec:

./sipp -m 1 -sf recv.xml -3pcc 127.0.0.1:9001 -t t1
./sipp -m 1 -sf send.xml -3pcc 127.0.0.1:9001 -t t1 google.com:80

GDB:

(gdb) bt
#0  0x000055555563959d in process_message (socket=0x55555599b8c0, msg=0x7ffffffed650 "call-id: [email protected]\r\ninternal-cmd: abort_call\r\n\r\n", msg_size=58, src=0x7ffffffed5d0)
    at /home/walter/src/sipp/src/socket.cpp:1170
#1  0x000055555563ed13 in SIPpSocket::pollset_process (wait=1) at /home/walter/src/sipp/src/socket.cpp:2995
#2  0x00005555556561ca in traffic_thread (rtp_errors=@0x7fffffffd7f8: 0, echo_errors=@0x7fffffffd7fc: 0) at /home/walter/src/sipp/src/sipp.cpp:601
#3  0x000055555565abdb in main (argc=9, argv=0x7fffffffdcd8) at /home/walter/src/sipp/src/sipp.cpp:2161
(gdb) list
1165	                        break;
1166	                    case T_TCP:
1167	                    case T_SCTP:
1168	                    case T_TLS:
1169	                        new_ptr->associate_socket(tcp_multiplex);
1170	                        tcp_multiplex->ss_count++;
1171	                        break;
1172	                    }
1173	                }
1174	            }

(gdb) print tcp_multiplex
$1 = (SIPpSocket *) 0x0

Looks like tcp_multiplex hasn't been initialized. I assume the problem goes away if you use -t tn instead of -t t1 (or use udp mode).

Bug appears to be in:

• open_connections() - only creates the tcp_multiplex for MODE_CLIENT (non-MODE_SERVER)
• if you remove the recvCmd, then you get
  <recv> before <send> sequence without a mandatory message. Please remove one 'optional=true' (element 2)
• but with 3pcc recvCmd you bypass this check and can turn it from a MODE_SERVER into a MODE_CLIENT
• and now certain assumptions (like an existing tcp_multiplex socket) don't hold true

[wdoekes]

Ok, for -t tn you're in trouble elsehwere:

(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff73c4859 in __GI_abort () at abort.c:79
#2  0x00007ffff73c4729 in __assert_fail_base (fmt=0x7ffff755a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55555567a219 "false", 
    file=0x55555567a1f0 "/home/walter/src/sipp/include/socket.hpp", line=48, function=<optimized out>) at assert.c:92
#3  0x00007ffff73d5f36 in __GI___assert_fail (assertion=0x55555567a219 "false", file=0x55555567a1f0 "/home/walter/src/sipp/include/socket.hpp", line=48, 
    function=0x55555567a1b8 "socklen_t socklen_from_addr(const sockaddr_storage*)") at assert.c:101
#4  0x000055555563f024 in socklen_from_addr (ss=0x55555599f7a0) at /home/walter/src/sipp/include/socket.hpp:48
#5  0x000055555563a7c8 in SIPpSocket::connect (this=0x55555599f770, dest=0x555555883020 <remote_sockaddr>) at /home/walter/src/sipp/src/socket.cpp:1559
#6  0x00005555555d2cc5 in call::connect_socket_if_needed (this=0x55555599b9c0) at /home/walter/src/sipp/src/call.cpp:1387
#7  0x00005555555d387f in call::send_scene (this=0x55555599b9c0, index=2, send_status=0x7fffffffd5b8, len=0x7fffffffd5b4) at /home/walter/src/sipp/src/call.cpp:1634
#8  0x00005555555d4b98 in call::executeMessage (this=0x55555599b9c0, curmsg=0x5555558a2150) at /home/walter/src/sipp/src/call.cpp:1950
#9  0x00005555555d5cd1 in call::run (this=0x55555599b9c0) at /home/walter/src/sipp/src/call.cpp:2221
#10 0x000055555565611c in traffic_thread (rtp_errors=@0x7fffffffd7d8: 0, echo_errors=@0x7fffffffd7dc: 0) at /home/walter/src/sipp/src/sipp.cpp:591
#11 0x000055555565abdb in main (argc=11, argv=0x7fffffffdcb8) at /home/walter/src/sipp/src/sipp.cpp:2161
(gdb) up 4
#4  0x000055555563f024 in socklen_from_addr (ss=0x55555599f7a0) at /home/walter/src/sipp/include/socket.hpp:48
48	        assert(false);
(gdb) list
43	    if (ss->ss_family == AF_INET) {
44	        return sizeof(struct sockaddr_in);
45	    } else if (ss->ss_family == AF_INET6) {
46	        return sizeof(struct sockaddr_in6);
47	    } else {
48	        assert(false);
49	        return 0;
50	    }
51	}
52	
(gdb) print ss
$1 = (const sockaddr_storage *) 0x55555599f7a0
(gdb) print ss->ss_family
$2 = 0
(gdb) print *ss
$3 = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}

[wdoekes]

I can't tell what scenario you're trying to achieve. But for now, that combination of optional-recv and recvCmd will not work.

The receivereg.xml scenario you have should either be a client-scenario (start with a send) or a server-scenario (start with a recv). If you have both, like you do know, things will go wrong -- as you have noticed.

[sharkwsk]

Ok, I modified the receivereg.xml to start like this. Same crash occurs

<scenario name="UAS receiver">

  <!-- Receive the invite message -->
  <!-- ================================================================== -->

<recvCmd next="sendregister">
</recvCmd>

<recv request="INVITE" next="registrationsuccessful">
    <action>
      <!-- Analyse the message -->
      <!-- =================== -->
        <ereg regexp=".*" search_in="hdr" header="Via:" check_it="true" assign_to="2" occurrence="1"/>
        <ereg regexp=".*" search_in="hdr" header="Record-Route:" check_it="true" assign_to="4" occurrence="1"/>
    </action>
</recv>

<label id="sendregister"/>
..
..

What I would like to achieve is fairly simple use case

• Set of users (called users) registers and waits for calls to arrive
• Set of Users (calling users) registers and makes call to called users (B)
• Keep terminate the call
• Unregister users
• Continue the cycle with some level of overlap (e.g. at a time 2 calls active)

Initially, I was referring to below post and preparing for the scenario described there - 3PCC scenario with trigger messages to have some level of synchronization between A & B parties
https://sourceforge.net/p/sipp/mailman/message/34707334/

[wdoekes]

Ok, I modified the receivereg.xml to start like this. Same crash occurs

Ok. You have managed to create another way to make the sendMode ambiguous. You didn't fix the underlying problem that SIPp starts in UAS mode and then you ask it to play UAC.

The sendMode is determined by the first <recv>/<send> that's encountered in the scenario: <recv> for UAS in your case. But you have found the <recvCmd/> loophole to make it skip that statement, and start with a <send> instead of a <recv>: while SIPp does not know where to send anything at that point, the <send>-code assumes it's already connected. The result is the segfaults you see.

If you intend on skipping the <recv>: remove that statement, and observe how SIPp will complain that you didn't specify any target to send to.

Missing remote host parameter. This scenario requires it

[sharkwsk]

Ok. I guess I am too obsessed to simulate the scenario that is described in that forum :)
I will have to abandon that and see alternative ways to achieve my use case.

I know its not related to this issue, Is there any possibility to achieve below mentioned use case..

• Set of users (called users - B) registers and waits for calls to arrive, periodically keeps registrations updated (e.g. 60mins)
• Set of Users (calling users - A) registers and makes call to called users (B)
• Keep the call up for sometime (5,10s) and terminate the call
• Unregister user A
• Continue the cycle with some level of overlap (e.g. at a time 2 calls active)

[wdoekes]

I know its not related to this issue, Is there any possibility to achieve below mentioned use case..

This is not the right place for those questions.

[sharkwsk]

Is there any forum for SIPp apart from SourceForge ?
You may close this ticket