[asterisk-bugs] [Asterisk 0010923]: crash in ast_var_name on SIP hangup
noreply at bugs.digium.com
noreply at bugs.digium.com
Thu Nov 15 07:45:33 CST 2007
A NOTE has been added to this issue.
======================================================================
http://bugs.digium.com/view.php?id=10923
======================================================================
Reported By: atis
Assigned To: Corydon76
======================================================================
Project: Asterisk
Issue ID: 10923
Category: Channels/chan_sip/General
Reproducibility: N/A
Severity: crash
Priority: normal
Status: feedback
Asterisk Version: 1.4.12.1
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Disclaimer on File?: N/A
Request Review:
======================================================================
Date Submitted: 10-09-2007 08:37 CDT
Last Modified: 11-15-2007 07:45 CST
======================================================================
Summary: crash in ast_var_name on SIP hangup
Description:
I just upgraded to asterisk 1.4.12.1 (from 1.4.10), and within few hours i
got crash.
It occurred on hangup of SIP channel, and it seems to be related to some
SIP data.
======================================================================
----------------------------------------------------------------------
atis - 11-15-07 07:45
----------------------------------------------------------------------
The problem is not completely gone. I can still crash it without valgrind,
but no success when running valgrind.
The big problem when running asterisk+valgrind - the system is becoming
extremely slow, SIP registrations are lost, and there are problems with
sending media. I can repeat the problem with some automated tests, but
valgrind slows everything down numerous times - and no success yet in
crashing it.
I will try to run tests on our production system that has 8 cores at night
time and i hope that this would compensate slowdown, but that needs some
preparations, and i have only few hours for tests.
As far as i have tested, this problem is related to having multiple
queues, transfers between them and agent logins/logouts. I'm also using
agentcallbacklogin, and i know it's not recommended, but it's not crashing
for 1.4.10 like this.
So, here goes log of what happens within short time of runnig valgrind. I
get none of those registration and audio problems when not running
valgrind.
[Nov 15 14:06:11] NOTICE[23373]: pbx_spool.c:351 attempt_thread: Call
completed to Local/054 at agent-dial
-- AGI Script Executing Application: (SendDTMF) Options: (0)
-- SIP/agent_22227-08531388 answered Local/054 at agent-dial-3b17,2
-- Executing [054 at agent-out:1] NoOp("Local/054 at agent-dial-3b17,1",
"Agent action: queue_login_1") in new stack
-- Executing [054 at agent-out:2] AGI("Local/054 at agent-dial-3b17,1",
"agi_script.php|queue_login_1") in new stack
-- Launched AGI Script ./php/agi_script.php
agi_script.php|queue_login_1:
agi_script.php|queue_login_1:
/work/test_framework/actions/agent-out/queue_login_1.php
-- Attempting call on Local/056 at agent-dial for 056 at agent-out:1 (Retry
1)
-- Executing [056 at agent-dial:1] Dial("Local/056 at agent-dial-e265,2",
"SIP/056 at agent_22252") in new stack
-- Called 056 at agent_22252
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- Attempting call on Local/027 at agent-dial for 027 at agent-out:1 (Retry
1)
-- Executing [027 at agent-dial:1] Dial("Local/027 at agent-dial-6a5d,2",
"SIP/027 at agent_22247") in new stack
-- Called 027 at agent_22247
-- AGI Script Executing Application: (SendDTMF) Options: (#)
[Nov 15 14:06:13] WARNING[23025]: chan_sip.c:12224
handle_response_register: Got 200 OK on REGISTER that isn't a register
-- SIP/agent_22237-085df750 answered Local/056 at agent-dial-7769,2
-- Executing [056 at agent-out:1] NoOp("Local/056 at agent-dial-7769,1",
"Agent action: queue_logout_2") in new stack
-- Executing [056 at agent-out:2] AGI("Local/056 at agent-dial-7769,1",
"agi_script.php|queue_logout_2") in new stack
-- Launched AGI Script ./php/agi_script.php
agi_script.php|queue_logout_2:
agi_script.php|queue_logout_2:
/work/test_framework/actions/agent-out/queue_logout_2.php
-- Attempting call on Local/056 at agent-dial for 056 at agent-out:1 (Retry
1)
-- Executing [056 at agent-dial:1] Dial("Local/056 at agent-dial-76f5,2",
"SIP/056 at agent_22224") in new stack
-- Called 056 at agent_22224
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
[Nov 15 14:06:14] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22252 at agent_22252' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=3)
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script agi_script.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [056 at agent-out:3] Hangup("SIP/agent_22256-084dd438", "")
in new stack
== Spawn extension (agent-out, 056, 3) exited non-zero on
'SIP/agent_22256-084dd438'
[Nov 15 14:06:15] NOTICE[23375]: pbx_spool.c:351 attempt_thread: Call
completed to Local/056 at agent-dial
-- AGI Script Executing Application: (SendDTMF) Options: (2)
[Nov 15 14:06:15] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22240 at agent_22240' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=4)
[Nov 15 14:06:15] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22219 at agent_22219' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=4)
[Nov 15 14:06:15] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22208 at agent_22208' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=4)
-- AGI Script Executing Application: (SendDTMF) Options: (2)
== Spawn extension (agent-dial, 054, 1) exited non-zero on
'Local/054 at agent-dial-3b17,2'
-- SIP/agent_22211-084d6948 answered Local/056 at agent-dial-8226,2
-- Executing [056 at agent-out:1] NoOp("Local/056 at agent-dial-8226,1",
"Agent action: queue_logout_2") in new stack
-- Executing [056 at agent-out:2] AGI("Local/056 at agent-dial-8226,1",
"agi_script.php|queue_logout_2") in new stack
-- Launched AGI Script ./php/agi_script.php
agi_script.php|queue_logout_2:
agi_script.php|queue_logout_2:
/work/test_framework/actions/agent-out/queue_logout_2.php
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
[Nov 15 14:06:16] WARNING[23025]: chan_sip.c:12224
handle_response_register: Got 200 OK on REGISTER that isn't a register
-- AGI Script Executing Application: (SendDTMF) Options: (9)
-- AGI Script Executing Application: (SendDTMF) Options: (9)
[Nov 15 14:06:16] WARNING[23025]: chan_sip.c:12224
handle_response_register: Got 200 OK on REGISTER that isn't a register
[Nov 15 14:06:16] WARNING[23025]: chan_sip.c:12224
handle_response_register: Got 200 OK on REGISTER that isn't a register
-- AGI Script Executing Application: (SendDTMF) Options: (2)
[Nov 15 14:06:16] WARNING[23025]: chan_sip.c:12224
handle_response_register: Got 200 OK on REGISTER that isn't a register
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (SendDTMF) Options: (0)
-- AGI Script Executing Application: (SendDTMF) Options: (0)
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 127214)
-- AGI Script Executing Application: (SendDTMF) Options: (9)
-- Executing [22238 at incoming:1] AGI("SIP/112233-085209a8",
"detect_did_agent.php|22238") in new stack
-- Launched AGI Script ./php/detect_did_agent.php
-- AGI Script Executing Application: (Goto) Options:
(agent-in|22238|1)
-- Goto (agent-in,22238,1)
-- AGI Script detect_did_agent.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [22238 at agent-in:1] NoOp("SIP/112233-085209a8", "Agent
incoming from ITN Economy Sales-----22901-----112233 112233 to 22238") in
new stack
-- Executing [22238 at agent-in:2] Answer("SIP/112233-085209a8", "") in
new stack
-- Executing [22238 at agent-in:3] AGI("SIP/112233-085209a8",
"agi_script.php") in new stack
-- Launched AGI Script ./php/agi_script.php
agi_script.php:
agi_script.php: /work/test_framework/actions/agent-in/default.php
-- Playing 'tt-weasels' (escape_digits=) (sample_offset 0)
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (SendDTMF) Options: (1)
-- AGI Script Executing Application: (SendDTMF) Options: (4)
[Nov 15 14:06:18] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22218 at agent_22218' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=4)
-- AGI Script Executing Application: (SendDTMF) Options: (#)
-- AGI Script Executing Application: (SendDTMF) Options: (0)
-- AGI Script Executing Application: (SendDTMF) Options: (#)
-- AGI Script Executing Application: (SendDTMF) Options: (3)
[Nov 15 14:06:19] NOTICE[23360]: pbx_spool.c:341 attempt_thread: Call
failed to go through, reason (0) Call Failure (not BUSY, and not NO_ANSWER,
maybe Circuit busy or down?)
== Spawn extension (agent-dial, 056, 1) exited non-zero on
'Local/056 at agent-dial-7607,2'
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (9)
-- AGI Script agi_script.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [054 at agent-out:3] Hangup("SIP/agent_22227-08531388", "")
in new stack
== Spawn extension (agent-out, 054, 3) exited non-zero on
'SIP/agent_22227-08531388'
[Nov 15 14:06:20] NOTICE[23379]: pbx_spool.c:351 attempt_thread: Call
completed to Local/054 at agent-dial
-- AGI Script agi_script.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [056 at agent-out:3] Hangup("Local/056 at agent-dial-7769,1",
"") in new stack
== Spawn extension (agent-out, 056, 3) exited non-zero on
'Local/056 at agent-dial-7769,1'
[Nov 15 14:06:20] NOTICE[23385]: pbx_spool.c:351 attempt_thread: Call
completed to Local/056 at agent-dial
== Spawn extension (agent-dial, 056, 1) exited non-zero on
'Local/056 at agent-dial-7769,2'
-- AGI Script Executing Application: (SendDTMF) Options: (2)
-- AGI Script Executing Application: (SendDTMF) Options: (#)
agi_script.php: Found 8001 samples per second for tt-weasels - total is
20559
-- Playing 'tt-weasels' (escape_digits=) (sample_offset 0)
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:21] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22211 at agent_22211' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=8)
[Nov 15 14:06:21] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22209 at agent_22209' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=7)
-- AGI Script Executing Application: (SendDTMF) Options: (9)
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (0)
[Nov 15 14:06:22] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22256 at agent_22256' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=7)
== Spawn extension (did-dial, 8006772943, 1) exited non-zero on
'Local/8006772943 at did-dial-0d01,2'
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- AGI Script Executing Application: (SendDTMF) Options: (8)
-- AGI Script agi_script.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [056 at agent-out:3] Hangup("Local/056 at agent-dial-8226,1",
"") in new stack
== Spawn extension (agent-out, 056, 3) exited non-zero on
'Local/056 at agent-dial-8226,1'
[Nov 15 14:06:22] NOTICE[23387]: pbx_spool.c:351 attempt_thread: Call
completed to Local/056 at agent-dial
== Spawn extension (agent-dial, 056, 1) exited non-zero on
'Local/056 at agent-dial-8226,2'
[Nov 15 14:06:22] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22236 at agent_22236' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=7)
[Nov 15 14:06:22] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22275 at agent_22275' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=8)
[Nov 15 14:06:22] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22272 at agent_22272' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=4)
[Nov 15 14:06:22] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22271 at agent_22271' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=6)
-- AGI Script Executing Application: (SendDTMF) Options: (1)
[Nov 15 14:06:23] NOTICE[23025]: chan_sip.c:7322 sip_reg_timeout: --
Registration for '22259 at agent_22259' timed out, trying again (Attempt
http://bugs.digium.com/view.php?id=6)
-- AGI Script Executing Application: (SendDTMF) Options: (4)
-- Playing 'tt-weasels' (escape_digits=) (sample_offset 0)
-- AGI Script Executing Application: (SendDTMF) Options: (#)
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:24] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- AGI Script Executing Application: (SendDTMF) Options: (6)
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- AGI Script Executing Application: (SendDTMF) Options: (0)
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
-- AGI Script Executing Application: (SendDTMF) Options: (5)
-- Playing 'tt-weasels' (escape_digits=) (sample_offset 0)
-- Exiting with 500ms silence >= 500ms required
-- AGI Script agi_script.php completed, returning 0
Huh? Child handler, but nobody there?
-- Executing [054 at agent-out:3] Hangup("SIP/agent_22274-085fbfa0", "")
in new stack
== Spawn extension (agent-out, 054, 3) exited non-zero on
'SIP/agent_22274-085fbfa0'
[Nov 15 14:06:26] NOTICE[23364]: pbx_spool.c:351 attempt_thread: Call
completed to Local/054 at agent-dial
-- SIP/agent_22234-0864a3d0 answered Local/054 at agent-dial-7cec,2
-- Executing [054 at agent-out:1] NoOp("Local/054 at agent-dial-7cec,1",
"Agent action: queue_login_1") in new stack
-- Executing [054 at agent-out:2] AGI("Local/054 at agent-dial-7cec,1",
"agi_script.php|queue_login_1") in new stack
-- Launched AGI Script ./php/agi_script.php
agi_script.php|queue_login_1:
agi_script.php|queue_login_1:
/work/test_framework/actions/agent-out/queue_login_1.php
-- AGI Script Executing Application: (WaitForSilence) Options: (500)
-- Waiting 1 time(s) for 500 ms silence with 0 timeout
-- Attempting call on Local/054 at agent-dial for 054 at agent-out:1 (Retry
1)
-- Attempting call on Local/2943 at did-dial for 2943 at did-out:1 (Retry
1)
-- Executing [054 at agent-dial:1] Dial("Local/054 at agent-dial-6a33,2",
"SIP/054 at agent_22255") in new stack
-- Called 054 at agent_22255
-- Executing [2943 at did-dial:1] Dial("Local/2943 at did-dial-002d,2",
"SIP/2943 at external_calls") in new stack
-- Called 2943 at external_calls
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
[Nov 15 14:06:26] WARNING[23239]: file.c:638 ast_readaudio_callback:
Failed to write frame
agi_script.php|ivr_queue: Failed to talk with voice tt-monkeys
-- Playing 'tt-monkeys' (escape_digits=) (sample_offset 0)
Issue History
Date Modified Username Field Change
======================================================================
11-15-07 07:45 atis Note Added: 0073708
======================================================================
More information about the asterisk-bugs
mailing list