[Home]

Summary:ASTERISK-17872: Asterisk 1.6.2.17.2 randomly chrashes after 1 to 3 days of normal operation
Reporter:Pedro Guillem (pguillem)Labels:
Date Opened:2011-05-17 13:06:03Date Closed:2011-07-26 14:03:04
Priority:CriticalRegression?Yes
Status:Closed/CompleteComponents:General
Versions:1.6.2.17 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) core_dumt_bt_btfull.txt
Description:I did not find an attachment oprion.. so i pasted the backtrace after BT and BT full


BT

#0  0x00007f46780004d8 in ?? ()
#1  0x000000000045b29d in ast_hangup (chan=0x7f4678237ef0) at channel.c:1857
#2  0x00007f469869bde1 in dial_exec_full (chan=0x7f4684684f50, data=0x7f468daa96a0, peerflags=0x7f468daa74c0, continue_exec=0x0) at app_dial.c:2310
#3  0x00007f469869c181 in dial_exec (chan=0x7f4684684f50, data=0x7f468daa96a0) at app_dial.c:2362
#4  0x00000000004c8c3b in pbx_exec (c=0x7f4684684f50, app=0x7f4688006990, data=0x7f468daa96a0) at pbx.c:1360
ASTERISK-1  0x00000000004d06f8 in pbx_extension_helper (c=0x7f4684684f50, con=0x0, context=0x7f4684685310 "default", exten=0x7f4684685360 "573185584138",
   priority=17, label=0x0, callerid=0x7f4678013500 "900915", action=E_SPAWN, found=0x7f468daabd94, combined_find_spawn=1) at pbx.c:3727
ASTERISK-2  0x00000000004d1e4b in ast_spawn_extension (c=0x7f4684684f50, context=0x7f4684685310 "default", exten=0x7f4684685360 "573185584138", priority=17,
   callerid=0x7f4678013500 "900915", found=0x7f468daabd94, combined_find_spawn=1) at pbx.c:4225
ASTERISK-3  0x00000000004d263d in __ast_pbx_run (c=0x7f4684684f50, args=0x0) at pbx.c:4319
ASTERISK-4  0x00000000004d3c68 in pbx_thread (data=0x7f4684684f50) at pbx.c:4606
ASTERISK-5  0x000000000052b378 in dummy_start (data=0x7f46845503e0) at utils.c:968
ASTERISK-6 0x00007f46a250d8ba in start_thread () from /lib/libpthread.so.0
ASTERISK-7 0x00007f46a2bfa02d in clone () from /lib/libc.so.6
ASTERISK-8 0x0000000000000000 in ?? ()






THREAD APPLY BT


#1  0x000000000045b29d in ast_hangup (chan=0x7f4678237ef0) at channel.c:1857
       res = 0
       __PRETTY_FUNCTION__ = "ast_hangup"
#2  0x00007f469869bde1 in dial_exec_full (chan=0x7f4684684f50, data=0x7f468daa96a0, peerflags=0x7f468daa74c0, continue_exec=0x0) at app_dial.c:2310
       number = 0x7f46782360d1 "573185584138@250.20.55.1"
       res = -1
       rest = 0x0
       cur = 0x0
       outgoing = 0x0
       peer = 0x7f4678237ef0
       to = 50126
       num = {chan = 0x7f4684684f50, busy = 0, congestion = 0, nochan = 0}
       cause = 0
       numsubst = "573185584138@250.20.55.1\00\00\00\00`C\000xF\177\000\000\034\000\000\000\065\000\000\000`f\bxF\177\000\000@oª\215F\177\000\000\00$ # Line purposely modified for confidentiality
       cidname = '\000' <repeats 79 times>
       config = {features_caller = {flags = 128}, features_callee = {flags = 0}, start_time = {tv_sec = 1305641566, tv_usec = 838364}, nexteventts = {
           tv_sec = 0, tv_usec = 0}, partialfeature_timer = {tv_sec = 0, tv_usec = 0}, feature_timer = 0, timelimit = 0, play_warning = 0,
         warning_freq = 0, warning_sound = 0x0, end_sound = 0x0, start_sound = 0x0, firstpass = 1, flags = 0,
         end_bridge_callback = 0x7f4698697327 <end_bridge_callback>, end_bridge_callback_data = 0x7f4684684f50,
         end_bridge_callback_data_fixup = 0x7f4698697452 <end_bridge_callback_data_fixup>}
       calldurationlimit = {tv_sec = 0, tv_usec = 0}
       dtmfcalled = 0x0
       dtmfcalling = 0x0
       pa = {sentringing = 1, privdb_val = 0, privcid = '\000' <repeats 255 times>, privintro = '\000' <repeats 1023 times>,
         status = "ANSWER\000R\000GS", '\000' <repeats 244 times>}
       sentringing = 0
       moh = 0
       outbound_group = 0x0
       result = 0
       parse = 0x7f468daa6380 "SIP"
       opermode = 0
       delprivintro = 0
       args = {argc = 3, argv = 0x7f468daa68f8, peers = 0x7f468daa6380 "SIP", timeout = 0x7f468daa63a1 "60", options = 0x7f468daa63a4 "g", url = 0x0}
       opts = {flags = 32}
       opt_args = {0x5847db "", 0x7f468489c888 "", 0x0, 0x0, 0x7f468daa6df0 "", 0x66018c0180 <Address 0x66018c0180 out of bounds>, 0x7f468daa6e98 "",
         0x7f468daa6e78 "", 0x5847d6 "%0*ld", 0x7f468daa6e5c "", 0x0, 0x0}
       datastore = 0x7f4678004890
       fulldial = 0
       num_dialed = 1
       __PRETTY_FUNCTION__ = "dial_exec_full"
