[Home]

Summary:ASTERISK-16512: [patch] ERROR[7169] astobj2.c: bad magic number 0x0 for 0x8b1c3d0
Reporter:frank koster (notthematrix)Labels:
Date Opened:2010-08-05 07:57:23Date Closed:2010-10-15 01:21:06
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Addons/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 17801.patch
( 1) 20100813__issue17801__debug.diff.txt
( 2) backtrace.txt
( 3) backtracefull.txt
( 4) bug17801.diff1.txt
( 5) config.tgz
Description:found a crash
happens randomly
[Aug  3 21:26:00] ERROR[7169] astobj2.c: bad magic number 0x0 for 0x8b1c3d0


[Aug  4 16:32:10] ERROR[31100] astobj2.c: bad magic number 0x0 for 0x6c13550
Then restaring
[Aug  4 16:32:15] VERBOSE[9142] config.c:   == Parsing '/etc/asterisk/asterisk.conf': [Aug  4 16:32:15] VERBOSE[9142] config.c:   == Found
Aug  4 20:04:14] VERBOSE[12064] app_macro.c:   == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/31251788117-0000000b' in macro 'hangupca$
[Aug  4 20:04:14] ERROR[12064] astobj2.c: bad magic number 0x0 for 0x30caff0
[Aug  4 20:04:19] VERBOSE[14199] config.c:   == Parsing '/etc/asterisk/asterisk.conf': [Aug  4 20:04:19] VERBOSE[14199] config.c:   == Found


[Aug  5 14:05:48] VERBOSE[5735] app_dial.c:     -- Called 31251788103
[Aug  5 14:05:48] ERROR[12953] astobj2.c: bad magic number 0x0 for 0x7f3cf40469b0
[Aug  5 14:05:52] VERBOSE[5748] config.c:   == Parsing '/etc/asterisk/asterisk.conf': [Aug  5 14:05:52] VERBOSE[5748] config.c:   == Found

etc
Comments:By: frank koster (notthematrix) 2010-08-05 08:00:17

processor : 0
vendor_id : AuthenticAMD
cpu family : 15
model : 107
model name : AMD Athlon(tm) 64 X2 Dual Core Processor 6000+
stepping : 2
cpu MHz : 3100.093
cache size : 512 KB
physical id : 0
siblings : 2
core id : 0
cpu cores : 2
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 1
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy 3dnowprefetch
bogomips : 6200.18
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc 100mhzsteps

processor : 1
vendor_id : AuthenticAMD
cpu family : 15
model : 107
model name : AMD Athlon(tm) 64 X2 Dual Core Processor 6000+
stepping : 2
cpu MHz : 3100.093
cache size : 512 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 1
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy 3dnowprefetch
bogomips : 6200.24
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc 100mhzsteps

Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Ubuntu 4.3.2-1ubuntu12' --with-bugurl=file:///usr/share/doc/gcc-4.3/README.Bugs --enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr --enable-shared --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --enable-nls --with-gxx-include-dir=/usr/include/c++/4.3 --program-suffix=-4.3 --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --enable-mpfr --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.3.2 (Ubuntu 4.3.2-1ubuntu12)

asterisk Connected to Asterisk SVN-branch-1.8-r280984

This also happens in earlyer versions....
By: Tilghman Lesher (tilghman) 2010-08-05 10:37:00

Thank you for your bug report. In order to move your issue forward, we require a backtrace from the core file produced after the crash. Please see the doc/backtrace.txt file in your Asterisk source directory.

Also, be sure you have DONT_OPTIMIZE enabled in menuselect within the Compiler Flags section, then:

make install

after enabling, reproduce the crash, and then execute the instructions in doc/backtrace.txt.

When complete, attach that file to this issue report. Thanks!
By: frank koster (notthematrix) 2010-08-05 15:25:21

Aug  5 22:18:58] ERROR[300] astobj2.c: bad magic number 0x31333135 for 0x7f750405f5e0

