[Home]

Summary:ASTERISK-13795: Crash using func_odbc
Reporter:Sebastian Gutierrez (sum)Labels:
Date Opened:2009-03-21 13:33:55Date Closed:2009-04-02 10:15:23
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Functions/func_odbc
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 1.malloc_debug.txt
( 1) 1.valgrindMALLOCDEBUG.txt
( 2) 2.valgrind.txt
( 3) 20090322__bug14716.diff.txt
( 4) 20090402__bug14716.diff.txt
( 5) malloc_debug162.txt
( 6) valgrind.txt
( 7) valgrind162.txt
Description:
Crash using func_odbc

1) with don't optimize it doesn't crash
2) with debug malloc realtime stop working with this error:

Connected to Asterisk 1.6.2.0-beta1 currently running on localhost (pid = 16736)
Verbosity was 3 and is now 4
failed to extend from 16 to 63
failed to extend from 16 to 43
[Mar 21 00:31:07] WARNING[16755]: res_config_mysql.c:369 realtime_mysql: MySQL RealTime: Failed to query database: Query was empty
failed to extend from 16 to 63
[Mar 21 00:31:07] WARNING[16755]: res_config_mysql.c:369 realtime_mysql: MySQL RealTime: Failed to query database: Query was empty
[Mar 21 00:31:07] NOTICE[16755]: chan_sip.c:20367 handle_request_register: Registration from '"1001"<sip:1001@192.168.175.133>' failed for '192.168.175.1' - No matching peer found


Tell me if you need valgrind file of the run without crashing, or any other info.
Comments:By: Sebastian Gutierrez (sum) 2009-03-21 14:58:34

UPDATE: 1) with dont't optimize doesn't crash if I start it with valgrind, if I started it with safe_asterisk for example, it crashes too.
By: Tilghman Lesher (tilghman) 2009-03-22 02:19:31

Yes, I need the valgrind output, regardless of whether it crashed or not.
By: Sebastian Gutierrez (sum) 2009-03-22 08:28:31

I've uploaded valgrind, tell me if you need more info or test something.
By: Tilghman Lesher (tilghman) 2009-03-22 11:24:55

Patch uploaded.  This has worked for me in a branch that I'm working on, although it was not yet merged.  Please check and ensure that it works for you.
By: Sebastian Gutierrez (sum) 2009-03-22 12:37:01

Patch applyed succesfuly:

Results:

(Optimized)
firts call works ok retrieving the values from the query, but the second made asterisk crash again.

