ASTERISK-10522: several crashes in Trunk using cdr_odbc and func_odbc with SQL Server. fretds 0.64 (latest)

[Home]

Summary: ASTERISK-10522: several crashes in Trunk using cdr_odbc and func_odbc with SQL Server. fretds 0.64 (latest)

Reporter: Private Name (falves11) Labels:

Date Opened: 2007-10-14 00:02:24 Date Closed: 2007-10-22 11:43:58

Priority: Critical Regression? No

Status: Closed/Complete Components: CDR/cdr_odbc

Versions: Frequency of
Occurrence

Related
Issues:

Environment: Attachments: ( 0) bt_full.txt
( 1) bt_full1.txt
( 2) bt_full2.txt
( 3) bt_full3.txt
( 4) digium_crash2.txt
( 5) digium_crashes.txt

Description: #0 0xb6f11ab1 in tds_open_socket (tds=0x0, ip_addr=0x0, port=0, timeout=0) at net.c:242
242 tds_client_msg(tds->tds_ctx, tds, 20003, 9, 0, 0, "SQL Server connection timed out.");
(gdb) bt
#0 0xb6f11ab1 in tds_open_socket (tds=0x0, ip_addr=0x0, port=0, timeout=0) at net.c:242

#0 0x00000017 in ?? ()
(gdb) bt
#0 0x00000017 in ?? ()
#1 0x08790980 in ?? ()
#2 0x00000001 in ?? ()
#3 0xb0e641a8 in ?? ()
#4 0xb6f01de1 in tds_flush_packet (tds=Cannot access memory at address 0x30e04188
) at write.c:291
Previous frame inner to this frame (corrupt stack?)

#0 tds_flush_packet (tds=Cannot access memory at address 0x108
) at write.c:298
298 }
(gdb) bt
#0 tds_flush_packet (tds=Cannot access memory at address 0x108
) at write.c:298
Cannot access memory at address 0x100

#0 0xb6f11b2b in tds_open_socket (tds=0x0, ip_addr=0x0, port=1433, timeout=90000) at net.c:250
250 if (getsockopt(tds->s, SOL_SOCKET, SO_ERROR, (char *) &len, &optlen) != 0) {
(gdb) bt
#0 0xb6f11b2b in tds_open_socket (tds=0x0, ip_addr=0x0, port=1433, timeout=90000) at net.c:250
#1 0x00000000 in ?? ()
(gdb)

#0 0xb6f11b2b in tds_open_socket (tds=0x0, ip_addr=0x0, port=1433, timeout=90000) at net.c:250
250 if (getsockopt(tds->s, SOL_SOCKET, SO_ERROR, (char *) &len, &optlen) != 0) {
(gdb) bt
#0 0xb6f11b2b in tds_open_socket (tds=0x0, ip_addr=0x0, port=1433, timeout=90000) at net.c:250
#1 0x00000000 in ?? ()
(gdb)

quit

****** ADDITIONAL INFORMATION ******

My machine is open to inspection on request

Comments: By: Private Name (falves11) 2007-10-14 09:14:12

Fresh from this morning

#0 0xb6f5ba88 in SQLNumResultCols () from /usr/lib/libodbc.so.1
#1 0xb6ecc13f in acf_odbc_read (chan=0xb647af18, cmd=0xb660bc60 "MINIXEL_ROUTING", s=0xb660bc70 "S208-1192367328.1397", buf=0xb660bd40 "", len=4096) at func_odbc.c:312
#2 0x080cc09a in ast_func_read (chan=0xb647af18,
function=0xb660cd50 "MINIXEL_ROUTING(S208-1192367328.1397,209.237.252.94,15206421013,5206860418,<sip:5206860418@209.237.252.94>;party=calling;screen=yes;privacy=off)", workspace=0xb660bd40 "", len=4096)
at pbx.c:1586
#3 0x080d2705 in pbx_substitute_variables_helper_full (c=0xb647af18, headp=0xb647b264, cp1=0x8248030 "ARRAY(ANI,X,Nohunt,Delay)=${MINIXEL_ROUTING(${UNIQUEID},${SIPIP},${EXTEN},${anix},${cnum})}",
cp2=0xb6612faa "", count=8165) at pbx.c:1718
#4 0x080d678b in pbx_extension_helper (c=0xb647af18, con=Variable "con" is not available.
) at pbx.c:1810
ASTERISK-1 0x080d7dcf in __ast_pbx_run (c=0xb647af18) at pbx.c:2397
ASTERISK-2 0x080da29e in pbx_thread (data=0xb647af18) at pbx.c:2752
ASTERISK-3 0x0810f245 in dummy_start (data=0x1) at utils.c:807
ASTERISK-4 0xb7eaa3cc in start_thread () from /lib/tls/libpthread.so.0
ASTERISK-5 0xb71ffc3e in clone () from /lib/tls/libc.so.6
By: Tilghman Lesher (tilghman) 2007-10-14 13:03:07