offcorce astobj2.c is located in main/astobj2.c
By: Leif Madsen (lmadsen) 2010-08-05 16:04:11

Backtrace required to move this issue forward.
By: frank koster (notthematrix) 2010-08-05 17:12:34

oke setup astyerisk now waiting for a crash so I can make the BT


By: frank koster (notthematrix) 2010-08-05 18:23:27

Made BT and BT full hope it solves this anoying bug soon...
Can only trigger this one  when more then 1 call is being done and I try to stress it be fireing multple in and outgoing calls at the same time...


By: snuffy (snuffy) 2010-08-05 21:17:06

We still need some more information..

1. the specific steps or actions you took that caused you to encounter the problem
2. configuration information such as dialplan (e.g. extensions.conf) and channel configuration (e.g. sip.conf).

Thanks!


By: frank koster (notthematrix) 2010-08-06 03:34:39

When one person is making a call start making calls randomly , if there are multiple calls then when a call is initaited or after hangup asterisk crashes...


here some exaples from log file...

[Aug  3 21:26:00] VERBOSE[7173] res_agi.c:     -- dialparties.agi: Filtered ARG3: 31251788103
[Aug  3 21:26:00] VERBOSE[7173] res_agi.c:     -- <Local/145131251788103@inttrunks-8f80;2>AGI Script dialparties.agi completed, returning 0
[Aug  3 21:26:00] VERBOSE[7173] pbx.c:     -- Executing [s@macro-dial:7] Dial("Local/145131251788103@inttrunks-8f80;2", "SIP/31251788103,"",tr") in new stack
[Aug  3 21:26:00] VERBOSE[7173] app_dial.c:     -- Called 31251788103
[Aug  3 21:26:00] VERBOSE[7170] app_dial.c:     -- Local/145131251788103@inttrunks-8f80;1 is ringing
[Aug  3 21:26:00] ERROR[7169] astobj2.c: bad magic number 0x0 for 0x8b1c3d0



