[asterisk-bugs] [Asterisk 0015109]: Abort by memory allocator, possibly in moh_files_generator
Asterisk Bug Tracker
noreply at bugs.digium.com
Wed Jun 10 15:11:17 CDT 2009
A NOTE has been added to this issue.
======================================================================
https://issues.asterisk.org/view.php?id=15109
======================================================================
Reported By: jvandal
Assigned To:
======================================================================
Project: Asterisk
Issue ID: 15109
Category: Resources/res_musiconhold
Reproducibility: random
Severity: block
Priority: normal
Status: acknowledged
Target Version: 1.4.27
Asterisk Version: 1.4.24
Regression: No
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
======================================================================
Date Submitted: 2009-05-14 10:49 CDT
Last Modified: 2009-06-10 15:11 CDT
======================================================================
Summary: Abort by memory allocator, possibly in
moh_files_generator
Description:
I have a server running with Asterisk 1.4.24.1 where it randomly segfault
for "unknown" reason.
I'm not sure if this is related to moh_files_generator function or with
filestream_descructor.
Let me know what needed in order to fix this crash, if GDB traces aren't
enough.
Asterisk is compiled with DONT_OPTIMIZE and others flag needed for "gdb".
======================================================================
Relationships ID Summary
----------------------------------------------------------------------
related to 0014958 Segfault Asterisk 1.4.24.1
related to 0015123 out of bounds crash and core dump
has duplicate 0015195 double free or corruption (!prev) in mo...
======================================================================
----------------------------------------------------------------------
(0106262) aragon (reporter) - 2009-06-10 15:11
https://issues.asterisk.org/view.php?id=15109#c106262
----------------------------------------------------------------------
I have been able to lab this up and reproduce the crash 12 times before
running under valgrind. I should be able to test any patch very quickly in
this lab environment.
Using Asterisk 1.4 SVN branch revision 199742
Uploading a valgrind dump and malloc_debug.txt
valgrind.txt.core.3857.zip
malloc_debug.txt
I don't know if valgrind itself was responsible for causing the error I
see in malloc_debug.txt file...
PHP Fatal error: Class 'NLS' not found in
/var/www/scopserv/telephony/scripts/agi/fixcidname.php on line 32
PHP Fatal error: Maximum execution time of 5 seconds exceeded in
/var/www/scopserv/telephony/lib/phpagi.php on line 174
Here is the CLI the system was shooting out prior to the crash.
-- Executing [5000 at zap-incoming:1] Answer("Zap/242-1", "") in new
stack
-- Got SIP response 489 "Bad event" back from 192.168.30.146
-- Accepting call from '1021' to '5000' on channel 0/2, span 11
-- Executing [5000 at zap-incoming:3] NoOp("Zap/241-1", ""INCOMING CALL
FROM CALLER ID: 1002 (1002)"") in new stack
-- Got SIP response 489 "Bad event" back from 192.168.30.146
-- Executing [5000 at zap-incoming:4] Set("Zap/241-1",
"__INCOMING_DNIS=5000") in new stack
-- Executing [5000 at zap-incoming:5] Set("Zap/241-1",
"CALLERID(dnid)=5000") in new stack
-- Executing [5000 at zap-incoming:6] Set("Zap/241-1",
"CDR(userfield)=5000") in new stack
-- Got SIP response 489 "Bad event" back from 192.168.30.146
-- Got SIP response 489 "Bad event" back from 192.168.30.146
[Jun 10 15:43:34] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1611' is now Reachable. (1884ms / 2000ms)
[Jun 10 15:43:34] ERROR[14172]: pbx.c:1565 ast_func_write: Function CDR
not registered
-- Executing [5000 at zap-incoming:7] Goto("Zap/241-1", "10") in new
stack
[Jun 10 15:43:35] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1645' is now Lagged. (3272ms / 2000ms)
-- Executing [5000 at zap-incoming:2] Set("Zap/242-1",
"CHANNEL(musicclass)=default") in new stack
-- Goto (zap-incoming,5000,10)
-- Executing [5000 at zap-incoming:10] AGI("Zap/241-1",
"/var/www/scopserv/telephony/scripts/agi/fixcidname.php") in new stack
== Parsing '/etc/asterisk/res_snmp.conf': Found
Loading [Sub]Agent Module
-- Executing [5000 at zap-incoming:3] NoOp("Zap/242-1", ""INCOMING CALL
FROM CALLER ID: 1021 (1021)"") in new stack
-- Executing [5000 at zap-incoming:1] Answer("Zap/243-1", "") in new
stack
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1623' is now Reachable. (1736ms / 2000ms)
res_snmp.so => (SNMP [Sub]Agent for Asterisk)
-- Got SIP response 489 "Bad event" back from 192.168.30.146
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1632' is now Reachable. (1955ms / 2000ms)
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1625' is now Reachable. (1963ms / 2000ms)
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1624' is now Reachable. (1964ms / 2000ms)
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1611' is now Lagged. (3386ms / 2000ms)
[Jun 10 15:43:36] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1644' is now Reachable. (1964ms / 2000ms)
-- Executing [5000 at zap-incoming:4] Set("Zap/242-1",
"__INCOMING_DNIS=5000") in new stack
-- Accepting call from '1040' to '5000' on channel 0/3, span 11
== Parsing '/etc/asterisk/codecs.conf': [Jun 10 15:43:36] NOTICE[13661]:
chan_sip.c:13085 handle_response_peerpoke: Peer '1639' is now Reachable.
(1829ms / 2000ms)
-- Executing [5000 at zap-incoming:1] Answer("Zap/244-1", "") in new
stack
-- Executing [5000 at zap-incoming:5] Set("Zap/242-1",
"CALLERID(dnid)=5000") in new stack
-- Executing [5000 at zap-incoming:2] Set("Zap/243-1",
"CHANNEL(musicclass)=default") in new stack
Found
-- codec_g722: using generic PLC
-- Got SIP response 489 "Bad event" back from 192.168.30.146
-- Executing [5000 at zap-incoming:6] Set("Zap/242-1",
"CDR(userfield)=5000") in new stack
-- Launched AGI Script
/var/www/scopserv/telephony/scripts/agi/fixcidname.php
-- Got SIP response 489 "Bad event" back from 192.168.30.146
== Registered translator 'g722tolin' from format g722 to slin, cost 486
[Jun 10 15:43:37] ERROR[14203]: pbx.c:1565 ast_func_write: Function CDR
not registered
-- Executing [5000 at zap-incoming:7] Goto("Zap/242-1", "10") in new
stack
-- Goto (zap-incoming,5000,10)
-- Executing [5000 at zap-incoming:10] AGI("Zap/242-1",
"/var/www/scopserv/telephony/scripts/agi/fixcidname.php") in new stack
-- Executing [5000 at zap-incoming:3] NoOp("Zap/243-1", ""INCOMING CALL
FROM CALLER ID: 1040 (1040)"") in new stack
-- Launched AGI Script
/var/www/scopserv/telephony/scripts/agi/fixcidname.php
-- Accepting call from '1027' to '5000' on channel 0/4, span 11
-- Executing [5000 at zap-incoming:2] Set("Zap/244-1",
"CHANNEL(musicclass)=default") in new stack
== Registered translator 'lintog722' from format slin to g722, cost 501
-- Executing [5000 at zap-incoming:4] Set("Zap/243-1",
"__INCOMING_DNIS=5000") in new stack
codec_g722.so => (ITU G.722-64kbps G722 Transcoder)
== Registered application 'ZapBarge'
app_dahdibarge.so => (Barge in on channel application)
-- AGI Script /var/www/scopserv/telephony/scripts/agi/fixcidname.php
completed, returning 0
-- Executing [5000 at zap-incoming:11] Set("Zap/242-1", "FAXNUMBER=5000")
in new stack
-- Executing [5000 at zap-incoming:3] NoOp("Zap/244-1", ""INCOMING CALL
FROM CALLER ID: 1027 (1027)"") in new stack
-- AGI Script /var/www/scopserv/telephony/scripts/agi/fixcidname.php
completed, returning 0
-- Executing [5000 at zap-incoming:11] Set("Zap/241-1", "FAXNUMBER=5000")
in new stack
-- Executing [5000 at zap-incoming:4] Set("Zap/244-1",
"__INCOMING_DNIS=5000") in new stack
-- Loaded PUBLIC key 'iaxtel'
-- Executing [5000 at zap-incoming:12] Set("Zap/242-1",
"__INCOMINGLINE=1") in new stack
-- Executing [5000 at zap-incoming:5] Set("Zap/243-1",
"CALLERID(dnid)=5000") in new stack
-- Loaded PUBLIC key 'freeworlddialup'
res_crypto.so => (Cryptographic Digital Signatures)
-- Executing [5000 at zap-incoming:12] Set("Zap/241-1",
"__INCOMINGLINE=1") in new stack
-- Executing [5000 at zap-incoming:1] Answer("Zap/245-1", "") in new
stack
-- Executing [5000 at zap-incoming:5] Set("Zap/244-1",
"CALLERID(dnid)=5000") in new stack
== Registered application 'NVFaxDetect'
app_nv_fax_detect.so => (NV Fax Detection Application)
-- Executing [5000 at zap-incoming:13] GotoIf("Zap/241-1", "0?14:15") in
new stack
-- Executing [5000 at zap-incoming:13] GotoIf("Zap/242-1", "0?14:15") in
new stack
== Registered application 'Transfer'
app_transfer.so => (Transfer)
-- Executing [5000 at zap-incoming:6] Set("Zap/243-1",
"CDR(userfield)=5000") in new stack
[Jun 10 15:43:39] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1623' is now Lagged. (5426ms / 2000ms)
-- Executing [5000 at zap-incoming:6] Set("Zap/244-1",
"CDR(userfield)=5000") in new stack
-- Goto (zap-incoming,5000,15)
-- Executing [5000 at zap-incoming:15] GotoIf("Zap/241-1", "0?16:17") in
new stack
-- Goto (zap-incoming,5000,15)
== Registered application 'SetCDRUserField'
== Registered application 'AppendCDRUserField'
[Jun 10 15:43:39] ERROR[10126]: manager.c:2649
ast_manager_register_struct: Could not obtain lock on manager list
-- Executing [5000 at zap-incoming:15] GotoIf("Zap/242-1", "0?16:17") in
new stack
[Jun 10 15:43:39] ERROR[14227]: pbx.c:1565 ast_func_write: Function CDR
not registered
-- Executing [5000 at zap-incoming:7] Goto("Zap/243-1", "10") in new
stack
-- Executing [5000 at zap-incoming:2] Set("Zap/245-1",
"CHANNEL(musicclass)=default") in new stack
-- Accepting call from '1029' to '5000' on channel 0/5, span 11
-- Executing [5000 at zap-incoming:3] NoOp("Zap/245-1", ""INCOMING CALL
FROM CALLER ID: 1029 (1029)"") in new stack
-- Goto (zap-incoming,5000,17)
-- Executing [5000 at zap-incoming:17] GotoIf("Zap/241-1", "0?18:19") in
new stack
[Jun 10 15:43:40] ERROR[14244]: pbx.c:1565 ast_func_write: Function CDR
not registered
-- Executing [5000 at zap-incoming:7] Goto("Zap/244-1", "10") in new
stack
-- Goto (zap-incoming,5000,17)
-- Executing [5000 at zap-incoming:17] GotoIf("Zap/242-1", "0?18:19") in
new stack
-- Goto (zap-incoming,5000,10)
-- Executing [5000 at zap-incoming:10] AGI("Zap/243-1",
"/var/www/scopserv/telephony/scripts/agi/fixcidname.php") in new stack
[Jun 10 15:43:40] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1632' is now Lagged. (6226ms / 2000ms)
-- Executing [5000 at zap-incoming:1] Answer("Zap/246-1", "") in new
stack
-- Goto (zap-incoming,5000,19)
-- Executing [5000 at zap-incoming:19] GotoIf("Zap/241-1", "0?20:21") in
new stack
-- Executing [5000 at zap-incoming:4] Set("Zap/245-1",
"__INCOMING_DNIS=5000") in new stack
-- Goto (zap-incoming,5000,10)
-- Executing [5000 at zap-incoming:10] AGI("Zap/244-1",
"/var/www/scopserv/telephony/scripts/agi/fixcidname.php") in new stack
-- Goto (zap-incoming,5000,19)
-- Executing [5000 at zap-incoming:19] GotoIf("Zap/242-1", "0?20:21") in
new stack
-- Accepting call from '1021' to '5000' on channel 0/6, span 11
[Jun 10 15:43:40] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1625' is now Lagged. (6548ms / 2000ms)
-- Goto (zap-incoming,5000,21)
-- Executing [5000 at zap-incoming:21] Set("Zap/241-1",
"CHANNEL(language)=en") in new stack
-- Executing [5000 at zap-incoming:5] Set("Zap/245-1",
"CALLERID(dnid)=5000") in new stack
-- Goto (zap-incoming,5000,21)
-- Executing [5000 at zap-incoming:21] Set("Zap/242-1",
"CHANNEL(language)=en") in new stack
[Jun 10 15:43:41] ERROR[14244]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:431
__ast_pthread_mutex_lock: loader.c line 194 (__ast_module_user_add): Error
obtaining mutex: Invalid argument
[Jun 10 15:43:41] ERROR[14244]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:514
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
mutex '&(&mod->users)->lock' freed more times than we've locked!
loader.c line 196 (__ast_module_user_add): mutex '&(&mod->users)->lock'
freed more times than we've locked!
[Jun 10 15:43:41] ERROR[14244]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:531
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
Error releasing mutex: Invalid argument
-- Executing [5000 at zap-incoming:22] Set("Zap/242-1", "QUEUE_PRIO=0")
in new stack
[Jun 10 15:43:41] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1624' is now Lagged. (7648ms / 2000ms)
-- Executing [5000 at zap-incoming:22] Set("Zap/241-1", "QUEUE_PRIO=0")
in new stack
-- Executing [5000 at zap-incoming:6] Set("Zap/245-1",
"CDR(userfield)=5000") in new stack
-- Executing [5000 at zap-incoming:2] Set("Zap/246-1",
"CHANNEL(musicclass)=default") in new stack
[Jun 10 15:43:42] NOTICE[13661]: chan_sip.c:13085
handle_response_peerpoke: Peer '1644' is now Lagged. (7810ms / 2000ms)
-- Executing [5000 at zap-incoming:23] Gosub("Zap/242-1",
"default-application-acd-irs-new-english|s|1") in new stack
[Jun 10 15:43:42] ERROR[14304]: pbx.c:1565 ast_func_write: Function CDR
not registered
-- Executing [5000 at zap-incoming:7] Goto("Zap/245-1", "10") in new
stack
-- Executing [5000 at zap-incoming:1] Answer("Zap/247-1", "") in new
stack
-- Executing [5000 at zap-incoming:23] Gosub("Zap/241-1",
"default-application-acd-irs-new-english|s|1") in new stack
-- Executing [5000 at zap-incoming:3] NoOp("Zap/246-1", ""INCOMING CALL
FROM CALLER ID: 1021 (1021)"") in new stack
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:431
__ast_pthread_mutex_lock: loader.c line 194 (__ast_module_user_add): Error
obtaining mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:514
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
mutex '&(&mod->users)->lock' freed more times than we've locked!
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:531
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
Error releasing mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:431
__ast_pthread_mutex_lock: loader.c line 207 (__ast_module_user_remove):
Error obtaining mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:514
__ast_pthread_mutex_unlock: loader.c line 209 (__ast_module_user_remove):
mutex '&(&mod->users)->lock' freed more times than we've locked!
[Jun 10 15:43:42] ERROR[14203]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:531
__ast_pthread_mutex_unlock: loader.c line 209 (__ast_module_user_remove):
Error releasing mutex: Invalid argument
-- Launched AGI Script
/var/www/scopserv/telephony/scripts/agi/fixcidname.php
-- Goto (zap-incoming,5000,10)
-- Executing [5000 at zap-incoming:10] AGI("Zap/245-1",
"/var/www/scopserv/telephony/scripts/agi/fixcidname.php") in new stack
-- Executing [s at default-application-acd-irs-new-english:1]
NoOp("Zap/242-1", ""=== START QUEUE (default-irs-new-english) ==="") in new
stack
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:431
__ast_pthread_mutex_lock: loader.c line 194 (__ast_module_user_add): Error
obtaining mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:514
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
mutex '&(&mod->users)->lock' freed more times than we've locked!
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:531
__ast_pthread_mutex_unlock: loader.c line 196 (__ast_module_user_add):
Error releasing mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:431
__ast_pthread_mutex_lock: loader.c line 207 (__ast_module_user_remove):
Error obtaining mutex: Invalid argument
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:514
__ast_pthread_mutex_unlock: loader.c line 209 (__ast_module_user_remove):
mutex '&(&mod->users)->lock' freed more times than we've locked!
[Jun 10 15:43:42] ERROR[14172]:
/dar/build/asterisk-1.4.26/include/asterisk/lock.h:531
__ast_pthread_mutex_unlock: loader.c line 209 (__ast_module_user_remove):
Error releasing mutex: Invalid argument
-- Executing [s at default-application-acd-irs-new-english:1]
NoOp("Zap/241-1", ""=== START QUEUE (default-irs-new-english) ==="") in new
stack
-- Executing [5000 at zap-incoming:4] Set("Zap/246-1",
"__INCOMING_DNIS=5000") in new stack
-- Launched AGI Script
/var/www/scopserv/telephony/scripts/agi/fixcidname.php
Issue History
Date Modified Username Field Change
======================================================================
2009-06-10 15:11 aragon Note Added: 0106262
======================================================================
More information about the asterisk-bugs
mailing list