I need a 'bt full' (as an upload, please) and I need to see the contents of the [ROUTING] context in func_odbc.conf. My inclination, though, is that this is an error in the FreeTDS routines, given where all of the above crashes occur.
By: Tilghman Lesher (tilghman) 2007-10-14 18:51:24

Uh, no. When I said I needed a 'bt full', I need the WHOLE thing, not a segmented portion.
By: Private Name (falves11) 2007-10-14 21:01:22

Dear Corydon76
Please send detailed instructions on how to do what you need. My email is falves1 at hotmail
it is crashing now every 5 minutes, because the traffic is picking up. I am going to replace it with the old perl technology until we find the bug
By: Tilghman Lesher (tilghman) 2007-10-14 22:34:57

Run exactly the same command, but post the ENTIRE output, not just the first frame.
By: Private Name (falves11) 2007-10-14 22:44:08

Dear Corydon76
I am posting all I get. if you look at the latest upload, I posted a bunch of useless lines and all the output that get when I type bt full
This is the command:
gdb /usr/sbin/asterisk core.8152

and I get only this
Reading symbols from /usr/lib/asterisk/modules/res_realtime.so...done.
Loaded symbols for /usr/lib/asterisk/modules/res_realtime.so
#0 0xb6f4bca7 in SQLDescribeCol () from /usr/lib/libodbc.so.1
(gdb) bt full
#0 0xb6f4bca7 in SQLDescribeCol () from /usr/lib/libodbc.so.1
No symbol table info available.
#1 0xb6ecc711 in acf_odbc_read (chan=0x82c7950, cmd=0xb622ec60 "MINIXEL_ROUTING", s=0xb622ec70 "S208-1192411686.2653", buf=0xb622ed40 "9122188444,SIP/19124224052@69.67.248.28\\,90\\,L(5400000),", len=4096)
at func_odbc.c:349
res1 = Variable "res1" is not available.
(gdb) quit

Please contact me via email and you may log into the box and research the issue. I had to take it out of production. Another weird fact is that I cannot make AGi work on this box. The dialplan line exten => _X,1,agi,anything.pl does not work.
By: Tilghman Lesher (tilghman) 2007-10-15 01:48:30

The reason why AGI is not working is that you're using really old syntax that has been deprecated since before 1.0 and has been removed in trunk. The correct syntax is AGI(script.pl).

In terms of what gdb is giving you, I've never seen that issue from gdb before. Either there's something very wrong with your package of gdb, or you have massive memory corruption on your system.

I can't commit to looking at your system this week, but if you'd like a bug marshal to look at your system, please request assistance in #asterisk-bugs on irc.freenode.net.
By: Tilghman Lesher (tilghman) 2007-10-15 12:52:08

Just a thought, but are you using "pooling=yes" in res_odbc.conf? If you aren't, you really should be.
By: Private Name (falves11) 2007-10-15 16:34:41

I changed the option to pooling=yes in res_config.odbc, and since then it crashed around 40 times when I was out of the office. The latest file represents the bt full for the post pooling option. I recompiled asterisk without optimization as instructed.
By: Private Name (falves11) 2007-10-16 14:47:35