(Don't Optimize and malloc debug)
Still not working realtime I attach valgrind ( check: 1.malloc_debug.txt, 1.valgrindMALLOCDEBUG.txt)

(Don't Optimize)
Still not crashing asterisk, I attach valgrind (check 2.valgrind.txt)


By: Private Name (falves11) 2009-03-25 18:28:25

It looks similar to my bug 14753, but please note that with version 1.6.1
SVN-branch-1.6.1-r184345 it does not crash, only with Trunk. Also I am using freetds and Sybase, but that seems to be unrelated. I checked and the driver does send the query and gets a respnse.
By: Sebastian Gutierrez (sum) 2009-03-25 18:31:14

try as I did, with don't optimzed and starting asterisk with valgrind, if it doesn't crash seems to be the same problem, and this two bugs should be related.
By: Tilghman Lesher (tilghman) 2009-03-26 10:44:56

sum:  I'm glad you're able to diagnose two issues as being related.  Perhaps you could also come up with a patch, since you're able to clearly relate two issues together, where I find no conclusive evidence.
By: Sebastian Gutierrez (sum) 2009-03-26 11:06:22

was a suggestion and not an afirmation, I just wanted to get more info about the problem, I'm here to help, I saw the other issue and seems the same as I was experimenting, I'm also executing a Store Procedure and the backtrace looks very similar (the difference I can see is he is using 64bit Os and I don't):

(gdb) bt
#0  0x009cf127 in _int_realloc () from /lib/libc.so.6
#1  0x009d0377 in realloc () from /lib/libc.so.6
#2  0x08151524 in _ast_realloc (p=0x95b1de8, len=51, file=0x81adf74 "/usr/src/asterisk-1.6.2.0-beta1/include/asterisk/strings.h", lineno=561,
   func=0x81adfb7 "ast_str_make_space") at /usr/src/asterisk-1.6.2.0-beta1/include/asterisk/utils.h:493
#3  0x08151ab3 in ast_str_make_space (buf=0xb70c7aa8, new_len=39) at /usr/src/asterisk-1.6.2.0-beta1/include/asterisk/strings.h:539
#4  0x0814417a in __ast_str_helper (buf=0xb70c7aa8, max_len=0, append=1, fmt=0x152d9c6 ",", ap=0xb70c778c "") at strings.c:92
ASTERISK-1  0x08151bcd in ast_str_append_va (buf=0xb70c7aa8, max_len=0, fmt=0x152d9c6 ",", ap=0xb70c778c "") at /usr/src/asterisk-1.6.2.0-beta1/include/asterisk/strings.h:749
ASTERISK-2  0x08151d0f in ast_str_append (buf=0xb70c7aa8, max_len=0, fmt=0x152d9c6 ",") at /usr/src/asterisk-1.6.2.0-beta1/include/asterisk/strings.h:821
ASTERISK-3  0x015293c9 in acf_odbc_read (chan=0x95b6f18, cmd=0xb70c7b50 "ODBC_MSSQL", s=0xb70c7b5b "IVR_TEST_Asterisk 1001", buf=0xb70c7c00 "1,0", len=4096)
   at func_odbc.c:545
ASTERISK-4  0x080fd0ac in ast_func_read (chan=0x95b6f18, function=0xb70c8c10 "ODBC_MSSQL(IVR_TEST_Asterisk 1001)", workspace=0xb70c7c00 "1,0", len=4096) at pbx.c:3346
ASTERISK-5  0x080fd5ed in pbx_substitute_variables_helper_full (c=0x95b6f18, headp=0x95b7030, cp1=0x9570750 "HASH(Cliente)=${ODBC_MSSQL(IVR_TEST_Asterisk ${ANI})}",
   cp2=0xb70cce96 "", count=8177, used=0xb70cad24) at pbx.c:3481
ASTERISK-6 0x080fdb91 in pbx_substitute_variables_helper (c=0x95b6f18, cp1=0x9570750 "HASH(Cliente)=${ODBC_MSSQL(IVR_TEST_Asterisk ${ANI})}",
   cp2=0xb70cce88 "HASH(Cliente)=", count=8191) at pbx.c:3576
ASTERISK-7 0x080fdc71 in pbx_substitute_variables (passdata=0xb70cce88 "HASH(Cliente)=", datalen=8192, c=0x95b6f18, e=0x9570798) at pbx.c:3599
ASTERISK-8 0x080fde99 in pbx_extension_helper (c=0x95b6f18, con=0x0, context=0x95b7188 "outgoing", exten=0x95b71d8 "141", priority=11, label=0x0, callerid=0x95b10e8 "1001",
   action=E_SPAWN, found=0xb70cf2dc, combined_find_spawn=1) at pbx.c:3661
ASTERISK-9 0x080ff440 in ast_spawn_extension (c=0x95b6f18, context=0x95b7188 "outgoing", exten=0x95b71d8 "141", priority=11, callerid=0x95b10e8 "1001", found=0xb70cf2dc,
   combined_find_spawn=1) at pbx.c:4137
ASTERISK-10 0x080ffacc in __ast_pbx_run (c=0x95b6f18, args=0x0) at pbx.c:4227
ASTERISK-11 0x08100f54 in pbx_thread (data=0x95b6f18) at pbx.c:4514
ASTERISK-12 0x081525cf in dummy_start (data=0x95b6ab8) at utils.c:968
ASTERISK-13 0x0058946b in start_thread () from /lib/libpthread.so.0
ASTERISK-14 0x00a34dbe in clone () from /lib/libc.so.6


By: Tilghman Lesher (tilghman) 2009-03-26 11:21:06

That backtrace means you have memory corruption.  Valgrind is the normal tool for tracking down corruption, and it is very normal for valgrind to prevent crashes, as it is intercepting memory accesses and evaluating them for correctness.  Just because two different people running valgrind see that valgrind prevents the crash does NOT mean the crashes are related.  Please don't make managing this issue more complicated than it needs to be by drawing unfounded conclusions and expecting the bug marshals to follow that red herring.
By: John Hass (john8675309) 2009-03-30 12:36:30

I can confirm this bug as well.

right when I do a call to func_odbc:

testbridge16*CLI> *** glibc detected *** /usr/sbin/asterisk: realloc(): invalid next size: 0x00007fbf4012fef0 ***
======= Backtrace: =========
/lib/libc.so.6[0x7fbf488c5138]
/lib/libc.so.6[0x7fbf488c9041]
/lib/libc.so.6(realloc+0x12f)[0x7fbf488c9d9f]
/usr/sbin/asterisk(__ast_str_helper+0x21a)[0x4f1e0a]
/usr/sbin/asterisk(ast_str_append+0x89)[0x4ff159]
/usr/lib/asterisk/modules/func_odbc.so[0x7fbf356e287b]
/usr/sbin/asterisk(ast_func_read+0xfb)[0x4b8b4b]
/usr/sbin/asterisk(pbx_substitute_variables_helper_full+0x2fa)[0x4be5aa]
/usr/sbin/asterisk(pbx_substitute_variables_helper+0x2a)[0x4bec6a]
/usr/lib/asterisk/modules/pbx_realtime.so[0x7fbf24b237ec]
/usr/sbin/asterisk[0x4c14c7]
/usr/sbin/asterisk[0x4c2e3c]
/usr/sbin/asterisk[0x4c428b]
/usr/sbin/asterisk[0x4fea9c]
/lib/libpthread.so.0[0x7fbf4a60d017]


Let me know what I can do to help.
By: Tilghman Lesher (tilghman) 2009-03-30 14:24:44

john8675309: as stated in the previous bugnote, this is memory corruption.  The ONLY useful information that can be provided is with valgrind.  Please see doc/valgrind.txt.
By: Tilghman Lesher (tilghman) 2009-03-30 14:28:48

sum:  in the original report, you noted that when you started with malloc debug, realtime failed for you.  What branch of asterisk-addons are you using, since there is no branch of 1.6.2 for asterisk-addons?
By: Sebastian Gutierrez (sum) 2009-03-30 14:31:36

asterisk-addons-1.6.1.0-rc3.tar.gz

they seem to be the addons that should be with this version regarding the mail send with the releases, isn't it?
By: Tilghman Lesher (tilghman) 2009-03-30 14:57:20

sum: Not if you're testing 1.6.2, it shouldn't be.
By: Sebastian Gutierrez (sum) 2009-03-30 16:07:47

so which version should I use, let me know and I'll make a test.

Quoting mail: Asterisk 1.6.0.7-rc2, 1.6.1.0-rc3, 1.6.2.0-beta1 & Asterisk-Addons 1.6.0.2-rc1, 1.6.1.0-rc3 Now Available:

"Note that the 1.6.1 series of Asterisk-Addons is compatible with both Asterisk 1.6.1 and 1.6.2 branches."


By: Tilghman Lesher (tilghman) 2009-03-31 10:04:05

Yeah, that was a mistake on the part of the release manager.  He is working on making a 1.6.2 release candidate of addons today.

For the time being, you can use trunk, although it is up for API changes in the future.


By: Sebastian Gutierrez (sum) 2009-03-31 10:30:02

I'll wait to 1.6.2 addons, and I'll give feedback on the issue.
Tell me what tests you requiere when I have 1.6.2 addons, so I can make a full test and give you the right info to solve this issue.
By: Leif Madsen (lmadsen) 2009-04-01 16:25:24

Asterisk-Addons 1.6.2.0-beta1 is now available.
By: Sebastian Gutierrez (sum) 2009-04-01 17:01:47

The problem is solved with addons 1.6.2, any idea why? do you want any debug information to check everything is ok??
By: Private Name (falves11) 2009-04-01 17:17:27

My 1.6.1 SVN 185779 crashes daily. I just compiled it with no_optimze, but I cannot use valgrind in production. I don't use addons. My backend is freetds. Something else is wrong: if I use "realtime" in asterisk.conf, and it blows up, safe_asterisk is not safe anymore, for it does not come back automatically
By: Tilghman Lesher (tilghman) 2009-04-01 17:24:44

sum:  I suspect the issue here was version skew.  One or more APIs was not compatible between branches, and unfortunately, you only found this out through the crash.  Unless you still have this issue, I'm going to suggest closing this one out.
By: Sebastian Gutierrez (sum) 2009-04-01 17:26:35

I agree.
By: Sebastian Gutierrez (sum) 2009-04-01 17:36:19

bad news, I try again but this time without dont optimize and debug malloc flags, and start crashing again this is the bt:
(gdb) bt
#0  0x009cf127 in _int_realloc () from /lib/libc.so.6
#1  0x009d0377 in realloc () from /lib/libc.so.6
#2  0x08140525 in __ast_str_helper (buf=0xb6fa3d44, max_len=0, append=1,
   fmt=0x6f28ac3 ",", ap=0xb6fa3a0c "")
   at /usr/src/integra/asterisk-1.6.2.0-beta1/include/asterisk/utils.h:493
#3  0x0814d6a1 in ast_str_append (buf=0xb6fa3d44, max_len=0, fmt=0x6f28ac3 ",")
   at /usr/src/integra/asterisk-1.6.2.0-beta1/include/asterisk/strings.h:749
#4  0x06f26ee5 in acf_odbc_read (chan=0x86c07a0, cmd=0xb6fa3d80 "ODBC_MSSQL",
   s=0xb6fa3d8b "IVR_chequearcliente_Asterisk 1001", buf=0xb6fa3e00 "1,0",
   len=4096) at func_odbc.c:545
