[asterisk-bugs] [JIRA] (ASTERISK-27615) Dialplan deadlock when connection to external SQL server is lost

Richard Mudgett (JIRA) noreply at issues.asterisk.org
Wed Jan 24 13:09:49 CST 2018


    [ https://issues.asterisk.org/jira/browse/ASTERISK-27615?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=241787#comment-241787 ] 

Richard Mudgett edited comment on ASTERISK-27615 at 1/24/18 1:08 PM:
---------------------------------------------------------------------

Same issue when loading one or the other.

CentOS 7.3.1611
Kernel 3.10.0-514.21.1.el7.x86_64
unixODBC version 2.3.1 release 11.el7.x86_64

My odbc.ini entries all look like this:
{noformat}
[dev-dallas-sql1]
Description=MySQL for Asterisk CDR
Driver=MySQL
Driver64=MySQL
Server=dev-dallas-sql1.myserver.net
UserName=root
Password=password
Database=container_999999
{noformat}

odbcinst.ini
{noformat}
[MySQL]
Description=ODBC for MySQL
Driver64=/usr/lib64/libmyodbc5.so
Setup64=/usr/lib64/libodbcmyS.so
FileUsage=1
DontDLClose=1
CPTimeout=1000
CPTimeToLive=100
Threading=2
Pooling=yes
{noformat}

Here is something that might indicate where the trouble lies.
{noformat}exten => 102,1,noop(${ODBC_blacklist_global(42)}){noformat}
{noformat}
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'SQL_ESC(${ARG1})' (from 'SQL_ESC(${ARG1})}'' len 16)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1})' len 4)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:381 ast_str_retrieve_variable: Result of 'ARG1' is '42'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:508 ast_str_substitute_variables_full: Function SQL_ESC(42) result is '42'
-----when locked up, Asterisk does not get farther than this-----
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:931 odbc_obj_connect: Connecting dev-dallas-sql1(0x25f62e8)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:969 odbc_obj_connect: res_odbc: Connected to dev-dallas-sql1 [dev-dallas-sql1 (0x25f62e8)]
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:848 _ast_odbc_request_obj2: Created ODBC handle 0x25f62e8 on class 'dev-dallas-sql1', new count is 1
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:910 acf_odbc_read: Got collength of 8 and maxcol of 19 for column 'COUNT(*)' (offset 0)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:957 acf_odbc_read: Got coldata of '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:981 acf_odbc_read: buf is now set to '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:983 acf_odbc_read: buf is now set to '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x25f62e8 into pool
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:708 pbx_substitute_variables_helper_full: Function ODBC_blacklist_global(42) result is '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx.c:2914 pbx_extension_helper: Launching 'NoOp'
    -- Executing [102 at from-internal:1] NoOp("PJSIP/103a1-0000002d", "0") in new stack
{noformat}

Entires in res_odbc.conf
{noformat}
[dev-dallas-sql1]
enabled => yes
dsn => dev-dallas-sql1
username => root
password => password
pre-connect => yes
{noformat}



was (Author: fortytwo):
Same issue when loading one or the other.

CentOS 7.3.1611
Kernel 3.10.0-514.21.1.el7.x86_64
unixODBC version 2.3.1 release 11.el7.x86_64

My odbc.ini entries all look like this:
{code}
[dev-dallas-sql1]
Description=MySQL for Asterisk CDR
Driver=MySQL
Driver64=MySQL
Server=dev-dallas-sql1.myserver.net
UserName=root
Password=password
Database=container_999999
{code}

odbcinst.ini
{code}
[MySQL]
Description=ODBC for MySQL
Driver64=/usr/lib64/libmyodbc5.so
Setup64=/usr/lib64/libodbcmyS.so
FileUsage=1
DontDLClose=1
CPTimeout=1000
CPTimeToLive=100
Threading=2
Pooling=yes
{code}

Here is something that might indicate where the trouble lies.
{noformat}exten => 102,1,noop(${ODBC_blacklist_global(42)}){noformat}
{code}
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'SQL_ESC(${ARG1})' (from 'SQL_ESC(${ARG1})}'' len 16)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1})' len 4)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:381 ast_str_retrieve_variable: Result of 'ARG1' is '42'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:508 ast_str_substitute_variables_full: Function SQL_ESC(42) result is '42'
-----when locked up, Asterisk does not get farther than this-----
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:931 odbc_obj_connect: Connecting dev-dallas-sql1(0x25f62e8)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:969 odbc_obj_connect: res_odbc: Connected to dev-dallas-sql1 [dev-dallas-sql1 (0x25f62e8)]
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:848 _ast_odbc_request_obj2: Created ODBC handle 0x25f62e8 on class 'dev-dallas-sql1', new count is 1
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:910 acf_odbc_read: Got collength of 8 and maxcol of 19 for column 'COUNT(*)' (offset 0)
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:957 acf_odbc_read: Got coldata of '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:981 acf_odbc_read: buf is now set to '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: func_odbc.c:983 acf_odbc_read: buf is now set to '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x25f62e8 into pool
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx_variables.c:708 pbx_substitute_variables_helper_full: Function ODBC_blacklist_global(42) result is '0'
[Jan 24 15:42:39] DEBUG[10075][C-00000026]: pbx.c:2914 pbx_extension_helper: Launching 'NoOp'
    -- Executing [102 at from-internal:1] NoOp("PJSIP/103a1-0000002d", "0") in new stack
{code}

Entires in res_odbc.conf
{code}
[dev-dallas-sql1]
enabled => yes
dsn => dev-dallas-sql1
username => root
password => password
pre-connect => yes
{code}

> Dialplan deadlock when connection to external SQL server is lost
> ----------------------------------------------------------------
>
>                 Key: ASTERISK-27615
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-27615
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: CDR/cdr_adaptive_odbc, Functions/func_cdr
>    Affects Versions: 14.6.0
>            Reporter: Jared Hull
>            Assignee: Unassigned
>            Severity: Critical
>
> We have a cluster of SQL servers for CDR and realtime states that are used in dialplan. Recently we had a single SQL server lose network connectivity, and all Asterisk instances which used this server as their primary started to hang in dialplan.
> If I stop the SQL service while leaving the server pingable, Asterisk will continue to work and simply return a few errors when the CDR is committed to the database.
> {code}
> res_odbc.c:962 odbc_obj_connect: res_odbc: Error SQLConnect=-1 errno=2003 [unixODBC][MySQL][ODBC 5.2(w) Driver]Can't connect to MySQL server on 'dev-dallas-sql1
> cdr_adaptive_odbc.c:436 odbc_log: cdr_adaptive_odbc: Unable to retrieve database handle for 'dev-dallas-sql1:cdr_event_log'.  CDR failed: INSERT INTO cdr_event_log (
> {code}
> If I 'service network stop' on the SQL server to simulate network failure, asterisk stops executing dialplan related to func_odbc and cdr_adaptive_odbc. It is as if it still thinks the SQL connection is there, and refuses to failover to another DSN in the case of func_odbc. cdr_adaptive_odbc doesn't even have failover connections (this would be a very useful feature) so I don't know what can be done about that, other than to skip CDR and throw an error.
> Dialplan to reproduce:
> {code}
> exten => 101,1,noop(${CDR(anything)})
> exten => 102,1,noop(${ODBC_blacklist_global(42)})
> {code}
> Example of cdr_adaptive_odbc.conf entry:
> {code}
> [default]
> connection=dev-dallas-sql1
> table=cdr_event_log
> {code}
> Example of func_odbc.conf entry:
> {code}
> [blacklist_global]
> dsn=dev-dallas-sql1,dev-dallas-sql2,dev-dallas-sql3
> readsql=SELECT COUNT(*) FROM blacklist_global WHERE cid_number='${SQL_ESC(${ARG1})}'
> {code}



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list