#3  0x00007f469869c181 in dial_exec (chan=0x7f4684684f50, data=0x7f468daa96a0) at app_dial.c:2362
       peerflags = {flags = 4294967328}
#4  0x00000000004c8c3b in pbx_exec (c=0x7f4684684f50, app=0x7f4688006990, data=0x7f468daa96a0) at pbx.c:1360
       res = 32582
       u = 0x7f4678087b70
       saved_c_appl = 0x0
       saved_c_data = 0x0
       __PRETTY_FUNCTION__ = "pbx_exec"
ASTERISK-1  0x00000000004d06f8 in pbx_extension_helper (c=0x7f4684684f50, con=0x0, context=0x7f4684685310 "default", exten=0x7f4684685360 "573185584138",
   priority=17, label=0x0, callerid=0x7f4678013500 "900915", action=E_SPAWN, found=0x7f468daabd94, combined_find_spawn=1) at pbx.c:3727
       e = 0x7f46880481a0
       app = 0x7f4688006990
       res = -1918190800
       q = {incstack = {0x7f4688045f60 "default", 0x0 <repeats 127 times>}, stacklen = 1, status = 5, swo = 0x0, data = 0x0,
         foundcontext = 0x7f4688046b93 "processcall_normal"}
       passdata = "SIP/573185584138@250.20.55.1,60,g\000CR|41|500543|NORMAL\00\00\00\00\000\000\000È\234ª\215F\177\000\000¨\234ª\215F\177\000\000\20$ #Line purposely Modified for confidentiality
       matching_action = 0
       __PRETTY_FUNCTION__ = "pbx_extension_helper"
ASTERISK-2  0x00000000004d1e4b in ast_spawn_extension (c=0x7f4684684f50, context=0x7f4684685310 "default", exten=0x7f4684685360 "573185584138", priority=17,
   callerid=0x7f4678013500 "900915", found=0x7f468daabd94, combined_find_spawn=1) at pbx.c:4225
No locals.
ASTERISK-3  0x00000000004d263d in __ast_pbx_run (c=0x7f4684684f50, args=0x0) at pbx.c:4319
       digit = 0
       invalid = 0
       timeout = 0
       dst_exten = "\00\00\00\00\00\00\0\000\215F\177", '\000' <repeats 18 times>, "ྪ\215F\177", '\000' <repeats 42 times>, "нª\215F\177\000\0$
       pos = 0
       found = 1
       res = 0
       autoloopflag = 0
       error = 0
       __PRETTY_FUNCTION__ = "__ast_pbx_run"
ASTERISK-4  0x00000000004d3c68 in pbx_thread (data=0x7f4684684f50) at pbx.c:4606
       c = 0x7f4684684f50
ASTERISK-5  0x000000000052b378 in dummy_start (data=0x7f46845503e0) at utils.c:968
       __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {0, 319432785810653480, 139941005441728, 139941001217792, 139941366071360, 7,
               319432785785487656, -368237864384888536}, __mask_was_saved = 0}}, __pad = {0x7f468daabf80, 0x0, 0x7f46a271e280, 0x0}}
       __cancel_routine = 0x4371e4 <ast_unregister_thread>
       __cancel_arg = 0x7f468daac700
       not_first_call = 0
       ret = 0x7f46a2e82870
       a = {start_routine = 0x4d3c43 <pbx_thread>, data = 0x7f4684684f50,
         name = 0x7f46840098c0 "pbx_thread", ' ' <repeats 11 times>, "started at [ 4627] pbx.c ast_pbx_start()"}
ASTERISK-6 0x00007f46a250d8ba in start_thread () from /lib/libpthread.so.0
No symbol table info available.
ASTERISK-7 0x00007f46a2bfa02d in clone () from /lib/libc.so.6
No symbol table info available.
ASTERISK-8 0x0000000000000000 in ?? ()
No symbol table info available.


****** STEPS TO REPRODUCE ******

No specific steps to reproduce. The service simply crashes occasionally.


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

Intel(R) Core(TM)2 Duo CPU     E7500  @ 2.93GHz
Kernel 2.6.32-5-amd64 #1 SMP x86_64
Debian 6 Squeeze
1 GB RAM