ASTERISK-1  0x08100b50 in ast_func_read (chan=0x86c07a0,
   function=0xb6fa4e10 "ODBC_MSSQL(IVR_chequearcliente_Asterisk 1001)",
   workspace=0xb6fa3e00 "1,0", len=4096) at pbx.c:3346
ASTERISK-2  0x0810724d in pbx_substitute_variables_helper_full (c=0x86c07a0,
   headp=0x86c08b8,
   cp1=0x8675ec0 "HASH(Cliente)=${ODBC_MSSQL(IVR_chequearcliente_Asterisk ${ANI})}", cp2=0xb6fa8ef2 "", count=8177, used=0xb6fab198) at pbx.c:3481
ASTERISK-3  0x08107aea in pbx_extension_helper (c=0x86c07a0, con=0x0,
   context=0x86c0a10 "outgoing", exten=0x86c0a60 "141", priority=11,
   label=0x0, callerid=0x86c0f98 "1001", action=E_SPAWN, found=0xb6fab328,
   combined_find_spawn=1) at pbx.c:3576
ASTERISK-4  0x0810a214 in __ast_pbx_run (c=0x86c07a0, args=0x0) at pbx.c:4137
ASTERISK-5  0x0810bd90 in pbx_thread (data=0x86c07a0) at pbx.c:4514


