[2017-09-07 08:36:53] DEBUG[27403]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying.
[2017-09-07 08:36:57] DEBUG[14814]: res_pjsip_session.c:646 handle_incoming_sdp: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:471 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f6dcc01de78'
[2017-09-07 08:36:57] DEBUG[14814]: res_rtp_asterisk.c:3142 rtp_allocate_transport: Allocated port 13260 for RTP instance '0x7f6dcc01de78'
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:488 ast_rtp_instance_new: RTP instance '0x7f6dcc01de78' is setup and ready to go
[2017-09-07 08:36:57] DEBUG[14814]: res_rtp_asterisk.c:5805 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 103 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 102 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 104 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 125 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1027 ast_rtp_codecs_payloads_set_m_type: Don't have a default tx payload type 109 format for m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 3 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7f6d5cf16450
[2017-09-07 08:36:57] DEBUG[14814]: res_pjsip_session.c:655 handle_incoming_sdp: Media stream 'audio' handled by audio
[2017-09-07 08:36:57] DEBUG[14814]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:36:57] DEBUG[14814]: channel.c:1001 __ast_channel_alloc_ap: Channel 0x7f6dcc0193e8 'PJSIP/2000-0000002a' allocated
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Macro'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: db.c:374 db_get_common: Unable to find key '2000/dialopts' in family 'AMPUSER'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Gosub'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:604 gosub_exec: Channel PJSIP/2000-0000002a has no datastore, so we're allocating one.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG1' to 'out'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG2' to '01234567891'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG3' to 'dontcare'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '4'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '4'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'NoOp'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '3'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'NoOp'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Gosub'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG1' to 'dontcare'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG2' to 'out'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_stack.c:646 gosub_exec: Setting 'ARG3' to '01234567891'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'NoOp'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Goto'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Return'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Return'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Macro'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: db.c:374 db_get_common: Unable to find key '2000/pinless' in family 'AMPUSER'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: func_db.c:149 function_db_read: DB: AMPUSER/2000/pinless not found in database.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GosubIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GosubIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: db.c:374 db_get_common: Unable to find key '2000/pinless' in family 'AMPUSER'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: func_db.c:149 function_db_read: DB: AMPUSER/2000/pinless not found in database.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: db.c:374 db_get_common: Unable to find key '20/dialopts' in family 'TRUNK'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Macro'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: db.c:374 db_get_common: Unable to find key '2000/emergency_cid' in family 'DEVICE'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: func_db.c:149 function_db_read: DB: DEVICE/2000/emergency_cid not found in database.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Macro
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GosubIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GosubIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Set'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Set
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Macro'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'MacroExit'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Macro
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx_builtins.c:1255 pbx_builtin_gotoif: Not taking any branch
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Dial'
[2017-09-07 08:36:57] DEBUG[28638]: dsp.c:497 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[2017-09-07 08:36:57] DEBUG[28638]: dsp.c:497 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:1001 __ast_channel_alloc_ap: Channel 0x7f6db001f118 'PJSIP/01234567890-0000002b' allocated
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable NODEST from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __MON_FMT from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __FROMEXTEN from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __TIMESTR from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __YEAR from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __MONTH from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __DAY from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __REC_STATUS from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __DIAL_OPTIONS from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:6572 ast_channel_inherit_variables: Inheriting variable __REALCALLERIDNUM from PJSIP/2000-0000002a to PJSIP/01234567890-0000002b.
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting read format path: g722 -> g722
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting write format path: g722 -> g722
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting read format path: g722 -> g722
[2017-09-07 08:36:57] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting write format path: g722 -> g722
[2017-09-07 08:36:57] DEBUG[14814]: res_pjsip_sdp_rtp.c:187 create_rtp: Transport 0.0.0.0-udp bound to 0.0.0.0: Using it for RTP media.
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:471 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:36:57] DEBUG[14814]: res_rtp_asterisk.c:3142 rtp_allocate_transport: Allocated port 19672 for RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:36:57] DEBUG[14814]: rtp_engine.c:488 ast_rtp_instance_new: RTP instance '0x7f6dcc074bb8' is setup and ready to go
[2017-09-07 08:36:57] DEBUG[14814]: res_rtp_asterisk.c:5805 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:36:57] DEBUG[28638]: res_pjsip_session.c:2256 outbound_invite_auth: Initial INVITE is being challenged.
[2017-09-07 08:36:58] DEBUG[6262]: db.c:374 db_get_common: Unable to find key 'DND2000' in family 'CustomDevstate'
[2017-09-07 08:36:58] DEBUG[6262]: app_queue.c:2617 extension_state_cb: Extension '2000@ext-local' changed to state '2' (In use)
[2017-09-07 08:37:02] DEBUG[27470]: manager.c:6358 process_message: Running action 'Login'
[2017-09-07 08:37:02] DEBUG[27472]: manager.c:6358 process_message: Running action 'Login'
[2017-09-07 08:37:02] DEBUG[27471]: manager.c:6358 process_message: Running action 'Login'
[2017-09-07 08:37:02] DEBUG[28638]: res_pjsip_session.c:710 handle_negotiated_sdp_session_media: Applying negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:02] DEBUG[28638]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:37:02] DEBUG[28638]: res_rtp_asterisk.c:5871 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:37:02] DEBUG[28638]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7f6d91a34f20
[2017-09-07 08:37:02] DEBUG[28638]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7f6d91a34f20
[2017-09-07 08:37:02] DEBUG[28638]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[28638]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[28638]: res_pjsip_session.c:715 handle_negotiated_sdp_session_media: Applied negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[14814]: res_pjsip_session.c:710 handle_negotiated_sdp_session_media: Applying negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:02] DEBUG[14814]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:02] DEBUG[14814]: res_rtp_asterisk.c:5871 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 103 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 102 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 104 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 125 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1027 ast_rtp_codecs_payloads_set_m_type: Don't have a default tx payload type 109 format for m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 3 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7f6d5cf16120
[2017-09-07 08:37:02] DEBUG[14814]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[14814]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[14814]: res_pjsip_session.c:715 handle_negotiated_sdp_session_media: Applied negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:512 find_best_technology: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge_native_rtp.c:733 native_rtp_bridge_compatible: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e' can not use native RTP bridge as two channels are required
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:517 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:526 find_best_technology: Chose bridge technology simple_bridge
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:809 bridge_base_init: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: calling simple_bridge technology constructor
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:817 bridge_base_init: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: calling simple_bridge technology start
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge_channel.c:2792 bridge_channel_internal_join: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a77718(PJSIP/01234567890-0000002b) is joining
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge_channel.c:2188 bridge_channel_internal_push_full: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: pushing 0x7f6db0a77718(PJSIP/01234567890-0000002b)
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology softmix does not have any capabilities we want.
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge_native_rtp.c:733 native_rtp_bridge_compatible: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e' can not use native RTP bridge as two channels are required
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:517 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:526 find_best_technology: Chose bridge technology simple_bridge
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:1063 smart_bridge_operation: Bridge cda52520-805d-460e-b5a3-a7c24e43475e is already using the new technology.
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: bridge.c:430 bridge_channel_complete_join: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a77718(PJSIP/01234567890-0000002b) is joining simple_bridge technology
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge_channel.c:2792 bridge_channel_internal_join: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a71128(PJSIP/2000-0000002a) is joining
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge_channel.c:2188 bridge_channel_internal_push_full: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: pushing 0x7f6db0a71128(PJSIP/2000-0000002a)
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology softmix does not have any capabilities we want.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge_native_rtp.c:623 native_rtp_bridge_compatible_check: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e'.  Checking compatability for channels 'PJSIP/01234567890-0000002b' and 'PJSIP/2000-0000002a'
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge_native_rtp.c:657 native_rtp_bridge_compatible_check: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e' can not use native RTP bridge as channel 'PJSIP/01234567890-0000002b' has DTMF hooks
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:517 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:526 find_best_technology: Chose bridge technology simple_bridge
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:1063 smart_bridge_operation: Bridge cda52520-805d-460e-b5a3-a7c24e43475e is already using the new technology.
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: bridge.c:430 bridge_channel_complete_join: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a71128(PJSIP/2000-0000002a) is joining simple_bridge technology
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[6259]: cdr.c:1293 cdr_object_finalize: Finalized CDR for PJSIP/01234567890-0000002b - start 1504766217.448465 answer 1504766222.416552 end 1504766222.418092 dispo ANSWERED
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/01234567890-0000002b setting read format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting write format path: g722 -> g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4786 ast_rtcp_interpret: Got RTCP report of 64 bytes
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4845 ast_rtcp_interpret: 0x7f6dcc0b3710 -- Received RTCP report from 10.0.1.104:4029, dropping due to strict RTP protection. Received SSRC '2016488673' but expected '0'
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4845 ast_rtcp_interpret: 0x7f6dcc0b3710 -- Received RTCP report from 10.0.1.104:4029, dropping due to strict RTP protection. Received SSRC '2016488673' but expected '0'
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4786 ast_rtcp_interpret: Got RTCP report of 64 bytes
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4845 ast_rtcp_interpret: 0x7f6dcc0b3710 -- Received RTCP report from 10.0.1.104:4029, dropping due to strict RTP protection. Received SSRC '2016488673' but expected '0'
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4845 ast_rtcp_interpret: 0x7f6dcc0b3710 -- Received RTCP report from 10.0.1.104:4029, dropping due to strict RTP protection. Received SSRC '2016488673' but expected '0'
[2017-09-07 08:37:02] DEBUG[14814]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: res_rtp_asterisk.c:4234 ast_rtp_write: Ooh, format changed from none to g722
[2017-09-07 08:37:02] DEBUG[27481][C-0000001a]: res_rtp_asterisk.c:4074 rtp_raw_write: Starting RTCP transmission on RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4234 ast_rtp_write: Ooh, format changed from none to g722
[2017-09-07 08:37:02] DEBUG[27446][C-0000001a]: res_rtp_asterisk.c:4786 ast_rtcp_interpret: Got RTCP report of 84 bytes
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[27472]: manager.c:6358 process_message: Running action 'Command'
[2017-09-07 08:37:03] DEBUG[28638]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:03] DEBUG[14814]: res_pjsip_session.c:710 handle_negotiated_sdp_session_media: Applying negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:03] DEBUG[14814]: res_rtp_asterisk.c:5704 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:03] DEBUG[14814]: res_rtp_asterisk.c:5871 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:03] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7f6d5cf15eb0
[2017-09-07 08:37:03] DEBUG[14814]: rtp_engine.c:1032 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7f6d5cf15eb0
[2017-09-07 08:37:03] DEBUG[14814]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting read format path: g722 -> g722
[2017-09-07 08:37:03] DEBUG[14814]: channel.c:5549 set_format: Channel PJSIP/2000-0000002a setting write format path: g722 -> g722
[2017-09-07 08:37:03] DEBUG[14814]: res_pjsip_session.c:715 handle_negotiated_sdp_session_media: Applied negotiated SDP media stream 'audio' using audio SDP handler
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology softmix does not have any capabilities we want.
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge.c:507 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge_native_rtp.c:623 native_rtp_bridge_compatible_check: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e'.  Checking compatability for channels 'PJSIP/01234567890-0000002b' and 'PJSIP/2000-0000002a'
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge_native_rtp.c:657 native_rtp_bridge_compatible_check: Bridge 'cda52520-805d-460e-b5a3-a7c24e43475e' can not use native RTP bridge as channel 'PJSIP/01234567890-0000002b' has DTMF hooks
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge.c:517 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge.c:526 find_best_technology: Chose bridge technology simple_bridge
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: bridge.c:1063 smart_bridge_operation: Bridge cda52520-805d-460e-b5a3-a7c24e43475e is already using the new technology.
[2017-09-07 08:37:03] DEBUG[27446][C-0000001a]: channel.c:3749 __ast_read: Dropping duplicate answer!
[2017-09-07 08:37:03] WARNING[27481][C-0000001a]: chan_pjsip.c:1743 chan_pjsip_indicate: Don't know how to indicate condition 36
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge_channel.c:288 ast_bridge_channel_leave_bridge_nolock: Setting 0x7f6db0a77718(PJSIP/01234567890-0000002b) state from:0 to:1
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge_channel.c:2125 bridge_channel_internal_pull: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: pulling 0x7f6db0a77718(PJSIP/01234567890-0000002b)
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge_channel.c:2137 bridge_channel_internal_pull: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a77718(PJSIP/01234567890-0000002b) is leaving simple_bridge technology
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge.c:320 bridge_dissolve: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: dissolving bridge with cause 16(Normal Clearing)
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge_channel.c:288 ast_bridge_channel_leave_bridge_nolock: Setting 0x7f6db0a71128(PJSIP/2000-0000002a) state from:0 to:2
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge.c:281 bridge_queue_action_nodup: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: queueing action type:13 sub:1001
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: bridge.c:1020 smart_bridge_operation: Bridge cda52520-805d-460e-b5a3-a7c24e43475e is dissolved, not performing smart bridge operation.
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: channel.c:2587 ast_hangup: Channel 0x7f6db001f118 'PJSIP/01234567890-0000002b' hanging up.  Refs: 2
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: chan_pjsip.c:2245 hangup_cause2sip: AST hangup cause 16 (no match found in PJSIP)
[2017-09-07 08:37:05] DEBUG[14814]: rtp_engine.c:414 instance_destructor: Destroyed RTP instance '0x7f6dcc074bb8'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge_channel.c:2125 bridge_channel_internal_pull: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: pulling 0x7f6db0a71128(PJSIP/2000-0000002a)
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge_channel.c:2137 bridge_channel_internal_pull: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: 0x7f6db0a71128(PJSIP/2000-0000002a) is leaving simple_bridge technology
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge.c:1020 smart_bridge_operation: Bridge cda52520-805d-460e-b5a3-a7c24e43475e is dissolved, not performing smart bridge operation.
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge.c:659 destroy_bridge: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: actually destroying basic bridge, nobody wants it anymore
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge.c:684 destroy_bridge: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: calling basic bridge destructor
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge.c:690 destroy_bridge: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: calling simple_bridge technology stop
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: bridge.c:697 destroy_bridge: Bridge cda52520-805d-460e-b5a3-a7c24e43475e: calling simple_bridge technology destructor
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: app_dial.c:3218 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:4390 __ast_pbx_run: Spawn extension (from-internal,01234567891,5) exited non-zero on 'PJSIP/2000-0000002a'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: channel.c:2496 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'PJSIP/2000-0000002a'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: channel.c:2496 ast_softhangup_nolock: Soft-Hanging (0x80) up channel 'PJSIP/2000-0000002a'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Macro'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '1'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'GotoIf'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: GotoIf
[2017-09-07 08:37:05] DEBUG[27481][C-0000001a]: channel.c:2222 ast_channel_destructor: Channel 0x7f6db001f118 'PJSIP/01234567890-0000002b' destroying
[2017-09-07 08:37:05] DEBUG[6259]: cdr.c:1293 cdr_object_finalize: Finalized CDR for PJSIP/2000-0000002a - start 1504766217.435642 answer 1504766222.416685 end 1504766225.461606 dispo ANSWERED
[2017-09-07 08:37:05] DEBUG[6259]: cdr.c:1121 cdr_object_create_public_records: CDR for PJSIP/01234567890-0000002b is dialed and has no Party B; discarding
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx_variables.c:775 pbx_substitute_variables_helper_full: Expression result is '0'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'ExecIf'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: ExecIf
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'NoOp'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: Noop
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'AGI'
[2017-09-07 08:37:05] DEBUG[27530]: manager.c:6358 process_message: Running action 'Login'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: app_macro.c:459 _macro_exec: Executed application: AGI
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:2915 pbx_extension_helper: Launching 'Hangup'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: channel.c:2496 ast_softhangup_nolock: Soft-Hanging (0x20) up channel 'PJSIP/2000-0000002a'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: pbx.c:4202 ast_pbx_h_exten_run: Spawn extension (from-internal,h,1) exited non-zero on 'PJSIP/2000-0000002a'
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: channel.c:2587 ast_hangup: Channel 0x7f6dcc0193e8 'PJSIP/2000-0000002a' hanging up.  Refs: 2
[2017-09-07 08:37:05] DEBUG[27446][C-0000001a]: chan_pjsip.c:2245 hangup_cause2sip: AST hangup cause 16 (no match found in PJSIP)
[2017-09-07 08:37:05] DEBUG[28638]: rtp_engine.c:414 instance_destructor: Destroyed RTP instance '0x7f6dcc01de78'
[2017-09-07 08:37:05] DEBUG[28638]: channel.c:2222 ast_channel_destructor: Channel 0x7f6dcc0193e8 'PJSIP/2000-0000002a' destroying
[2017-09-07 08:37:05] DEBUG[6262]: db.c:374 db_get_common: Unable to find key 'DND2000' in family 'CustomDevstate'
[2017-09-07 08:37:05] DEBUG[6262]: app_queue.c:2617 extension_state_cb: Extension '2000@ext-local' changed to state '1' (Not in use)
[2017-09-07 08:37:05] DEBUG[14814]: res_pjsip_session.c:3494 session_inv_on_tsx_state_changed: BYE received final response code 200