[OpenSER-Devel] [ openser-Bugs-1879864 ] openser crash when extra acc params enabled

Fri Mar 7 17:41:42 CET 2008

Bugs item #1879864, was opened at 2008-01-25 19:01
Message generated for change (Comment added) made by bogdan_iancu
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=743020&aid=1879864&group_id=139143

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: ver 1.3.x
Status: Open
Resolution: Fixed
Priority: 7
Private: No
Submitted By: Ovidiu Sas (osas)
Assigned to: Bogdan-Andrei Iancu (bogdan_iancu)
Summary: openser crash when extra acc params enabled

Initial Comment:
If I enable extra acc in openser while doing syslog accounting, openser is crashing while handling 487 message.

The following extra acc params is crashing the server:
modparam("acc", "log_extra", "r_uri=$ru;from=$fn;from_uri=$fu;to=$tn;to_uri=$tu;contact=$ct;ua=$hdr(User-Agent);src_ip=$si;src_port=$sp;rpid=$re ")

Here are the relevant informations:
# openser -V
version: openser 1.3.0-notls (i386/linux)
flags: STATS: Off, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
svnrevision: 2:3580M
@(#) $Id: main.c 3565 2008-01-23 17:17:29Z miconda $
main.c compiled on 23:23:01 Jan 24 2008 with gcc 4.1.2

Core was generated by `/usr/sbin/openser -P /var/run/openser.pid -m 512'.
Program terminated with signal 11, Segmentation fault.
#0  0x080efa69 in free_to ()
(gdb) bt
#0  0x080efa69 in free_to ()
#1  0x080daa30 in clean_hdr_field ()
#2  0x0014fd4a in t_should_relay_response (Trans=0x9b965678, new_code=487, branch=0, should_store=0xbfdb1cf4, should_relay=0xbfdb1cf8, 
    cancel_bitmap=0xbfdb1dd0, reply=0x8195c70) at t_reply.c:545
#3  0x00150a94 in relay_reply (t=0x9b965678, p_msg=0x8195c70, branch=0, msg_status=487, cancel_bitmap=0xbfdb1dd0) at t_reply.c:1051
#4  0x00151fcb in reply_received (p_msg=0x8195c70) at t_reply.c:1403
#5  0x08063c50 in forward_reply ()
#6  0x080940e2 in receive_msg ()
#7  0x080d3c87 in udp_rcv_loop ()
#8  0x0806c396 in main ()

Regards,
Ovidiu Sas

----------------------------------------------------------------------

>Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-03-07 18:41

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Hi Ovidiu,

I did some more fixing related to this bug - could you please re-try?

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-02-25 17:13

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Based on some reports from Ovidiu, it looks like there are some side
effects (crashes) that might be related to this fix....still to investigate

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-02-11 18:25

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Hi Ovidiu,

A fix is available on SVN trunk - please update and test again to see if
the problem was fixed. I need your confirmation before doing a backport to
1.3 and 1.2

Thanks and regards,
Bogdan

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-02-07 13:20

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Hi Ovidiu,

Thanks for the core file - it was really helpful. I spent some time
digging into it and I found the bug.
Shortly, it is the same reported by Will (id #1887999). He reported as mem
leak, but as suspected, it can be also a crash (as in your case).

The problem was the $re from extra_acc - RPID header - this pseudo
variable was triggering the parsing (with parse_to() ) of the RPID header
in TMCB_RESPONSE_OUT handler of acc. The parsed hdr was in the private
memory of a process receiving the first reply that required acc. The parsed
hdr remained attached to the transaction (in shm mem) and the
TMCB_ON_FAILURE tried to free it in a different process. The result is
known :).....

I will prepare asap a fix for this problem.

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-01-29 10:56

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Ovidiu,

could you provide the core file and the binaries? I would like to inspect
a bit the core.

Thanks and regards,
Bogdan

----------------------------------------------------------------------

Comment By: Ovidiu Sas (osas)
Date: 2008-01-28 23:55

Message:
Logged In: YES 
user_id=1395524
Originator: YES

The server seems to be working fine with the following log_extra params:
modparam("acc", "log_extra", "from_uri=$fu;r_uri=$ru ")

I will try tomorrow to play more with "To" and report back.

Henning, in my openser config I'm using only cr_tree_rewrite_uri().

----------------------------------------------------------------------

Comment By: Henning Westerholt (henningw)
Date: 2008-01-28 18:28

Message:
Logged In: YES 
user_id=337916
Originator: NO

Not sure if this is related.. 

Ovidiu, you're seeing this crash with the cr module.. In route_func.c:413
there is a call to parse_headers() to parse the 'TO' header. Perhaps this
is wrong, the parse_to function from the core should be used instead? (This
function is only executed if you choose to balance via 'TO'.)

Cheers,

Henning

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2008-01-28 16:23

Message:
Logged In: YES 
user_id=1275325
Originator: NO

Hi Ovidiu,

Try to remove only the $tn and $tu (each at a time and then both) and see
if openser still crash. The backtrace shows that TM tries to free the TO
header, like it was parsed in this route. But when using TM, the TO header
is parsed from the beginning, when the transaction is
created.....strange...

Have you found a way to reproduce this? or the crash is only occasionally?
because the debug log will be useful.

BTW, does the corefile provides a line for free_to()?? the top 2 frames
are missing source info.

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: Matt Reilly (sipphonematt)
Date: 2008-01-25 23:10

Message:
Logged In: YES 
user_id=1965181
Originator: NO

I had a crash with 1.3.0 which may or may not be related. We have a large
db_extra field for extended acc logging. The crash itself occurred in
get_all_db_ucontacts() (though, I believe it was unrelated to bug
#1873335). After going through the core file, we discovered that
fm_malloc() had returned overlapping memory areas indicating heap
corruption. Perhaps there is some double free in the acc extra accounting?

I still have the core file if desired. 

----------------------------------------------------------------------

Comment By: Ovidiu Sas (osas)
Date: 2008-01-25 19:49

Message:
Logged In: YES 
user_id=1395524
Originator: YES

If i remove all the log_extra, the server seems to be stable ... so after
all, it may be somehow related to acc.

----------------------------------------------------------------------

Comment By: Ovidiu Sas (osas)
Date: 2008-01-25 19:09

Message:
Logged In: YES 
user_id=1395524
Originator: YES

Hmmm ... it doesn't seem to be related to the acc module

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=743020&aid=1879864&group_id=139143