Do you want valgrind info with malloc debug although it doesn't crash?
By: Tilghman Lesher (tilghman) 2009-04-01 17:45:32

sum: were you running with or without the patch already attached to this issue?  If not, please update to current SVN 1.6.2 and try again.
By: Private Name (falves11) 2009-04-01 20:08:46

I tried to install 1.6.2 SVN and It does not even load, what can I do? 1.6.1 is unstable.
CDR simple logging enabled.
36 modules will be loaded.
[Apr  1 19:21:01] .[Apr  1 19:21:01] .[Apr  1 19:21:01] .[Apr  1 19:21:01] .[Apr  1 19:21:01] SIP channel loading...
Cannot find variable 'SIPPEER' in tree 'description'
Cannot find variable 'SIPCHANINFO' in tree 'description'
[Apr  1 19:21:01] .  == H.323 listener started
[Apr  1 19:21:01] .Segmentation fault (core dumped)
By: Sebastian Gutierrez (sum) 2009-04-01 22:03:07

Version: Asterisk SVN-branch-1.6.2-r185947
Addons: 1.6.2 beta1
Status: crash

Without setting compiler flags: crash astersik, using valgrind doesn't crash
with malloc debug and dont optimize: doesn't crash uploaded results.

Uploaded: valgrind162, mallocdebug162
By: Tilghman Lesher (tilghman) 2009-04-02 00:51:42

sum:  I replicated the issue and tracked down the problem.  Patch uploaded.
By: Private Name (falves11) 2009-04-02 01:11:21

This command fails:
wget 'http://bugs.digium.com/file_download.php?file_id=22163&type=bug' -O - | patch -p0

Also, where do I need to located to apply the patch?

what would the command be once we get the file downloaded/
By: Private Name (falves11) 2009-04-02 01:26:19

I made it compile after applying the patch, but I still get this error:
== Registered custom function 'SIP_HEADER'
[Apr  2 02:19:23] DEBUG[15961]: xmldoc.c:1718 xmldoc_build_field: Cannot find variable 'SIPPEER' in tree 'description'
 == Registered custom function 'SIPPEER'
[Apr  2 02:19:23] DEBUG[15961]: xmldoc.c:1718 xmldoc_build_field: Cannot find variable 'SIPCHANINFO' in tree 'description'
 == Registered custom function 'SIPCHANINFO'
 == Registered custom function 'CHECKSIPDOMAIN'

is it irrelevant?
By: Michiel van Baak (mvanbaak) 2009-04-02 02:19:27

falves11: no, those debug lines are not related.
They are related to the xml documentation. Clearly those two function are not documented.
By: Private Name (falves11) 2009-04-02 02:24:05

I will post the result of the test tomorrow when traffic picks up. Many thanks.
By: Sebastian Gutierrez (sum) 2009-04-02 07:43:17

is not crashing anymore without the compilers flags. these seems fixed, maybe falves11 can give more feedback if he has more traffic. thnks!
By: Tilghman Lesher (tilghman) 2009-04-02 10:07:34

Given that falves11 has a completely different issue, I'm closing this one out.
By: Digium Subversion (svnbot) 2009-04-02 10:14:23

Repository: asterisk
Revision: 186021

U   trunk/main/strings.c

------------------------------------------------------------------------
r186021 | tilghman | 2009-04-02 10:14:23 -0500 (Thu, 02 Apr 2009) | 7 lines

Missed a common case for needing to extend the buffer.
(closes issue ASTERISK-13795)
Reported by: sum
Patches:
      20090402__bug14716.diff.txt uploaded by tilghman (license 14)
Tested by: sum

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

http://svn.digium.com/view/asterisk?view=rev&revision=186021
By: Digium Subversion (svnbot) 2009-04-02 10:15:22

Repository: asterisk
Revision: 186022

_U  branches/1.6.2/
U   branches/1.6.2/main/strings.c

------------------------------------------------------------------------
r186022 | tilghman | 2009-04-02 10:15:22 -0500 (Thu, 02 Apr 2009) | 14 lines

Merged revisions 186021 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r186021 | tilghman | 2009-04-02 10:14:22 -0500 (Thu, 02 Apr 2009) | 7 lines
 
 Missed a common case for needing to extend the buffer.
 (closes issue ASTERISK-13795)
  Reported by: sum
  Patches:
        20090402__bug14716.diff.txt uploaded by tilghman (license 14)
  Tested by: sum
........

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

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