I hereby request that this bug be reassigned to another bug marshall, if possible.
By: Tilghman Lesher (tilghman) 2007-10-16 15:24:25

This does appear to be an issue in FreeTDS, itself. I recommend that you report these issues to the upstream provider of your package.
By: Private Name (falves11) 2007-10-17 15:16:47

It seems that the bug is located at the point when the dialplan executes this line, which is perfectly correct but it generates an exception in the database
exten => h,1,Set(MINIXEL_ROUTING(${UNIQUEID})=${CDR(billsec)})

the term ${CDR(billsec)} returns ")" and not a number.
By: Tilghman Lesher (tilghman) 2007-10-17 15:29:33

No, it's actually returning "". CDR(billsec) is not actually calculated until the end of the call, which is why it's returning blank. You should only be referencing it in the 'h' extension.
By: Private Name (falves11) 2007-10-17 15:51:41

Thanks for the input. I am exactly doing that, i mean, if you look at my post, theextension is h,1. But it's ok, I am getting CDR(answer) and CDR(start) so I can calculate CDR(billsec) and CDR(duration) in the database.
By: Private Name (falves11) 2007-10-18 17:32:35

#0 0x080847d6 in ast_waitfor_nandfds_complex (c=0xb5480d70, n=2, ms=0xb5481cf8) at channel.c:1921
1921 ast_clear_flag(winner, AST_FLAG_EXCEPTION);
(gdb) bt full
#0 0x080847d6 in ast_waitfor_nandfds_complex (c=0xb5480d70, n=2, ms=0xb5481cf8) at channel.c:1921
__p = 16
__x = 0
aed = (struct ast_epoll_data *) 0x893d200
start = {tv_sec = 1192747301, tv_usec = 950168}
res = 1
i = 0
ev = {{events = 1, data = {ptr = 0x893d200, fd = 143905280, u32 = 143905280, u64 = 6605803606528}}, {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0,
u64 = 0}} <repeats 24 times>}
whentohangup = 0
diff = -1253569592
rms = 89998
now = -1253569592
winner = (struct ast_channel *) 0x4
__PRETTY_FUNCTION__ = "ast_waitfor_nandfds_complex"
#1 0x08084955 in ast_waitfor_nandfds (c=0xb5480d70, n=2, fds=0x0, nfds=0, exception=0x0, outfd=0x0, ms=0xb5481cf8) at channel.c:1949
No locals.
#2 0x0808499c in ast_waitfor_n (c=0xb5480d70, n=2, ms=0xb5481cf8) at channel.c:1955
No locals.
#3 0xb6b2028b in wait_for_answer (in=0x841ca40, outgoing=0xb3885cd8, to=0xb5481cf8, peerflags=0xb5481d48, pa=0xb5481510, num_in=0xb5481ce0,
result=0xb5481500) at app_dial.c:614
o = (struct chanlist *) 0x0
pos = 2
numlines = 1
winner = (struct ast_channel *) 0x841c500
watchers = {0x841ca40, 0xb380e578, 0x0 <repeats 22 times>, 0xb71954e4, 0xb71954e4, 0x0, 0xb71954e4, 0xb5480e30, 0xb5480e0c, 0xb725dff4, 0xb5480e3c,
0xb5480e18, 0xb7196901, 0xb5480e3c, 0xb3886a99, 0xb3886bcb, 0x0, 0xb3886bcb, 0xb725dff4, 0xb6942fc2, 0xb71a0b61, 0x5f480f28, 0xb6b2d29c, 0xab227498,
0x5b1700, 0xb5480e68, 0x806c796, 0x2e, 0x841cc18, 0xb5480e3c, 0xfbad8001, 0xb3886a99, 0x0, 0x820a828, 0x820a828, 0x370, 0x0, 0xb3886a99, 0xb6b2d29c,
0xb380e578, 0xb3885cd8, 0xb5480e88, 0x80c67b0, 0x0, 0x0, 0x2, 0xb3886a5f, 0x81eec80, 0x0, 0xb5480ef8, 0x80c6a64, 0x81ee2b0, 0x81ee310, 0x2, 0x0, 0x0,
0xffffffff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xb725dc00, 0xb725da20, 0x0, 0xb725dff4, 0xb725da20, 0xb3885cd8, 0xb6b2d29c, 0x80c60b7, 0x816f9c0, 0x0,
0xb5480ef8, 0x80d55d1, 0x816f9c0, 0xb6b2d29c, 0xb5481168, 0x80c9997, 0x841ca40, 0x0, 0xb5480f30, 0x841cbc8, 0x841cc18, 0xffffffff, 0x0, 0x815543d, 0x2,
0xb3885cd8, 0xb5480f58, 0x810c0ac, 0x81ee304, 0x0 <repeats 70 times>, 0xb71986a4, 0x0 <repeats 30 times>, 0xb7197d44, 0x0, 0x0, 0x0, 0x0, 0x0, 0x50, 0x0,
0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0xb725dff4, 0xb3800010, 0xb5481158, 0x807dd6e, 0xb389aeaa, 0xb387df72, 0x46, 0xb725dff4, 0x1, 0xb6b2a740, 0x0, 0xb387df68,
0x0, 0xb6b2a740, 0x1, 0x0, 0xb387df68, 0x0, 0xb387df68, 0xb7161cfb, 0x1, 0xb387df68, 0xb5481178, 0x807ddb1, 0xb300ae50, 0xb380e578, 0xb724a3c0, 0x0}
num = {chan = 0x841ca40, busy = 0, congestion = 0, nochan = 0}
prestart = 0
orig = 90000
peer = (struct ast_channel *) 0x0
single = 1
epollo = (struct chanlist *) 0x0
__PRETTY_FUNCTION__ = "wait_for_answer"
#4 0xb6b25295 in dial_exec_full (chan=0x841ca40, data=0xb5485f70, peerflags=0xb5481d48, continue_exec=0x0) at app_dial.c:1492
res = 0
rest = 0x0
cur = 0x0
outgoing = (struct chanlist *) 0xb3885cd8
peer = (struct ast_channel *) 0x841ca40
to = 89998
num = {chan = 0x841ca40, busy = 0, congestion = 0, nochan = 0}
cause = 0
numsubst = "14156952220@66.28.147.100\000Hµ9z\v\bhÎ\026\b\000\000\000\000\b\034Hµ¯_\v\b°â\211³\001\000\000\000\001\000\000\000ÈËA\b@ÊA\b°â\211³h\034Hµ¤\206\031·\220A\036\b°â\211³9\034Hµ\036\035Hµ@ÊA\bP\034Hµê\034HµÅ\206\f\bCALLERID\000all\000\000\026·h323\0001415695RD\r\b\000\000\000\000°â\211³9\034Hµ\200Á}¶\000\000\000\0000\034Hµè\034Hµ¯D\r\b@ÊA\b \034Hµ\036\035Hµ\231\231\231\031\000\000\000\000ôß%·"...
cidname = '\0' <repeats 79 times>
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 = 0xb6b2ad9e "timeleft", end_sound = 0x0, start_sound = 0x0, firstpass = 0, flags = 0}
calldurationlimit = 3600
dtmfcalled = 0x0
dtmfcalling = 0x0
pa = {sentringing = 0, privdb_val = 0, privcid = '\0' <repeats 255 times>, privintro = '\0' <repeats 1023 times>,
---Type <return> to continue, or q <return> to quit---
status = "NOANSWER\000GS", '\0' <repeats 244 times>}
sentringing = 0
moh = 0
outbound_group = 0x0
result = 0
start_time = 1192747299
parse = 0xb5481210 "SIP"
opermode = 0
args = {argc = 3, argv = 0xb54814d4, peers = 0xb5481210 "SIP", timeout = 0xb548122e "90", options = 0xb5481231 "L(3600000", url = 0x0}
opts = {flags = 512}
opt_args = {0x0, 0x0, 0x0, 0xb5481233 "3600000", 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}
__PRETTY_FUNCTION__ = "dial_exec_full"
ASTERISK-1 0xb6b270e3 in dial_exec (chan=0x841ca40, data=0xb5485f70) at app_dial.c:1846
peerflags = {flags = 0}
ASTERISK-2 0x080c600b in pbx_exec (c=0x841ca40, app=0x81c5de8, data=0xb5485f70) at pbx.c:596
res = 138529344
u = (struct ast_module_user *) 0xb389e2b0
saved_c_appl = 0x0
saved_c_data = 0x0
ASTERISK-3 0x080c9619 in pbx_extension_helper (c=0x841ca40, con=0x0, context=0x841cbc8 "h323", exten=0x841cc18 "14156952220", priority=12, label=0x0,
callerid=0xb38b2328 "2014532452", action=E_SPAWN) at pbx.c:1906
e = (struct ast_exten *) 0x81ee810
app = (struct ast_app *) 0x81c5de8
res = 8
q = {incstack = {0x0 <repeats 128 times>}, stacklen = 0, status = 5, swo = 0x0, data = 0x0, foundcontext = 0x841cbc8 "h323"}
passdata = "SIP/14156952220@66.28.147.100,90,L(3600000)", '\0' <repeats 8148 times>
matching_action = 0
__PRETTY_FUNCTION__ = "pbx_extension_helper"
ASTERISK-4 0x080ca92b in ast_spawn_extension (c=0x841ca40, context=0x841cbc8 "h323", exten=0x841cc18 "14156952220", priority=12, callerid=0xb38b2328 "2014532452")
at pbx.c:2397
No locals.
ASTERISK-5 0x080cae7d in __ast_pbx_run (c=0x841ca40) at pbx.c:2496
dst_exten = "\020\203HµL\203Hµ\000\000\000\000X\203Hµ\030\203Hµ\034\203Hµ\\\203Hµ", '\0' <repeats 36 times>, "`\203HµtÁ\f\b\000\000\000\000\000\000\000\000ô/ë·0 ê·\000\000\000\0004\000 ¶8\000 ¶\020\000 ¶\f\203Hµ\000\000\000\000\020\203Hµ\024\203Hµ\000\000\000\000 \203Hµ\030\203HµHø%·D}\031·\020\000\000\000\000\000\000\000°s\031·\000\000\000\000\f\000\000\000ôß%·\f\000\000\000@ø%·\b\203HµV¤\031·@ø%·\f\000\000\000\000\000\000\000x\t\002\000\f\000\000\000\210\206Ø\bô/ë·\000\000\000\000\000\000\000\0008\203Hµ¹£\020\b\001\000"...
pos = 0
digit = 0
found = 1
res = 0
autoloopflag = 0
error = 0
__PRETTY_FUNCTION__ = "__ast_pbx_run"
ASTERISK-6 0x080cc163 in pbx_thread (data=0x841ca40) at pbx.c:2752
c = (struct ast_channel *) 0x841ca40
ASTERISK-7 0x0810b42f in dummy_start (data=0x841c4f8) at utils.c:807
_buffer = {__routine = 0x806ba7d <ast_unregister_thread>, __arg = 0xb5488ba0, __canceltype = -1253538872, __prev = 0x0}
ret = (void *) 0xb725c6f4
a = {start_routine = 0x80cc14c <pbx_thread>, data = 0x841ca40,
name = 0x841c650 "pbx_thread", ' ' <repeats 11 times>, "started at [ 2773] pbx.c ast_pbx_start()"}
ASTERISK-8 0xb7ea93cc in start_thread () from /lib/tls/libpthread.so.0
No symbol table info available.
ASTERISK-9 0xb71fec3e in clone () from /lib/tls/libc.so.6
No symbol table info available.
(gdb)
By: Tilghman Lesher (tilghman) 2007-10-22 11:43:58

The latest crash that you posted has nothing to do with FreeTDS, so I'm closing this issue out. Please post that backtrace AS A FILE in a new bug.