Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Saúl Ibarra Corretgé]

Thanks Razvan!

On Fri, Mar 4, 2016 at 3:43 PM, Răzvan Crainea 
wrote:

> Closed #813 .
>
> —
> Reply to this email directly or view it on GitHub
> .
>
> ___
> Devel mailing list
> Devel@lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
>
>


-- 
/Saúl
bettercallsaghul.com
___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Răzvan Crainea]

Closed #813.

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#event-577857822___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Saúl Ibarra Corretgé]

Yep, good old `malloc` :-)

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#issuecomment-192299774___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Răzvan Crainea]

So you're using `malloc`? If so, you might indeed run into the first issue you 
pointed out.

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#issuecomment-192297263___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Saúl Ibarra Corretgé]

There you go:


(gdb) bt
#0  tcp_read_req (con=con@entry=0xa773e948,
bytes_read=bytes_read@entry=0xbfb3b8cc)
at tcp_read.c:711
#1  0x080e08a2 in handle_io (fm=0x99015c8, idx=idx@entry=-1,
event_type=event_type@entry=1) at tcp_read.c:1036
#2  0x080e271c in io_wait_loop_epoll (repeat=, h=, t=) at io_wait.h:867
#3  tcp_receive_loop (unix_sock=72) at tcp_read.c:1144
#4  0x080dc690 in tcp_init_children (chd_rank=chd_rank@entry=0x81e362c,
startup_done=startup_done@entry=0x0) at tcp_main.c:2378
#5  0x0805db02 in main_loop () at main.c:1011
#6  main (argc=11, argv=0xbfb3bbf4) at main.c:1612
(gdb) print req
$1 = (struct tcp_req *) 0x995eaf8
(gdb) print cur
cur_lock curr_dir current_dlg_pointer  current_req
(gdb) print current_req
$2 = {next = 0x0,
  buf = "\r\n\r\n2.0 200 OK\r\nVia: SIP/2.0/TLS
81.23.228.129:443;received=81.23.228.129;branch=z9hG4bK5a46.32065967.0\r\nVia:
SIP/2.0/UDP 81.23.228.150:5060;branch=z9hG4bK5a46.b782e725.0\r\nRecord-Route:

wrote:

> What allocator are you using? Could you print the req variable in gdb and
> paste the output here?
>
> —
> Reply to this email directly or view it on GitHub
> .
>
> ___
> Devel mailing list
> Devel@lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
>
>


-- 
/Saúl
bettercallsaghul.com
___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Răzvan Crainea]

What allocator are you using? Could you print the `req` variable in gdb and 
paste the output here?

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#issuecomment-192293339___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Saúl Ibarra Corretgé]

@razvancrainea it crashed here: 
https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L711 My guess is that 
it accesses freed memory, hence the crash. It might work sometimes, but if a 
hardened system memory allocator is used it will.

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#issuecomment-192265551___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

Re: [OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Răzvan Crainea]

Hi, Saul!

The first issue you pointed out, might indeed cause an "invalid" use of 
unallocated memory. However, since that's only pkg memory, nobody can come and 
use that buffer, so that can't cause any crash. Nevertheless, thanks for 
pointing it out, I will shortly fix that.

Regarding the `release_tcpconn` issue, I couldn't find any possible path where 
the function would get called twice. Even though `tcp_read_req` explicitly 
releases the connection, it only does it on successful cases.

Thanks for pointing these out, but I don't see a bug in the code. Perhaps the 
core dump might give us more information. Can you point out the line that 
crashed?

Thanks,
Răzvan


---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813#issuecomment-192260018___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel

[OpenSIPS-Devel] [opensips] [1.11] Crash on TCP read (#813)

[Saúl Ibarra Corretgé]

I found a crashed OpenSIPS process with the following backtrace:


(gdb) bt
#0  tcp_read_req (con=con@entry=0xa773e948, 
bytes_read=bytes_read@entry=0xbfb3b8cc) at tcp_read.c:711
#1  0x080e08a2 in handle_io (fm=0x99015c8, idx=idx@entry=-1, 
event_type=event_type@entry=1) at tcp_read.c:1036
#2  0x080e271c in io_wait_loop_epoll (repeat=, h=, t=)
at io_wait.h:867
#3  tcp_receive_loop (unix_sock=72) at tcp_read.c:1144
#4  0x080dc690 in tcp_init_children (chd_rank=chd_rank@entry=0x81e362c, 
startup_done=startup_done@entry=0x0)
at tcp_main.c:2378
#5  0x0805db02 in main_loop () at main.c:1011
#6  main (argc=11, argv=0xbfb3bbf4) at main.c:1612


I inspected the code and found a path which leads to the problem. If the code 
entered [this 
if](https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L704) `req` 
points to freed memory, so 
[this](https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L711) causes 
the crash.

I think we need to jump to `end_req` right after freeing the request, but I'm 
not that familiar with the code to provide a patch.

Something does look a bit strange to me: if `size` was 0 (which is the case), 
then 
[this](https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L678-L695) 
code path was followed, which means `release_tcpconn` was called. But when 
`tcp_read_req` returns (if it does so with an error) [this 
code](https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L1036-L1045) 
will call `release_tcpconn` again.

As a side note, `release_tcpconn` shoudl probably set the `fd` attribute on the 
connection to -1 after closing it 
[here](https://github.com/OpenSIPS/opensips/blob/1.11/tcp_read.c#L451).

Unfortunately I cannot reproduce the issue, it's the first time I've seen it, 
and we've been running 1.11 in production on sip2sip.info for quite a while, 
always with async TCP enabled.

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/813___
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel