[asterisk-bugs] [Asterisk 0012012]: SIGABORT in ast_channel_trylock in chan_local local_queue_frame when channel disappears underneath the code
Asterisk Bug Tracker
noreply at bugs.digium.com
Tue Jan 19 07:47:43 CST 2010
The following issue has been set as RELATED TO issue 0016639.
======================================================================
https://issues.asterisk.org/view.php?id=12012
======================================================================
Reported By: stevedavies
Assigned To: russell
======================================================================
Project: Asterisk
Issue ID: 12012
Category: Channels/chan_local
Reproducibility: random
Severity: crash
Priority: normal
Status: closed
Asterisk Version: 1.4.18
JIRA:
Regression: No
Reviewboard Link:
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
Resolution: fixed
Fixed in Version:
======================================================================
Date Submitted: 2008-02-17 09:27 CST
Last Modified: 2010-01-19 07:47 CST
======================================================================
Summary: SIGABORT in ast_channel_trylock in chan_local
local_queue_frame when channel disappears underneath the code
Description:
Asterisk SIGABORTS - a "stale" channel pointer is passed to
ast_channel_trylock.
Program terminated with signal 6, Aborted.
https://issues.asterisk.org/view.php?id=0 0x00002ab5aaf45b95 in raise () from
/lib64/libc.so.6
No symbol table info available.
https://issues.asterisk.org/view.php?id=1 0x00002ab5aaf46f90 in abort () from
/lib64/libc.so.6
No symbol table info available.
https://issues.asterisk.org/view.php?id=2 0x00002ab5aaf3f256 in __assert_fail
() from /lib64/libc.so.6
No symbol table info available.
https://issues.asterisk.org/view.php?id=3 0x00002ab5aaa3ad5a in
pthread_mutex_trylock () from
/lib64/libpthread.so.0
No symbol table info available.
https://issues.asterisk.org/view.php?id=4 0x00002aaaadc881a9 in
local_queue_frame (p=0x2aaab5b49cd0,
isoutbound=<value optimized out>, f=0x2aaab5481458, us=0x2aaab5b5a7f0)
from /usr/lib/asterisk/modules/chan_local.so
other = (struct ast_channel *) 0x2aaab5b5b180
https://issues.asterisk.org/view.php?id=5 0x00002aaaadc886b1 in local_write
(ast=0x2aaab5b5a7f0,
f=0x2aaab5481458) from /usr/lib/asterisk/modules/chan_local.so
p = (struct local_pvt *) 0x7ac2
res = <value optimized out>
isoutbound = <value optimized out>
__PRETTY_FUNCTION__ = "local_write"
https://issues.asterisk.org/view.php?id=6 0x000000000043ef8c in ast_write
(chan=0x2aaab5b5a7f0,
fr=0x2aaab5481458) at channel.c:2682
jump = <value optimized out>
res = -1
count = <value optimized out>
f = (struct ast_frame *) 0x2aaab5481458
f2 = (struct ast_frame *) 0x0
__PRETTY_FUNCTION__ = "ast_write"
https://issues.asterisk.org/view.php?id=7 0x0000000000440d8e in
ast_channel_bridge (c0=0x2aaab5415c10,
c1=0x2aaab5b5a7f0, config=0x40b38ba0, fo=0x40b379a8, rc=0x40b379a0)
at channel.c:3806
monitored_source = 0
to = <value optimized out>
res = <value optimized out>
nativefailed = 0
firstpass = <value optimized out>
o0nativeformats = 4
o1nativeformats = 4
time_left_ms = <value optimized out>
nexteventts = {tv_sec = 0, tv_usec = 0}
caller_warning = 0 '\0'
callee_warning = 0 '\0'
__PRETTY_FUNCTION__ = "ast_channel_bridge"
https://issues.asterisk.org/view.php?id=8 0x00002aaaaafcd125 in ast_bridge_call
(chan=0x2aaab5415c10,
peer=0x2aaab5b5a7f0, config=0x40b38ba0) at res_features.c:1420
other = (struct ast_channel *) 0x0
f = (struct ast_frame *) 0x0
who = (struct ast_channel *) 0x2aaab2cc8fa1
chan_featurecode = '\0' <repeats 11 times>
peer_featurecode = '\0' <repeats 11 times>
res = 538996016
hasfeatures = 0
backup_config = {features_caller = {flags = 0}, features_callee = {flags
= 0}, start_time = {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 = 0, flags = 0}
bridge_cdr = <value optimized out>
__PRETTY_FUNCTION__ = "ast_bridge_call"
https://issues.asterisk.org/view.php?id=9 0x00002aaab2cc7290 in dial_exec_full
(chan=0x2aaab5415c10, data=<value
optimized out>, peerflags=0x40b38e10, continue_exec=0x0)
from /usr/lib/asterisk/modules/app_dial.so
toast =
"\000\000\000\000\000\000\000\000rÖ÷ªµ*\000\00030;40\000\000\000ØJ\235\000\000\000\000\000ßJ\235\000\000\000\000\000X\000\000\000\000\000\000\000\020\016\016«ª*\000\000\006\000\000\000\000\000\000\000Àh\036«ª*\000\000S6÷ªµ*\000"
config = {features_caller = {flags = 0}, features_callee = {flags = 0},
start_time = {tv_sec = 1203059599, tv_usec = 762167},
feature_timer = 0, timelimit = 0, play_warning = 0, warning_freq = 0,
warning_sound = 0x0, end_sound = 0x0, start_sound = 0x0,
firstpass = 0, flags = 0}
res = 0
u = (struct ast_module_user *) 0x2aaab5b39810
rest = 0x0
cur = <value optimized out>
outgoing = (struct dial_localuser *) 0x2aaab5b0a7f0
peer = (struct ast_channel *) 0x2aaab5b5a7f0
to = -1
numbusy = 0
numcongestion = 0
numnochan = 0
cause = 0
numsubst = "0828294060 at from-internal/n", '\0' <repeats 30 times>,
"0\213³@\000\000\000\000X`M\000\000\000\000\000p\214³@\000\000\000\000P\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\020\214³@\000\000\000\000\223\001öªµ*\000\0000\000\000\0000\000\000\000\020\214³@\000\000\000\0000\213³@\000\000\000\000ʳ÷ªµ*\000\000\001\200
û\000\000\000\000ØJ\235\000\000\000\000\000ØJ\235\000\000\000\000\000\033\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\020\214³@\000\000\000\000¸K\235\000\000\000\000\000Y\200üªµ*\000\000\000\000\000\000\000\000\000\000s\000\000\000"...
cidname = '\0' <repeats 79 times>
privdb_val = 0
calldurationlimit = 0
timelimit = 0
play_warning = 0
warning_freq = 0
warning_sound = 0x0
end_sound = 0x0
start_sound = 0x0
dtmfcalled = 0x0
dtmfcalling = 0x0
status = "ANSWER\000R\000GS", '\0' <repeats 244 times>
play_to_caller = 0
play_to_callee = 0
sentringing = 0
moh = 0
outbound_group = 0x0
result = <value optimized out>
start_time = <value optimized out>
privintro = "\000\000\000\000\033\000\000\000ÃIO", '\0' <repeats 13
times>, "x\210³@\000\000\000\000\000\000\000\000\006\000\000\000\035",
'\0' <repeats 11 times>, "\n", '\0' <repeats 43 times>, "
\204³@\000\000\000\000ʳ÷ªµ*\000\000\001\200
û\000\000\000dør\220\000\000\000\000\000ør\220\000\000\000\000\000ør\220\000\000\000\000\000ør\220\000\000\000\000\000>s\220\000\000\000\000\000Øs\220\000\000\000\000\000ør\220\000\000\000\000\000Øs\220",
'\0' <repeats 29 times>,
"5K\235\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000ª*\000\000\002\000\000\000\000\000\000\000J\217³@\000\000\000\000#\000\000\000\000\000\000\000"...
privcid =
"\030\000\000\0000\000\000\000ð\213³@\000\000\000\0000\213³@\000\000\000\000\221\211A\000\000\000\000\000Feb
15
09:12:50\000\001\000\000\000\000\000\000\0000~Jµª*\000\000\000\020\000\000\000\000\000\000\220\211³@\000\000\000\000
\231³@", '\0' <repeats 12 times>, "\022©Eµª*\000\000ÄýF
ª*\000\000H`Aµª*\000\000\000\005b\000\000\000\000\000\001\000\000\000ÿÿÿ\177",
'\0' <repeats 24 times>, "3®Eµª*\000\000 \231³@", '\0' <repeats 12
times>, "°\211³@", '\0' <repeats 12 times>,
"ÙIO\000\000\000\000\000p\214³@\000\000\000\000p\214³@"...
opermode = 0
args = {argc = 3, argv = 0x40b38d38, peers = 0x40b37a40 "Local", timeout
= 0x40b37a61 "", options = 0x40b37a62 "g", url = 0x0}
opts = {flags = 32}
opt_args = {0x2aaab5b0a854 "O_DEPTH", 0x0, 0x40b38e60 "Àh\036«ª*",
0x40b38d60 "\030",
0x2aaaab0e0e10 " -- AGI Script Executing Application: (%s) Options:
(%s)\n", 0x6 <Address 0x6 out of bounds>,
0x2aaaab1e68c0 "T\v\016ǻ*", 0x4641f3
"H\215eà[A\\A]A^ÉÃHÇ\003\200", 0x0}
datastore = (struct ast_datastore *) 0x2aaab5b0a810
fulldial = 0
num_dialed = 1
__PRETTY_FUNCTION__ = "dial_exec_full"
https://issues.asterisk.org/view.php?id=10 0x00002aaab2cc8885 in dial_exec
(chan=0x7ac2, data=0x5fab) from
/usr/lib/asterisk/modules/app_dial.so
peerflags = {flags = 32}
https://issues.asterisk.org/view.php?id=11 0x0000000000475fc7 in pbx_exec
(c=0x2aaab5415c10, app=0x7a1820,
data=0x40b38f4a) at pbx.c:532
res = 0
saved_c_appl = 0x6583c8 "DeadAGI"
saved_c_data = 0x40b3caa0
"queueDial.agi|0828294060|Local/0828294060 at from-internal/n|1999|Agent/6049"
https://issues.asterisk.org/view.php?id=12 0x00002aaaab0dcef6 in free () from
/usr/lib/asterisk/modules/res_agi.so
No symbol table info available.
https://issues.asterisk.org/view.php?id=13 0x00002aaaab0dd9ba in free () from
/usr/lib/asterisk/modules/res_agi.so
No symbol table info available.
https://issues.asterisk.org/view.php?id=14 0x00002aaaab0dee71 in free () from
/usr/lib/asterisk/modules/res_agi.so
No symbol table info available.
https://issues.asterisk.org/view.php?id=15 0x000000000047dfed in
pbx_extension_helper (c=0x2aaab5415c10,
con=<value optimized out>, context=0x2aaab5415e60 "from-qmagent",
exten=0x2aaab5415eb0 "0828294060", priority=8, label=<value optimized
out>, callerid=0x2aaab5401cd0 "5036", action=E_SPAWN) at pbx.c:532
e = <value optimized out>
app = (struct ast_app *) 0x6583a0
res = <value optimized out>
q = {incstack = {0x0 <repeats 128 times>}, stacklen = 0, status = 5, swo
= 0x0, data = 0x0,
foundcontext = 0x2aaab5415e60 "from-qmagent"}
passdata =
"queueDial.agi|0828294060|Local/0828294060 at from-internal/n|1999|Agent/6049",
'\0' <repeats 8118 times>
matching_action = <value optimized out>
__PRETTY_FUNCTION__ = "pbx_extension_helper"
https://issues.asterisk.org/view.php?id=16 0x00000000004806d3 in __ast_pbx_run
(c=0x2aaab5415c10) at pbx.c:2306
waittime = <value optimized out>
dst_exten =
"\020\000\000\0000\000\000\000àð³@\000\000\000\000À+\203\000\000\000\000\000\"A\203\000\000\000\000\000
l\206µª*\000\000\000\000\000\000\000\000\000\000\205_\000\000\000\000\000\000\211QB",
'\0' <repeats 29 times>, "\201>", '\0' <repeats 38 times>, "\030", '\0'
<repeats 55 times>,
"\200)\024«µ*\000\000\000\000\000\000\000\000\000\000\030\000\000\000\000\000\000\000°\\\000\000\000\000\000Q\003\002\000\000\000\000\000\000XKµª*\000\000¿Gøªµ*\000\0000?Hµª*\000\0000?Hµª*\000"
pos = 33188
digit = 0
found = 1
res = 0
error = <value optimized out>
__PRETTY_FUNCTION__ = "__ast_pbx_run"
https://issues.asterisk.org/view.php?id=17 0x0000000000481359 in pbx_thread
(data=0x7ac2) at pbx.c:2623
No locals.
https://issues.asterisk.org/view.php?id=18 0x00000000004a9c7c in dummy_start
(data=<value optimized out>) at
utils.c:852
__cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {46912674217776,
-68840629257102411, 46959740289200, 1081583936, 3,
46912674420736, -68840630319060331, -68840629252225065},
__mask_was_saved = 0}}, __pad = {0x40b3f1e0, 0x0, 0x2ab5ab13d450,
0x2ab5aaa380b0}}
__cancel_arg = (void *) 0x40b3f940
not_first_call = <value optimized out>
ret = <value optimized out>
https://issues.asterisk.org/view.php?id=19 0x00002ab5aaa38143 in start_thread ()
from /lib64/libpthread.so.0
No symbol table info available.
https://issues.asterisk.org/view.php?id=20 0x00002ab5aafd574d in clone () from
/lib64/libc.so.6
No symbol table info available.
https://issues.asterisk.org/view.php?id=21 0x0000000000000000 in ?? ()
No symbol table info available.
Frame 4, executing in local_queue_frame around here:
/* Ensure that we have both channels locked */
if (us) {
while (ast_channel_trylock(other)) {
ast_channel_unlock(us);
usleep(1);
ast_channel_lock(us);
}
} else {
ast_channel_lock(other);
}
Presumably in the "ast_channel_trylock"
(gdb) p us->lock
$3 = {__data = {__lock = 1, __count = 1, __owner = 24491, __nusers = 1,
__kind = 1, __spins = 0, __list = {__prev = 0x0, __next = 0x0}},
__size =
"\001\000\000\000\001\000\000\000«_\000\000\001\000\000\000\001", '\0'
<repeats 22 times>, __align = 4294967297}
24491 is our thread - so we have "us" locked.
Problem is that "other" is junk:
(gdb) p *other
$5 = {tech = 0x4000000002, tech_pvt = 0xa000000140, __begin_field =
0x2aaab5b5b190, name = 0x1 <Address 0x1 out of bounds>,
language = 0x1fa <Address 0x1fa out of bounds>, musicclass = 0x40
<Address 0x40 out of bounds>, accountcode = 0x2aaab5b5b370 "ulawtolin",
call_forward = 0x2aaab5b5b230 "", uniqueid = 0x47b53c03 <Address
0x47b53c03 out of bounds>, __end_field = 0x2aaab5b5b1c0, __field_mgr = {
pool = 0x8a4e4, size = 0, space = 1, used = 327490}, fds = {20, 0,
7346, 0, 0, 0, 0, 0}, music_state = 0x0, generatordata = 0x0,
generator = 0x0, _bridge = 0x0, masq = 0x0, masqr = 0x0, cdrflags =
-1572864, _softhangup = 8650832, whentohangup = 13510803167444984,
blocker = 18440269913017810952, lock = {__data = {__lock = -6750320,
__count = 4259708, __owner = -4128776, __nusers = 4287627280,
__kind = 32, __spins = -6226024, __list = {__prev =
0xff4cff3c0000fff0, __next = 0x30003000000008}},
__size = "\220ÿ\230ÿ|ÿ@\000øÿÀÿ\020\000\220ÿ
\000\000\000\230ÿ ÿðÿ\000\000<ÿLÿ\b\000\000\0000\0000", __align =
18295310838726544},
blockproc = 0xffe800380094fff8 <Address 0xffe800380094fff8 out of
bounds>,
appl = 0xffc0fff000600028 <Address 0xffc0fff000600028 out of bounds>,
data = 0x48007000380020 <Address 0x48007000380020 out of bounds>,
fdno = 6815776, sched = 0x20ffd8ffa80010, streamid = -5701712, stream =
0x38003800000000, vstreamid = -524272,
vstream = 0x28001800000000, oldwriteformat = -3080312, timingfd = 40,
timingfunc = 0xffc0fff0fff80018, timingdata = 0xffb0fff800380020,
_state = 1638368, rings = 1048632, cid = {cid_dnid = 0xffe0ff6cffe8fff0
<Address 0xffe0ff6cffe8fff0 out of bounds>,
cid_num = 0x30ffd0ffd80000 <Address 0x30ffd0ffd80000 out of bounds>,
cid_name = 0x30003000180068 <Address 0x30003000180068 out of bounds>,
cid_ani = 0x40007800b400a4 <Address 0x40007800b400a4 out of bounds>,
cid_rdnis = 0xff6cffc000780040 <Address 0xff6cffc000780040 out of
bounds>, cid_pres = 1114088, cid_ani2 = -3670016, cid_ton = 5308384,
cid_tns = -4718528},
dtmfq = "
\000\000\000\230ÿðÿ\\ÿlÿ@\000ðÿØÿøÿ\000\000x\000H\000H\000\000\000°ÿlÿlÿèÿàÿH\000°ÿ¨ÿèÿ
ÿ\230ÿ\\ÿ`\000\020\000èÿ¤\000(\000\030\0000\000`\000\020\000\020\000\030\000Ðÿ\000",
dtmff = {frametype = 16, subclass = 6815792, datalen = 1048648, samples =
6815832,
mallocd = 2002873461, mallocd_hdr_len = 110, offset = 0, src = 0x175
<Address 0x175 out of bounds>, data = 0x800000002, delivery = {
tv_sec = 687194767520, tv_usec = 1}, frame_list = {next = 0x15b},
flags = 64, ts = 46912681391328, len = 46912681391168, seqno = 0},
context = "\000\000\000\000\000\000\000\000À\225³µª*", '\0' <repeats
65 times>,
exten = '\0' <repeats 32 times>,
"TUTVPWWTUQWUWTÔÔÔÔÑ×U×ÔUTUUTUÔÔ×××ÕUTTT×ÔWUUTTUU",
priority = 1431655765,
macrocontext =
"QVÕUUÔÔÔÔÔÕÕÕÖ×TQVUWTÕÕÕÕÔÔÕÔÔÕUUUUURQÔÕÔ×ßÒÕÔUTWVTVWUUÕÕÔÕÔÒÐW]SÕVWÔÔÔ×ÖÔWTUUWÕ",
macroexten = "ÞÝVÖÔTÐÕPY]T^SÖT×ÑÑÑÖÑÕUÔUWWzt_read\000aw",
'\0' <repeats 14 times>,
"\025\002\000\000\000\000\000\000\002\000\000\000@\000\000\000@\001\000\000
\000\000\000\001\000\000", macropriority = 0,
dialcontext =
"ú\001\000\000\000\000\000\000@\000\000\000\000\000\000\000𶵵ª*\000\000°µµµª*\000\000\003<µG\000\000\000\000ä¤\b",
'\0' <repeats 13 times>,
"\001\000\000\000\000\000\000\000Bÿ\004\000\000\000\000\000\024\000\000\000\000\000\000",
pbx = 0x1cb2, amaflags = 0,
cdr = 0x0, adsicpe = AST_ADSI_UNKNOWN, zone = 0x0, monitor = 0x0, insmpl
= 0, outsmpl = 0, fin = 0, fout = 0, hangupcause = -1572864,
varshead = {first = 0x300000ff6cfff8, last = 0xffe8ffc8ffc00008},
callgroup = 18295310838726544, pickupgroup = 18415218949328273400,
flags = 32, transfercapability = 65432, readq = {first =
0xff4cff3c0000fff0, last = 0x30003000000008}, alertpipe = {9764856,
-1572808},
nativeformats = 6291496, readformat = -4128784, writeformat = 3670048,
writetrans = 0xffe0002000680020, readtrans = 0x20ffd8ffa80010,
rawreadformat = -5701712, rawwriteformat = -458784, audiohooks =
0x38003800000000, unused = 0x280020fff80010, chan_list = {
next = 0x28001800000000}, jb = {conf = {flags = 4291886984, max_size =
-17732987957805032, resync_threshold = -22236557516210144,
impl = "àÿ\030\0008\000\020\000ðÿèÿ"}, impl =
0x30ffd0ffd80000, jbobj = 0x30003000180068, timebase = {tv_sec =
18014913917354148,
tv_usec = -41377096446508992}, next = -15762598694682648,
last_format = 5308384, logfile = 0xfff0ff9800000020, flags = 4285333340},
emulate_dtmf_digit = -40 'Ø', emulate_dtmf_duration = 7864320, dtmf_tv
= {tv_sec = -22517998132133816, tv_usec = -8725823071912084},
visible_indication = -5242808, datastores = {first = 0x60ff5cff98ffa0,
last = 0x2800a4ffe80010}}
So the ast_channel_trylock aborts
Where did "other" come from?
static int local_queue_frame(struct local_pvt *p, int isoutbound, struct
ast_frame *f, struct ast_channel *us)
{
struct ast_channel *other = NULL;
/* Recalculate outbound channel */
other = isoutbound ? p->owner : p->chan;
(gdb) p other
$10 = (struct ast_channel *) 0x2aaab5b5b180
(gdb) p p->owner
$11 = (struct ast_channel *) 0x2aaab5b5a7f0
(gdb) p p->chan
$12 = (struct ast_channel *) 0x0
So from that it looks like isoutbound was false, so other := p->chan,
which WAS 0x2aaab5b5b180. But in the meantime that channel disappeared...
p->owner->name: Local/0828294060 at from-internal-4468,1
Presumably, p->chan->name WAS Local/0828294060 at from-internal-4468,2??
My diagnosis is that the "other" channel was closed in another thread
between the time that "other" was fished out of the local_pvt structure,
and the time that it was passed to ast_channel_trylock.
Don't see obviously that the channel was locked to prevent it from being
closed.
======================================================================
Relationships ID Summary
----------------------------------------------------------------------
has duplicate 0012039 crash in local_hangup() when p->owne...
related to 0016639 Crash In chan_local in local_queue_fram...
======================================================================
Issue History
Date Modified Username Field Change
======================================================================
2010-01-19 07:47 lmadsen Relationship added related to 0016639
======================================================================
More information about the asterisk-bugs
mailing list