[Aug  4 16:32:10] VERBOSE[9134] pbx.c:     -- Executing [14440000031202525406@inttrunks-pref:1] Set("Local/14440000031202525406@inttrunks-31fc;2", "CALLERID$
[Aug  4 16:32:10] VERBOSE[9134] pbx.c:     -- Executing [14440000031202525406@inttrunks-pref:2] NoOp("Local/14440000031202525406@inttrunks-31fc;2", "calleri$
[Aug  4 16:32:10] VERBOSE[9134] pbx.c:     -- Executing [14440000031202525406@inttrunks-pref:3] Dial("Local/14440000031202525406@inttrunks-31fc;2", "SIP/voi$
[Aug  4 16:32:10] VERBOSE[9134] app_dial.c:     -- Called voicetrade/0000031202525406
[Aug  4 16:32:10] ERROR[31100] astobj2.c: bad magic number 0x0 for 0x6c13550

[Aug  4 20:04:14] VERBOSE[12064] pbx.c:     -- Executing [s@macro-hangupcall:7] GotoIf("SIP/31251788117-0000000b", "1?theend") in new stack
[Aug  4 20:04:14] VERBOSE[12064] pbx.c:     -- Goto (macro-hangupcall,s,9)
[Aug  4 20:04:14] VERBOSE[12064] pbx.c:     -- Executing [s@macro-hangupcall:9] Hangup("SIP/31251788117-0000000b", "") in new stack
[Aug  4 20:04:14] VERBOSE[12064] app_macro.c:   == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/31251788117-0000000b' in macro 'hangupca$
[Aug  4 20:04:14] ERROR[12064] astobj2.c: bad magic number 0x0 for 0x30caff0

[Aug  5 13:13:49] VERBOSE[12456] pbx.c:     -- Executing [14440000031634041406@inttrunks-pref:2] NoOp("Local/14440000031634041406@inttrunks-212a;2", "caller$
[Aug  5 13:13:49] VERBOSE[12456] pbx.c:     -- Executing [14440000031634041406@inttrunks-pref:3] Dial("Local/14440000031634041406@inttrunks-212a;2", "SIP/vo$
[Aug  5 13:13:49] VERBOSE[12456] app_dial.c:     -- Called voicetrade/0000031634041406
[Aug  5 13:13:50] ERROR[8808] astobj2.c: bad magic number 0xdc0200a0 for 0x7f49dc00d350


[Aug  5 14:05:48] VERBOSE[5735] res_agi.c:     -- dialparties.agi: Filtered ARG3: 31251788103
[Aug  5 14:05:48] VERBOSE[5735] res_agi.c:     -- <SIP/81.201.82.45-00000017>AGI Script dialparties.agi completed, returning 0
[Aug  5 14:05:48] VERBOSE[5735] pbx.c:     -- Executing [s@macro-dial:7] Dial("SIP/81.201.82.45-00000017", "SIP/31251788103,"",tr") in new stack
[Aug  5 14:05:48] VERBOSE[5735] app_dial.c:     -- Called 31251788103
[Aug  5 14:05:48] ERROR[12953] astobj2.c: bad magic number 0x0 for 0x7f3cf40469b0

[Aug  5 14:39:34] VERBOSE[25779] pbx.c:     -- Executing [144400000559132790869@inttrunks-pref:2] NoOp("Local/144400000559132790869@inttrunks-5f50;2", "call$
[Aug  5 14:39:34] VERBOSE[25779] pbx.c:     -- Executing [144400000559132790869@inttrunks-pref:3] Dial("Local/144400000559132790869@inttrunks-5f50;2", "SIP/$
[Aug  5 14:39:34] VERBOSE[25779] app_dial.c:     -- Called voicetrade/00000559132790869
[Aug  5 14:39:34] ERROR[21966] astobj2.c: bad magic number 0x37313532 for 0x7ff92c4cbbc0
[Aug  5 14:39:34] ERROR[21966] astobj2.c: bad magic number 0x37313532 for 0x7ff92c4cbbc0


Aug  5 14:39:34] VERBOSE[25779] app_dial.c:     -- SIP/voicetrade-0000000d is making progress passing it to Local/144400000559132790869@inttrunks-5f50;2
[Aug  5 14:39:34] VERBOSE[25776] app_dial.c:     -- Local/144400000559132790869@inttrunks-5f50;1 is making progress passing it to SIP/31208081066-0000000c
[Aug  5 14:39:40] VERBOSE[25774] asterisk.c:     -- Remote UNIX connection disconnected
[Aug  5 14:39:47] ERROR[21966] astobj2.c: bad magic number 0x37313532 for 0x7ff92c4cbbc0
[Aug  5 14:39:47] ERROR[21966] astobj2.c: bad magic number 0x37313532 for 0x7ff92c4cbbc0



Aug  5 18:53:43] WARNING[892] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 18:53:43] WARNING[892] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 18:53:43] WARNING[892] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 18:53:43] WARNING[892] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 18:53:43] WARNING[892] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 18:53:43] ERROR[12470] astobj2.c: bad magic number 0x37313532 for 0x8a8e4f0

[Aug  5 19:39:15] VERBOSE[23419] app_dial.c:     -- Called 31251788103
[Aug  5 19:39:15] VERBOSE[23411] app_dial.c:     -- Local/145131251788103@inttrunks-359c;1 is ringing
[Aug  5 19:39:15] WARNING[23416] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 19:39:15] WARNING[23416] chan_sip.c: Asked to transmit frame type alaw, while native formats is 0x100 (g729) read/write = 0x100 (g729)/0x100 (g729)
[Aug  5 19:39:15] ERROR[1405] astobj2.c: bad magic number 0x6e616d6d for 0x7f2d325e1fc0
[Aug  5 19:39:19] VERBOSE[23430] config.c:   == Parsing '/etc/asterisk/asterisk.conf': [Aug  5 19:39:19] VERBOSE[23430] config.c:   == Found





