::WORKING:: -- User entered '66' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'READSTATUS' is 'OK' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:4101 pbx_extension_helper: Launching 'NoOp' -- Executing [s@REDACTED-connect:2] NoOp("SIP/REDACTED-dev-0000006f", "Echo: OK") in new stack [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '4403819558' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:3] Set("SIP/REDACTED-dev-0000006f", "CID=4403819558") in new stack [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'VOICEUSERID' is '66' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3696 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1}'' len 4) [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'ARG1' is '66' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:613 acf_odbc_read: Got collength of 6 and maxcol of 4 for column 'UserID' (offset 0) [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:659 acf_odbc_read: Got coldata of '489' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:683 acf_odbc_read: buf is now set to '489' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:685 acf_odbc_read: buf is now set to '489' [Oct 6 19:20:14] DEBUG[21961]: res_odbc.c:1035 odbc_release_obj2: odbc_release_obj2(0x1e9930b8) called (obj->txf = (nil)) [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '489' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:4] Set("SIP/REDACTED-dev-0000006f", "USERID=489") in new stack [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'USERID' is '489' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3696 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1}'' len 4) [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'ARG1' is '489' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:613 acf_odbc_read: Got collength of 7 and maxcol of 1 for column 'cidlock' (offset 0) [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:659 acf_odbc_read: Got coldata of '0' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:683 acf_odbc_read: buf is now set to '0' [Oct 6 19:20:14] DEBUG[21961]: func_odbc.c:685 acf_odbc_read: buf is now set to '0' [Oct 6 19:20:14] DEBUG[21961]: res_odbc.c:1035 odbc_release_obj2: odbc_release_obj2(0x1e9930b8) called (obj->txf = (nil)) [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '0' [Oct 6 19:20:14] DEBUG[21961]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:5] Set("SIP/REDACTED-dev-0000006f", "CIDLOCK=0") in new stack [Oct 6 19:20:14] DEBUG[21961]: pbx.c:3110 ast_str_retrieve_variable: Result of 'CIDLOCK' is '0' ::NOT WORKING:: -- User entered '66' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3110 ast_str_retrieve_variable: Result of 'READSTATUS' is 'OK' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:4101 pbx_extension_helper: Launching 'NoOp' -- Executing [s@REDACTED-connect:2] NoOp("SIP/REDACTED-dev-00000071", "Echo: OK") in new stack [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '4403819558' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:3] Set("SIP/REDACTED-dev-00000071", "CID=4403819558") in new stack [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3110 ast_str_retrieve_variable: Result of 'VOICEUSERID' is '66' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3696 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1}'' len 4) [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3110 ast_str_retrieve_variable: Result of 'ARG1' is '66' [Oct 6 19:21:51] DEBUG[21967]: res_odbc.c:1035 odbc_release_obj2: odbc_release_obj2(0x1e9930b8) called (obj->txf = (nil)) [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:4] Set("SIP/REDACTED-dev-00000071", "USERID=") in new stack [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3110 ast_str_retrieve_variable: Result of 'USERID' is '' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3696 ast_str_substitute_variables_full: Evaluating 'ARG1' (from 'ARG1}'' len 4) [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3107 ast_str_retrieve_variable: Result of 'ARG1' is NULL [Oct 6 19:21:51] DEBUG[21967]: func_odbc.c:613 acf_odbc_read: Got collength of 6 and maxcol of 4 for column 'UserID' (offset 0) [Oct 6 19:21:51] DEBUG[21967]: func_odbc.c:659 acf_odbc_read: Got coldata of '489' [Oct 6 19:21:51] DEBUG[21967]: func_odbc.c:683 acf_odbc_read: buf is now set to '489' [Oct 6 19:21:51] DEBUG[21967]: func_odbc.c:685 acf_odbc_read: buf is now set to '489' [Oct 6 19:21:51] DEBUG[21967]: res_odbc.c:1035 odbc_release_obj2: odbc_release_obj2(0x1e9930b8) called (obj->txf = (nil)) [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3929 pbx_substitute_variables_helper_full: Function result is '489' [Oct 6 19:21:51] DEBUG[21967]: pbx.c:4101 pbx_extension_helper: Launching 'Set' -- Executing [s@REDACTED-connect:5] Set("SIP/REDACTED-dev-00000071", "CIDLOCK=489") in new stack [Oct 6 19:21:51] DEBUG[21967]: pbx.c:3110 ast_str_retrieve_variable: Result of 'CIDLOCK' is '489'