[Home]

Summary:ASTERISK-13841: Asterisk crashes randomly, with Exchange 2007
Reporter:Kyle Haefner (khaefner)Labels:
Date Opened:2009-03-26 12:15:47Date Closed:2011-06-07 14:01:06
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/TCP-TLS
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:From looking at the core, this may be related to the options message exchange sends periodically to check if a gateway is up.  

here is gdb bt output:
Core was generated by `/usr/sbin/asterisk -f -U asterisk -G asterisk -vvvg -c'.
Program terminated with signal 11, Segmentation fault.
#0  0x02ea0710 in find_call (req=0x1eb9f40, sin=0x9c802c0, intended_method=3) at chan_sip.c:6091
6091                    if (ast_strlen_zero(p->callid))
(gdb) bt
#0  0x02ea0710 in find_call (req=0x1eb9f40, sin=0x9c802c0, intended_method=3) at chan_sip.c:6091
#1  0x02ee08a5 in handle_request_do (req=0x1eb9f40, sin=0x9c802c0) at chan_sip.c:18920
#2  0x02e8dbb8 in _sip_tcp_helper_thread (pvt=0x0, tcptls_session=0x9c802b0) at chan_sip.c:2286
#3  0x02e8d477 in sip_tcp_worker_fn (data=0x9c802b0) at chan_sip.c:2206
#4  0x08143b43 in ast_make_file_from_fd (data=0x9c802b0) at tcptls.c:471
ASTERISK-1  0x0814fe84 in dummy_start (data=0x9c7a5e0) at utils.c:861
ASTERISK-2  0x0046a45b in start_thread () from /lib/libpthread.so.0
ASTERISK-3  0x003c224e in clone () from /lib/libc.so.6


****** ADDITIONAL INFORMATION ******

Here is the bt full:
#0  0x02ea0710 in find_call (req=0x1eb9f40, sin=0x9c802c0, intended_method=3) at chan_sip.c:6091
       found = 0
       p = (struct sip_pvt *) 0x3c
       tag = 0x2ef5dd8 ""
       totag = "\221?F\000\210\207?\001E?F\000\214?F\000\000\000\000\000\230\207?\001\001\000\000\000\000\000\000\000??B\000\000\000\000\000QU?\002\210\207?\001\200?F\000\230\207?\001\226?<\000|??\tx\205?\002?\207?\001@?\024\b|??\t(\b\000\000?\207?\001R??\002?\213?\002p??\t\030\210?\001A??\002 \213?\002\224R?\002?I\000\000/K?\002?K?\002"
       fromtag = "???\001\000\000\000\000p\201?\001\v\000\000\000\003", '\0' <repeats 15 times>, "\001\000\000\000\000\000\000\00071aa7c218e", '\0' <repeats 26 times>, "l??\000\000\000\000\000\213??\001x\205?\002???\001?W?\002\210\207?\001\030??\002\204??\001\221?F\000\000\000\000\000E?F\000\214?F"
       callid = 0x1eba23a "dd57dc1714c348d3b9e3968977e89e84"
       from = 0x1eba193 "<sip:TFEXUM1.csutest.local:5060;transport=Tcp;ms-opaque=4dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9"
       to = 0x1eba201 "<sip:129.82.174.135:5060>"
       cseq = 0x1eba222 "41027 OPTIONS"
       __PRETTY_FUNCTION__ = "find_call"
#1  0x02ee08a5 in handle_request_do (req=0x1eb9f40, sin=0x9c802c0) at chan_sip.c:18920
       p = (struct sip_pvt *) 0x1eb8898
       recount = 0
       nounlock = 0
       lockretry = 10
       __PRETTY_FUNCTION__ = "handle_request_do"
#2  0x02e8dbb8 in _sip_tcp_helper_thread (pvt=0x0, tcptls_session=0x9c802b0) at chan_sip.c:2286
       res = 1
       cl = 0
       req = {rlPart1 = 0x1eba164 "OPTIONS", rlPart2 = 0x1eba16c "sip:129.82.174.135:5060", len = 399, headers = 10, method = 3, lines = 0, sdp_start = 0, sdp_end = 0,
 debug = 0 '\0', has_to_tag = 0 '\0', ignore = 0 '\0', header = {0x1eba164 "OPTIONS",
   0x1eba18d "FROM: <sip:TFEXUM1.csutest.local:5060;transport=Tcp;ms-opaque=4dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9", 0x1eba1fd "TO: <sip:129.82.174.135:5060>",
   0x1eba21c "CSEQ: 41027 OPTIONS", 0x1eba231 "CALL-ID: dd57dc1714c348d3b9e3968977e89e84", 0x1eba25c "MAX-FORWARDS: 70",
   0x1eba26e "VIA: SIP/2.0/TCP 129.82.201.76:15793;branch=z9hG4bKb16847a0", 0x1eba2ab "ACCEPT: application/sdp", 0x1eba2c4 "CONTENT-LENGTH: 0",
   0x1eba2d7 "USER-AGENT: RTCC/3.0.0.0", 0x1eba2f1 "", 0x0 <repeats 53 times>}, line = {0x1eba2f3 "", 0x0 <repeats 63 times>},
 data = "OPTIONS\000sip:129.82.174.135:5060\000SIP/2.0\000\000FROM: <sip:TFEXUM1.csutest.local:5060;transport=Tcp;ms-opaque=4dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9\000\000TO: <sip:129.82.174.135:5060>\000\000CSEQ: 41027 OPTI"..., socket = {type = SIP_TRANSPORT_TCP, fd = 34, port = 50195, tcptls_session = 0x9c802b0}, next = {next = 0x0}}
       reqcpy = {rlPart1 = 0x1eb8f2c "OPTIONS", rlPart2 = 0x1eb8f34 "sip:129.82.174.135:5060", len = 399, headers = 10, method = 0, lines = 0, sdp_start = 0, sdp_end = 0,
 debug = 0 '\0', has_to_tag = 0 '\0', ignore = 0 '\0', header = {0x1eb8f2c "OPTIONS",
   0x1eb8f55 "FROM: <sip:TFEXUM1.csutest.local:5060;transport=Tcp;ms-opaque=4dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9", 0x1eb8fc5 "TO: <sip:129.82.174.135:5060>",
   0x1eb8fe4 "CSEQ: 41027 OPTIONS", 0x1eb8ff9 "CALL-ID: dd57dc1714c348d3b9e3968977e89e84", 0x1eb9024 "MAX-FORWARDS: 70",
   0x1eb9036 "VIA: SIP/2.0/TCP 129.82.201.76:15793;branch=z9hG4bKb16847a0", 0x1eb9073 "ACCEPT: application/sdp", 0x1eb908c "CONTENT-LENGTH: 0",
   0x1eb909f "USER-AGENT: RTCC/3.0.0.0", 0x1eb90b9 "", 0x0 <repeats 53 times>}, line = {0x1eb90bb "", 0x0 <repeats 63 times>},
 data = "OPTIONS\000sip:129.82.174.135:5060\000SIP/2.0\000\000FROM: <sip:TFEXUM1.csutest.local:5060;transport=Tcp;ms-opaque=4dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9\000\000TO: <sip:129.82.174.135:5060>\000\000CSEQ: 41027 OPTI"..., socket = {type = 0, fd = 0, port = 0, tcptls_session = 0x0}, next = {next = 0x0}}
       me = (struct sip_threadinfo *) 0x9dae1b0
       buf = "\r\n\000R-AGENT: RTCC/3.0.0.0\r\n\000.76:15793;branch=z9hG4bKb16847a0\r\n\0004dd13ba26d4d3474>;epid=5E34189619;tag=7a705ce2d9\r\n", '\0' <repeats 911 times>
       __PRETTY_FUNCTION__ = "_sip_tcp_helper_thread"
#3  0x02e8d477 in sip_tcp_worker_fn (data=0x9c802b0) at chan_sip.c:2206
       tcptls_session = (struct ast_tcptls_session_instance *) 0x9c802b0
#4  0x08143b43 in ast_make_file_from_fd (data=0x9c802b0) at tcptls.c:471
       tcptls_session = (struct ast_tcptls_session_instance *) 0x9c802b0
       ssl_setup = (int (*)(SSL *)) 0x805ae20 <SSL_accept@plt>
       ret = 32226192
       err = "p??\t\000\000\000\000,\b\000\000AG\000\000???\t(\b\000\000?\217G\000\000\000\000\000\220??\001x??\001_?\024\b\001\000\000\000(\b\000\000\000\000\000\000??5", '\0' <repeats 13 times>, "??F\000\000\000\000\000\221?F\000\000\000\000\000?\217G\000\030\025C\000???\001P\021C\000P\021C\000\214?F\000\000\000\000\000???\001Q\000\000\000\000\000\000\000P\021C\000\000\000\000\000\001\000\000\000???\001\200?F\000???\001\226?<\000|??\t?\217G\000???\001\220?\024\b|??\t(\b\000\000P?\001\000p??\t???\t\n\000\000\000\b??\001p??"...
       __PRETTY_FUNCTION__ = "ast_make_file_from_fd"
       cookie_funcs = {read = 0x8142036 <ssl_read>, write = 0x8142060 <ssl_write>, seek = 0, close = 0x8142081 <ssl_close>}
ASTERISK-1  0x0814fe84 in dummy_start (data=0x9c7a5e0) at utils.c:861
       __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {4689908, 0, 32226192, 32224184, -932919254, -1046771992}, __mask_was_saved = 0}}, __pad = {0x1ebb470, 0x0, 0x0,
   0x0}}
       __cancel_routine = (void (*)(void *)) 0x8071a81 <ast_unregister_thread>
       __cancel_arg = (void *) 0x1ebbb90
       not_first_call = 0
---Type <return> to continue, or q <return> to quit---
       ret = (void *) 0x0
       a = {start_routine = 0x814360a <ast_make_file_from_fd>, data = 0x9c802b0, name = 0x9c803b0 "ast_make_file_from_fd started at [  161] tcptls.c ast_tcptls_server_root()"}
       lock_info = (struct thr_lock_info *) 0x9dae270
       mutex_attr = {__size = "\001\000\000", __align = 1}
ASTERISK-2  0x0046a45b in start_thread () from /lib/libpthread.so.0
No symbol table info available.
ASTERISK-3  0x003c224e in clone () from /lib/libc.so.6

Comments:By: Leif Madsen (lmadsen) 2009-04-16 08:28:24

Are you using TCP/TLS here?
By: Kyle Haefner (khaefner) 2009-04-16 09:16:24

Yes TCP.  Exchange 2007 only connects over TCP.
By: Russell Bryant (russell) 2009-05-29 22:25:43

Will you try Asterisk 1.6.1?

I'm afraid that the changes necessary to address this crash are extremely invasive, and may be too much to do in 1.6.0.  Specifically, I am talking about the reference counted object handling of the sip_pvt data structure.

However, 1.6.1 has these improvements.  So, if you use 1.6.1, they should go away.

If you get a chance to try 1.6.1, please report back.

Thanks.
By: Kyle Haefner (khaefner) 2009-05-31 10:15:42

Actually, yes 1.6.1 seems to have fixed this and asterisk has remained up for a few weeks now (it was crashing several times a day).  You can probably close this.

Kyle
By: Joshua C. Colp (jcolp) 2009-06-01 08:38:01

Closed per reporter.