So it look like it happends when initiating or hanging up....
By: frank koster (notthematrix) 2010-08-07 03:24:25

more info needed?
By: The Mike Kilburn (mkilburn60) 2010-08-09 03:06:51

This fixed it for me

in channel.c

<code removed>
(Please post code as an attachment to the bug, not in the comments)


By: frank koster (notthematrix) 2010-08-09 04:06:13

@mkilburn60
Thanks instyalled the patch let you know if it fixed it for me
By: frank koster (notthematrix) 2010-08-10 05:05:09

Asterisk ran for 24 huors whitout crashing...
so it looks like the problem is fixed...
call waiting is now also working 100% al the time...
So hope that aterisk-dev will be imlementing this little patch in beta3
By: Tilghman Lesher (tilghman) 2010-08-10 09:59:51

mkilburn60: please post the patch as an upload, not embedded in a note.
By: frank koster (notthematrix) 2010-08-11 17:05:42

Well if nobody makes the patch I do it......
so it finaly can be put in beta4?
By: The Mike Kilburn (mkilburn60) 2010-08-11 17:26:37

although the patch is valid (chan needs to be checked for null before calling string functions), its covering another problem.

I'm now seeing another crash, in free(), when the bad magic number pops up.

here is the trace:


#0  0x00889402 in __kernel_vsyscall ()
#1  0x00236d10 in raise () from /lib/libc.so.6
#2  0x00238621 in abort () from /lib/libc.so.6
#3  0x0026ee5b in __libc_message () from /lib/libc.so.6
#4  0x00276d06 in _int_free () from /lib/libc.so.6
ASTERISK-1  0x0027a1e0 in free () from /lib/libc.so.6
ASTERISK-2  0x080831d0 in internal_ao2_ref (user_data=0x34e140, delta=<value optimized out>) at astobj2.c:274
ASTERISK-3  0x080ab52b in ast_channel_release (chan=0x89bbcd0) at channel.c:1869
ASTERISK-4  0x001dfeb4 in custom_log (cdr=0x8797d18) at cdr_custom.c:168
ASTERISK-5  0x080a20fc in post_cdr (cdr=0x8797d18) at cdr.c:1136
ASTERISK-6 0x080a2335 in ast_cdr_detach (cdr=0x8797d18) at cdr.c:1332
ASTERISK-7 0x080ecb6c in ast_bridge_call (chan=0x862ce38, peer=0x8972318, config=0xb7756d24) at features.c:3452
ASTERISK-8 0x003f1b97 in dial_exec_full (chan=0x862ce38, data=<value optimized out>, peerflags=0xb7756e60, continue_exec=0x0) at app_dial.c:2632
ASTERISK-9 0x003f4199 in dial_exec (chan=0x862ce38, data=0xb7758f14 "SIP/+12104646723@Cloud9,60") at app_dial.c:2732
ASTERISK-10 0x081365ab in pbx_exec (c=0x862ce38, app=0x84fc9f8, data=0xb7758f14 "SIP/+12104646723@Cloud9,60") at pbx.c:1395
ASTERISK-11 0x081427ca in pbx_extension_helper (c=0x862ce38, con=0x0, context=0x862d1a0 "callcontroller_bleg_originate", exten=0x862d1f0 "s", priority=8, label=0x0, callerid=0x88b4570 "447872205930", action=E_SPAWN, found=0xb775b338, combined_find_spawn=1)
   at pbx.c:4070
ASTERISK-12 0x08148eb6 in ast_spawn_extension (c=0x862ce38, args=0x0) at pbx.c:4562
ASTERISK-13 __ast_pbx_run (c=0x862ce38, args=0x0) at pbx.c:4660
ASTERISK-14 0x0814ac60 in pbx_thread (data=0x862ce38) at pbx.c:4971
ASTERISK-15 0x0818836b in dummy_start (data=0x88d8dc0) at utils.c:971
ASTERISK-16 0x0038745b in start_thread () from /lib/libpthread.so.0
ASTERISK-17 0x002dee5e in clone () from /lib/libc.so.6
By: Alec Davis (alecdavis) 2010-08-11 17:49:45