This also happens occacionally on the same setup with an Corei7

Intel(R) Core(TM) i7 CPU         860  @ 2.80GHz
Kernel 2.6.32-5-amd64 #1 SMP x86_64
8 GB RAM
Comments:By: Pedro Guillem (pguillem) 2011-05-17 13:09:06

Sorry guys. I found the upload option later and uploaded the file in a .txt.
By: Pedro Guillem (pguillem) 2011-05-17 13:12:57

Let me know if you need any further information about my machine. or anything i can provide to do a full investigation. I think this might be related to libc.so.6

Maybe they changed something relevant in the Squeeze version?
By: Pedro Guillem (pguillem) 2011-05-17 13:18:39

DMESG

[2813768.334206] asterisk[20816]: segfault at 7f46780004d8 ip 00007f46780004d8 sp 00007f468daa6238 error 15
By: Pedro Guillem (pguillem) 2011-05-17 13:50:52

I have narrowed the issue to the line 1857 of channel.c

chan->tech->hangup(chan);

I was reading a similar BUG 6 years ago, at ticket https://issues.asterisk.org/view.php?id=5051

I have no idea what might be producing this, since i'm not an expert in this particular file's behaviour.

The server only performs SIP to SIP calls, IAX2 to SIP calls and IAX to IAX calls.
By: Pedro Guillem (pguillem) 2011-05-17 13:56:03

I have also found this 2 lines in my /var/log/asterisk/messages



[May 17 09:12:46] WARNING[20819] pbx.c: Channel 'SIP/216.XX.XX.XX-00003722' sent into invalid extension 's' in context 'default', but no invalid handler

[May 17 09:12:48] ERROR[20816] channel.c: Unable to find channel in list to free. Assuming it has already been done.

This happened exactly before the crash.
Perhaps asterisk is trying to hang up an inexistent channel?.

Wouldn't it be good to check if the channel pointer is valid before hanging up a zombie?


By: Pedro Guillem (pguillem) 2011-05-17 15:34:49

Guys, my other server just crashed and THREAD 1 points exactely to the same line...


Thread 1 (Thread 10989):
#0  0x00007fd416fe22f8 in ?? () from /lib/libc.so.6
#1  0x000000000045b8cd in ast_hangup (chan=0x1ba4ce0) at channel.c:1857
#2  0x00007fd400e4bde1 in dial_exec_full (chan=0x7fd3f455e950, data=0x7fd3fb4986a0, peerflags=0x7fd3fb4964c0, continue_exec=0x0) at app_dial.c:2310
#3  0x00007fd400e4c181 in dial_exec (chan=0x7fd3f455e950, data=0x7fd3fb4986a0) at app_dial.c:2362
#4  0x00000000004c926b in pbx_exec (c=0x7fd3f455e950, app=0x7fd4104b00e0, data=0x7fd3fb4986a0) at pbx.c:1360
ASTERISK-1  0x00000000004d1604 in pbx_extension_helper (c=0x7fd3f455e950, con=0x0, context=0x7fd3f455ed10 "default", exten=0x7fd3f455ed60 "573167968116",
   priority=17, label=0x0, callerid=0x19c83e0 "900948", action=E_SPAWN, found=0x7fd3fb49ad94, combined_find_spawn=1) at pbx.c:3727
ASTERISK-2  0x00000000004d2d57 in ast_spawn_extension (c=0x7fd3f455e950, context=0x7fd3f455ed10 "default", exten=0x7fd3f455ed60 "573167968116", priority=17,
   callerid=0x19c83e0 "900948", found=0x7fd3fb49ad94, combined_find_spawn=1) at pbx.c:4225
ASTERISK-3  0x00000000004d3549 in __ast_pbx_run (c=0x7fd3f455e950, args=0x0) at pbx.c:4319
ASTERISK-4  0x00000000004d4b74 in pbx_thread (data=0x7fd3f455e950) at pbx.c:4606
ASTERISK-5  0x000000000052cc1c in dummy_start (data=0x7fd3f4067670) at utils.c:968
ASTERISK-6 0x00007fd41651b8ba in start_thread () from /lib/libpthread.so.0
ASTERISK-7 0x00007fd416d5402d in clone () from /lib/libc.so.6
ASTERISK-8 0x0000000000000000 in ?? ()


anyone?
By: Leif Madsen (lmadsen) 2011-05-17 17:12:01

Thanks for filing the issue. Have you tried using the latest 1.6.2 branch to verify the issue hasn't already been resolved?

Additionally, Asterisk 1.6.2 is now in security only maintenance mode, so you may wish to determine if the issue also exists in 1.8 as the 1.6.2 branch will not be receiving bug fixes any longer.

~~~~~

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch.

For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions
By: Pedro Guillem (pguillem) 2011-05-17 19:19:42

I'll go ahead and check that