I'm sure local channel masquarade is causing your problems.

from ASTERISK-15819 try using the '/n' switch like below.
exten => _1XXXX,n,Dial(Local/num@context/n,,r)

But don't give up, the above is only a workaround.
By: Tilghman Lesher (tilghman) 2010-08-11 23:16:08

mkilburn60:  that's a classic example of a backtrace in the case of memory corruption.  We require valgrind output in order to move this issue forward.

Please see the doc/valgrind.txt file in your Asterisk source directory for more information about how to produce debugging information. Thanks!
By: The Mike Kilburn (mkilburn60) 2010-08-12 00:26:26

tilghman - yes, memory corruption was the assumption. I'll have a look at the valgrind.txt file.
By: Alec Davis (alecdavis) 2010-09-17 15:30:12

I see your using the localchan, which has problems when calls are being optimized out. Thus using the /n switch on the end of the number may be a workaround for the problem.

ASTERISK-14975 diff3 patch may fix this issue too. Please test and feedback
By: Alec Davis (alecdavis) 2010-09-20 05:14:46

bug17801.diff1.txt defer unlocking the channels ao2_container till the very end of ast_do_masquerade.
Otherwise with no lock on the 'channels' ao2_container and releasing the locks on 'original and clonechan' channel before the linking back into ao2_container we get corrupted.

Also tried in ast_do_masquerade@done: the following, observing required locking order - but no better :
  unlock both channels
  ao2_lock(channels)
  lock both channels
  unlock both channels  (we should now be ok to ao2_link(channels, XXX)
  ao2_link(channels, original)
  ao2_link(channels, clonechan)
  ao2_unlock(channels)


By: Digium Subversion (svnbot) 2010-09-20 17:21:52

Repository: asterisk
Revision: 287661

U   branches/1.8/main/channel.c

------------------------------------------------------------------------
r287661 | alecdavis | 2010-09-20 17:21:51 -0500 (Mon, 20 Sep 2010) | 14 lines

ast_do_masquerade. Keep channels ao2_container locked while unlink and linking channels.

Previously, Masquerade would unlock 'original' and 'clonechan' and allow another masq thread to run.
End result would be corrupted memory, and the frequent report 'Bad Magic Number'.

(closes issue ASTERISK-16512,ASTERISK-16428)
Reported by: notthematrix
Patches:
     Based on bug17801.diff1.txt uploaded by alecdavis (license 585)
Tested by: alecdavis

Review: https://reviewboard.asterisk.org/r/928


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=287661
By: Digium Subversion (svnbot) 2010-09-20 17:24:53

Repository: asterisk
Revision: 287671

_U  trunk/
U   trunk/main/channel.c

------------------------------------------------------------------------
r287671 | alecdavis | 2010-09-20 17:24:52 -0500 (Mon, 20 Sep 2010) | 20 lines

Merged revisions 287661 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.8

........
 r287661 | alecdavis | 2010-09-21 10:21:50 +1200 (Tue, 21 Sep 2010) | 14 lines
 
 ast_do_masquerade. Keep channels ao2_container locked while unlink and linking channels.
 
 Previously, Masquerade would unlock 'original' and 'clonechan' and allow another masq thread to run.
 End result would be corrupted memory, and the frequent report 'Bad Magic Number'.
 
 (closes issue ASTERISK-16512,ASTERISK-16428)
 Reported by: notthematrix
 Patches:
       Based on bug17801.diff1.txt uploaded by alecdavis (license 585)
 Tested by: alecdavis
 
 Review: https://reviewboard.asterisk.org/r/928
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=287671