size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1276][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=6980 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7020 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1271][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7000 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7040 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1279][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7020 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7060 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7040 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7080 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1272][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7060 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7100 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1275][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7080 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7120 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1277][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7100 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7140 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1274][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7120 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7160 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1273][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7140 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7180 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1278][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7200 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1276][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7180 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7220 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1271][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7200 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7240 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1279][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7220 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7260 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7240 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7280 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1272][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7260 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7300 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1275][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7280 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7320 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1277][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7300 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7340 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1274][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7320 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7360 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1273][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7340 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7380 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1278][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7360 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7400 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1276][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7380 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7420 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1271][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7400 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7440 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1279][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7420 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7460 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7480 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1190]: res_pjsip/pjsip_message_filter.c:297 filter_on_tx_message: Re-wrote Contact URI host/port to ASTERISK-SIDE-A-IP:17777 (this may be re-written again later) [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7500 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7520 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7540 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7560 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7580 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[1190]: res_pjsip/pjsip_message_filter.c:297 filter_on_tx_message: Re-wrote Contact URI host/port to ASTERISK-SIDE-A-IP:17777 (this may be re-written again later) [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7600 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7620 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7640 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7660 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7680 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7700 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7720 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7740 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7760 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7780 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7800 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7820 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: ANSWER [2021-11-28 14:35:46] Timestamp: 07791ms SCall: 06856 DCall: 12206 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:10423 socket_process_helper: Received packet 2, (4, 4) [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7791 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK [2021-11-28 14:35:46] Timestamp: 07791ms SCall: 12206 DCall: 06856 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7791 [2021-11-28 14:35:46] Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass: (255?) [2021-11-28 14:35:46] Timestamp: 07794ms SCall: 06856 DCall: 12206 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:10423 socket_process_helper: Received packet 3, (4, -1) [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7794 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK [2021-11-28 14:35:46] Timestamp: 07794ms SCall: 12206 DCall: 06856 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1280][C-000000c9]: chan_iax2.c:12015 socket_process_helper: For call=12206, set last=7794 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: app_dial.c:1415 wait_for_answer: IAX2/ASTERISK-SIDE-B-IP:4569-12206 answered Local/91200REDACTED@REDACTED-originate-local-000001fc;2 [2021-11-28 14:35:46] -- IAX2/ASTERISK-SIDE-B-IP:4569-12206 answered Local/91200REDACTED@REDACTED-originate-local-000001fc;2 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: app_dial.c:1929 wait_for_answer: Local/91200REDACTED@REDACTED-originate-local-000001fc;2: Answered by IAX2/ASTERISK-SIDE-B-IP:4569-12206 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: channel.c:5826 set_format: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;2 setting write format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: channel.c:5826 set_format: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;2 setting read format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: stasis.c:579 stasis_topic_create_with_detail: Creating topic. name: bridge:all/bridge:6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1, detail: [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: stasis.c:613 stasis_topic_create_with_detail: Topic 'bridge:all/bridge:6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1': 0x7f1ad01e9310 created [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for IAX2 - ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1126]: chan_iax2.c:14575 iax2_devicestate: Checking device state for device ASTERISK-SIDE-B-IP [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:466 do_state_change: Changing state for IAX2/ASTERISK-SIDE-B-IP:4569 - state 4 (Invalid) [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for Local - 91200REDACTED@REDACTED-originate-local [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:466 do_state_change: Changing state for Local/91200REDACTED@REDACTED-originate-local - state 2 (In use) [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: app_dial.c:1415 wait_for_answer: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 answered Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 [2021-11-28 14:35:46] -- Local/91200REDACTED@REDACTED-originate-local-000001fc;1 answered Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: app_dial.c:1929 wait_for_answer: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1: Answered by Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: app_dial.c:3450 dial_exec_full: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1: Done [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Goto' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:12] Goto("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1", "caller") in new stack [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing-ring,91200REDACTED,6) [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Wait' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:6] Wait("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1", "0.01") in new stack [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:5826 set_format: Channel Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 setting write format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:3215 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:8275 ast_channel_start_silence_generator: Started silence generator on 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.914278 SystemName: REDACTED Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: start Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DialEnd Privilege: call,all Timestamp: 1638110146.914367 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 DestChannel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: start DestCallerIDName: DestConnectedLineNum: REDACTED DestConnectedLineName: InterLinked DestLanguage: en DestAccountCode: DestContext: DestExten: DestPriority: 1 DestUniqueid: REDACTED-1638110139.1537 DestLinkedid: REDACTED-1638110138.1531 DialStatus: ANSWER [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.914378 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.914278 SystemName: REDACTED Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: start Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.914309 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 Variable: DIALSTATUS Value: ANSWER [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.914324 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 Variable: DIALEDPEERNAME Value: IAX2/ASTERISK-SIDE-B-IP:4569-12206 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.914337 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 Variable: DIALEDPEERNUMBER Value: REDACTED@REDACTED/1REDACTED [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DialEnd Privilege: call,all Timestamp: 1638110146.914367 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 DestChannel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: start DestCallerIDName: DestConnectedLineNum: REDACTED DestConnectedLineName: InterLinked DestLanguage: en DestAccountCode: DestContext: DestExten: DestPriority: 1 DestUniqueid: REDACTED-1638110139.1537 DestLinkedid: REDACTED-1638110138.1531 DialStatus: ANSWER [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.914378 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[1173]: cdr.c:1470 cdr_object_finalize: Finalized CDR for Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 - start 1638110138.821597 answer 1638110138.827037 end 1638110146.914614 dur 8.093 bill 8.087 dispo ANSWERED [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for Local - 91200REDACTED@REDACTED-originate-local [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:466 do_state_change: Changing state for Local/91200REDACTED@REDACTED-originate-local - state 2 (In use) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.915379 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-originate-local Exten: 91200REDACTED Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.915402 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 4 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Variable: DIALSTATUS Value: ANSWER [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.915417 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 4 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Variable: DIALEDPEERNAME Value: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.915429 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 4 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Variable: DIALEDPEERNUMBER Value: 91200REDACTED@REDACTED-originate-local/n [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.915441 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 13 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: AppDial AppData: (Outgoing Line) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DialEnd Privilege: call,all Timestamp: 1638110146.915465 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 DestChannel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: 91200REDACTED DestCallerIDName: DestConnectedLineNum: REDACTED DestConnectedLineName: InterLinked DestLanguage: en DestAccountCode: DestContext: REDACTED-outgoing-ring DestExten: 91200REDACTED DestPriority: 13 DestUniqueid: REDACTED-1638110138.1535 DestLinkedid: REDACTED-1638110138.1531 DialStatus: ANSWER [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.915476 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 12 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Goto AppData: caller [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.915484 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 6 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Wait AppData: 0.01 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915492 SystemName: REDACTED Device: IAX2/ASTERISK-SIDE-B-IP:4569 State: INVALID [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915498 SystemName: REDACTED Device: Local/91200REDACTED@REDACTED-originate-local State: INUSE [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915503 SystemName: REDACTED Device: Local/91200REDACTED@REDACTED-originate-local State: INUSE [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: Newstate Privilege: call,all Timestamp: 1638110146.915379 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-originate-local Exten: 91200REDACTED Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DialEnd Privilege: call,all Timestamp: 1638110146.915465 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 DestChannel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: 91200REDACTED DestCallerIDName: DestConnectedLineNum: REDACTED DestConnectedLineName: InterLinked DestLanguage: en DestAccountCode: DestContext: REDACTED-outgoing-ring DestExten: 91200REDACTED DestPriority: 13 DestUniqueid: REDACTED-1638110138.1535 DestLinkedid: REDACTED-1638110138.1531 DialStatus: ANSWER [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915492 SystemName: REDACTED Device: IAX2/ASTERISK-SIDE-B-IP:4569 State: INVALID [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915498 SystemName: REDACTED Device: Local/91200REDACTED@REDACTED-originate-local State: INUSE [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.915503 SystemName: REDACTED Device: Local/91200REDACTED@REDACTED-originate-local State: INUSE [2021-11-28 14:35:46] DEBUG[1299]: app_queue.c:2589 device_state_cb: Device 'IAX2/ASTERISK-SIDE-B-IP:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [2021-11-28 14:35:46] DEBUG[1299]: app_queue.c:2589 device_state_cb: Device 'Local/91200REDACTED@REDACTED-originate-local' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2021-11-28 14:35:46] DEBUG[1299]: app_queue.c:2589 device_state_cb: Device 'Local/91200REDACTED@REDACTED-originate-local' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge_native_rtp.c:774 native_rtp_bridge_compatible: Bridge '6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1' can not use native RTP bridge as two channels are required [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:535 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:525 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want. [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuse) result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:13] GotoIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?blindtransferanswer") in new stack [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:530 find_best_technology: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:549 find_best_technology: Chose bridge technology simple_bridge [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:802 bridge_base_init: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: calling simple_bridge technology constructor [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:810 bridge_base_init: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: calling simple_bridge technology start [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ad0079488 Old: New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[1181]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ad0079488 Old: New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeCreate Privilege: call,all Timestamp: 1638110146.918409 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeCreate Privilege: call,all Timestamp: 1638110146.918409 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_builtins.c:1319 pbx_builtin_gotoif: Not taking any branch [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:14] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "GROUP(lineinuseoutboundanswered)=PJSIP/ATAxGrandstream2") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.919025 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 14 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Set AppData: GROUP(lineinuseoutboundanswered)=PJSIP/ATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'outgoingchan' is 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:15] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "SHARED(chananswered,Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1)=1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.919520 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 15 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Set AppData: SHARED(chananswered,Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1)=1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.919730 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 6 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Variable: SHARED(chananswered) Value: 1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CHANNELS(^\bPJSIP/ATAxGrandstream2) result is 'PJSIP/ATAxGrandstream2-00000081' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EPOCH' is '1638110146' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:16] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "SHARED(lastanswer,PJSIP/ATAxGrandstream2-00000081)=1638110146") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.920447 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 16 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Set AppData: SHARED(lastanswer,PJSIP/ATAxGrandstream2-00000081)=1638110146 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.920660 SystemName: REDACTED Channel: PJSIP/ATAxGrandstream2-00000081 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-local Exten: s Priority: 3 Uniqueid: REDACTED-1638110137.1530 Linkedid: REDACTED-1638110137.1530 Variable: SHARED(lastanswer) Value: 1638110146 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:17] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "CDR_PROP(disable)=1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.920999 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 17 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Set AppData: CDR_PROP(disable)=1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GosubIf' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:18] GosubIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "1?class-forward-process,set,1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.921391 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 18 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: GosubIf AppData: 1?class-forward-process,set,1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: app_stack.c:672 gosub_exec: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;1 has no datastore, so we're allocating one. [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.921607 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 18 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: LOCAL(ARGC) Value: 0 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CHANNELS(^\bPJSIP/ATAxGrandstream2) result is 'PJSIP/ATAxGrandstream2-00000081' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function SHARED(lastfwdattempt,PJSIP/ATAxGrandstream2-00000081) result is '' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL() result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ReturnIf' [2021-11-28 14:35:46] -- Executing [set@class-forward-process:1] ReturnIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "1?") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.922284 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: class-forward-process Exten: set Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: set Application: ReturnIf AppData: 1? [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.922434 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: class-forward-process Exten: set Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: ARGC Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.922587 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: class-forward-process Exten: set Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: GOSUB_RETVAL Value: [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: func_strings.c:780 filter: c1=65, c2=90 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: func_strings.c:780 filter: c1=97, c2=122 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: func_strings.c:780 filter: c1=48, c2=57 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: func_strings.c:794 filter: Allowed: 0123456789ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function FILTER(A-Za-z0-9,PJSIP/ATAxGrandstream2) result is 'PJSIPATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:19] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "filteredpeername=PJSIPATAxGrandstream2") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.923477 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 19 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Set AppData: filteredpeername=PJSIPATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.923625 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 19 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: filteredpeername Value: PJSIPATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@conferenceorig) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CONFBRIDGE_INFO(parties,centrex-conf6port-PJSIP/ATAxGrandstream2) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'filteredpeername' is 'PJSIPATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:20] GotoIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?centrex-conference-6-user,PJSIPATAxGrandstream2,1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.924673 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 20 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: GotoIf AppData: 0?centrex-conference-6-user,PJSIPATAxGrandstream2,1 [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:3215 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:8310 ast_channel_stop_silence_generator: Stopped silence generator on 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:5826 set_format: Channel Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 setting write format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function SHARED(chananswered) result is '1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:7] GotoIf("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1", "1?hangup") in new stack [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing-ring,91200REDACTED,11) [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Hangup' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:11] Hangup("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1", "") in new stack [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:2465 ast_softhangup_nolock: Soft-Hanging (0x20) up channel 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: pbx.c:4441 __ast_pbx_run: Spawn extension (REDACTED-outgoing-ring,91200REDACTED,11) exited non-zero on 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] == Spawn extension (REDACTED-outgoing-ring, 91200REDACTED, 11) exited non-zero on 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:2465 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:2556 ast_hangup: Channel 0x7f1ae40ee9f0 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' hanging up. Refs: 2 [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel.c:2202 ast_channel_destructor: Channel 0x7f1ae40ee9f0 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1' destroying [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: stasis.c:442 topic_dtor: Destroying topic. name: channel:REDACTED-1638110138.1531, detail: [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: stasis.c:450 topic_dtor: Topic 'channel:REDACTED-1638110138.1531': 0x7f1ae407eb30 destroyed [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel_internal_api.c:682 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [2021-11-28 14:35:46] DEBUG[26614][C-000000c9]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: bridge_channel.c:300 ast_bridge_channel_leave_bridge_nolock: Setting 0x5612af0974e0(Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2) state from:0 to:1 [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: bridge_channel.c:2188 bridge_channel_internal_pull: Bridge 8b8bd6e6-e43d-412d-966e-1312f64cf577: pulling 0x5612af0974e0(Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2) [2021-11-28 14:35:46] -- Channel Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 left 'softmix' base-bridge <8b8bd6e6-e43d-412d-966e-1312f64cf577> [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: bridge_channel.c:2200 bridge_channel_internal_pull: Bridge 8b8bd6e6-e43d-412d-966e-1312f64cf577: 0x5612af0974e0(Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2) is leaving softmix technology [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x5612aefe49a8 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x5612b175c598 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: confbridge/conf_state.c:84 conf_change_state: Changing conference 'linePJSIP/ATAxGrandstream2' state from MULTI to SINGLE [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: app_confbridge.c:1297 conf_update_user_mute: User PJSIP/ATAxGrandstream2-00000081 is unmuted: user:0 system:0. [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:4416 __ast_pbx_run: Extension s, priority 9 returned normally even though call was hung up [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel.c:2465 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel.c:2465 ast_softhangup_nolock: Soft-Hanging (0x80) up channel 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Gosub' [2021-11-28 14:35:46] -- Executing [h@REDACTED-outgoing:1] Gosub("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "REDACTED-outgoing-hangup,s,1(PJSIP/ATAxGrandstream2)") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: app_stack.c:672 gosub_exec: Channel Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 has no datastore, so we're allocating one. [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: app_stack.c:714 gosub_exec: Setting 'ARG1' to 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110138.0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110138.0) result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:1] GotoIf("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "0?calctotal") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_builtins.c:1319 pbx_builtin_gotoif: Not taking any branch [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CONFBRIDGE_INFO(parties,linePJSIP/ATAxGrandstream2) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110138.0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function DB_DELETE(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110138.0) result is 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbinitchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110138.0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function DB_DELETE(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110138.0) result is 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'NoOp' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:2] NoOp("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "1 / Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 / Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseoutboundunanswered) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseoutboundanswered) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseincominganswered) result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseincomingringing) result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:3] Set("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "total=2") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP(lineinuseoutboundanswered) result is '(null)' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function EXISTS() result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseoutboundanswered) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:4] GotoIf("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "0?:redirects") in new stack [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing-hangup,s,8) [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:8] Set("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "GROUP(lineinuseoutboundanswered)=") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'total' is '2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CONFBRIDGE_INFO(parties,linePJSIP/ATAxGrandstream2) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuse) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuseoutboundanswered) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for Local - PJSIPATAxGrandstream2@REDACTED-outgoing [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:466 do_state_change: Changing state for Local/PJSIPATAxGrandstream2@REDACTED-outgoing - state 1 (Not in use) [2021-11-28 14:35:46] DEBUG[1299]: app_queue.c:2589 device_state_cb: Device 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2021-11-28 14:35:46] DEBUG[1173]: cdr.c:1470 cdr_object_finalize: Finalized CDR for Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 - start 1638110146.914614 answer 1638110146.914614 end 1638110146.924919 dur 0.010 bill 0.010 dispo ANSWERED [2021-11-28 14:35:46] DEBUG[1173]: cdr.c:1470 cdr_object_finalize: Finalized CDR for PJSIP/ATAxGrandstream2-00000081 - start 1638110137.220776 answer 1638110137.224901 end 1638110146.925121 dur 9.704 bill 9.700 dispo ANSWERED [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: ConfbridgeLeave Privilege: call,all Timestamp: 1638110146.925926 SystemName: REDACTED Conference: linePJSIP/ATAxGrandstream2 BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Admin: No [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: ConfbridgeLeave Privilege: call,all Timestamp: 1638110146.925926 SystemName: REDACTED Conference: linePJSIP/ATAxGrandstream2 BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Admin: No [2021-11-28 14:35:46] DEBUG[1181]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x5612aefe49a8 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[1181]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x5612b175c598 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926412 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 7 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: GotoIf AppData: 1?hangup [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926433 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Hangup AppData: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: SoftHangupRequest Privilege: call,all Timestamp: 1638110146.926450 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: HangupRequest Privilege: call,all Timestamp: 1638110146.926465 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Hangup Privilege: call,all Timestamp: 1638110146.926478 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Cause: 16 Cause-txt: Normal Clearing [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926502 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: BRIDGEPEER Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeLeave Privilege: call,all Timestamp: 1638110146.926540 SystemName: REDACTED BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926565 SystemName: REDACTED Channel: PJSIP/ATAxGrandstream2-00000081 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-local Exten: s Priority: 3 Uniqueid: REDACTED-1638110137.1530 Linkedid: REDACTED-1638110137.1530 Variable: BRIDGEPEER Value: CBAnn/linePJSIP/ATAxGrandstream2-000001fb;2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926588 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: CONFBRIDGE_RESULT Value: HANGUP [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: SoftHangupRequest Privilege: call,all Timestamp: 1638110146.926599 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926608 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: h Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: h Application: Gosub AppData: REDACTED-outgoing-hangup,s,1(PJSIP/ATAxGrandstream2) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926620 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: h Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: LOCAL(ARG1) Value: PJSIP/ATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926632 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: h Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: LOCAL(ARGC) Value: 1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926640 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: GotoIf AppData: 0?calctotal [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926653 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: DB_RESULT Value: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926664 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 1 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: DB_RESULT Value: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926711 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 2 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: NoOp AppData: 1 / Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 / Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926728 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 3 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: Set AppData: total=2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.926759 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 3 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: total Value: 2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926771 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 4 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: GotoIf AppData: 0?:redirects [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.926783 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 8 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: Set AppData: GROUP(lineinuseoutboundanswered)= [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.926794 SystemName: REDACTED Device: Local/PJSIPATAxGrandstream2@REDACTED-outgoing State: NOT_INUSE [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: SoftHangupRequest Privilege: call,all Timestamp: 1638110146.926450 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: HangupRequest Privilege: call,all Timestamp: 1638110146.926465 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: Hangup Privilege: call,all Timestamp: 1638110146.926478 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 11 Uniqueid: REDACTED-1638110138.1531 Linkedid: REDACTED-1638110138.1531 Cause: 16 Cause-txt: Normal Clearing [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeLeave Privilege: call,all Timestamp: 1638110146.926540 SystemName: REDACTED BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: SoftHangupRequest Privilege: call,all Timestamp: 1638110146.926599 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.926794 SystemName: REDACTED Device: Local/PJSIPATAxGrandstream2@REDACTED-outgoing State: NOT_INUSE [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CHANNELS(^\bPJSIP/ATAxGrandstream2) result is 'PJSIP/ATAxGrandstream2-00000081' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:9] ExecIf("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "0?ChannelRedirect(PJSIP/ATAxGrandstream2-00000081,REDACTED-local,outgoingclear,1)") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'total' is '2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'ARG1' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@lineinuse) result is '1' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:374 ast_str_retrieve_variable: Result of 'desiredpeer' is NULL [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: db.c:399 db_get_common: Unable to find key '/tmp/chan/recallring' in family 'REDACTED' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: func_db.c:149 function_db_read: DB: REDACTED//tmp/chan/recallring not found in database. [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function DB(REDACTED//tmp/chan/recallring) result is '' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function SET(chan=) result is '' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function EXISTS() result is '0' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'chan' is '' [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:10] ExecIf("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "0?ExecIf(0?ChannelRedirect(,REDACTED-recall,cancel))") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Return' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing-hangup:11] Return("Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2", "") in new stack [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel.c:2556 ast_hangup: Channel 0x7f1ae403d6f0 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' hanging up. Refs: 2 [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel.c:2202 ast_channel_destructor: Channel 0x7f1ae403d6f0 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2' destroying [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: stasis.c:442 topic_dtor: Destroying topic. name: channel:REDACTED-1638110138.1532, detail: [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: stasis.c:450 topic_dtor: Topic 'channel:REDACTED-1638110138.1532': 0x7f1ae41088f0 destroyed [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for Local - PJSIPATAxGrandstream2@REDACTED-outgoing [2021-11-28 14:35:46] DEBUG[1126]: core_local.c:353 local_devicestate: Checking if extension PJSIPATAxGrandstream2@REDACTED-outgoing exists (devicestate) [2021-11-28 14:35:46] DEBUG[1126]: devicestate.c:466 do_state_change: Changing state for Local/PJSIPATAxGrandstream2@REDACTED-outgoing - state 1 (Not in use) [2021-11-28 14:35:46] DEBUG[1299]: app_queue.c:2589 device_state_cb: Device 'Local/PJSIPATAxGrandstream2@REDACTED-outgoing' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel_internal_api.c:682 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [2021-11-28 14:35:46] DEBUG[26618][C-000000c9]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: Hangup Privilege: call,all Timestamp: 1638110146.937144 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: h Priority: 2 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 Cause-txt: Normal Clearing [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.937156 SystemName: REDACTED Device: Local/PJSIPATAxGrandstream2@REDACTED-outgoing State: NOT_INUSE [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.937011 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: ExecIf AppData: 0?ChannelRedirect(PJSIP/ATAxGrandstream2-00000081,REDACTED-local,outgoingclear,1) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.937066 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: chan Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.937078 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 10 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: ExecIf AppData: 0?ExecIf(0?ChannelRedirect(,REDACTED-recall,cancel)) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.937090 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 11 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Extension: s Application: Return AppData: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.937106 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 11 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: ARGC Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.937118 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 11 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: ARG1 Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.937133 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-hangup Exten: s Priority: 11 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Variable: GOSUB_RETVAL Value: [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Hangup Privilege: call,all Timestamp: 1638110146.937144 SystemName: REDACTED Channel: Local/PJSIPATAxGrandstream2@REDACTED-outgoing-000001fa;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: h Priority: 2 Uniqueid: REDACTED-1638110138.1532 Linkedid: REDACTED-1638110138.1531 Cause: 16 Cause-txt: Normal Clearing [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: DeviceStateChange Privilege: call,all Timestamp: 1638110146.937156 SystemName: REDACTED Device: Local/PJSIPATAxGrandstream2@REDACTED-outgoing State: NOT_INUSE [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge_channel.c:2911 bridge_channel_internal_join: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: 0x7f1ad01ed5e0(IAX2/ASTERISK-SIDE-B-IP:4569-12206) is joining [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_builtins.c:1319 pbx_builtin_gotoif: Not taking any branch [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.938205 SystemName: REDACTED Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 Extension: Application: AppDial AppData: (Outgoing Line) [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge_channel.c:2251 bridge_channel_internal_push_full: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: pushing 0x7f1ad01ed5e0(IAX2/ASTERISK-SIDE-B-IP:4569-12206) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Goto' [2021-11-28 14:35:46] -- Executing [91200REDACTED@REDACTED-outgoing-ring:21] Goto("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "REDACTED-outgoing,PJSIP/ATAxGrandstream2,1") in new stack [2021-11-28 14:35:46] -- Channel IAX2/ASTERISK-SIDE-B-IP:4569-12206 joined 'simple_bridge' basic-bridge <6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1> [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.938837 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing-ring Exten: 91200REDACTED Priority: 21 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: 91200REDACTED Application: Goto AppData: REDACTED-outgoing,PJSIP/ATAxGrandstream2,1 [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing,PJSIP/ATAxGrandstream2,1) [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.938982 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 1 BridgeVideoSourceMode: none Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.938982 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 1 BridgeVideoSourceMode: none Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ae00b4668 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ae00b4668 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge_native_rtp.c:774 native_rtp_bridge_compatible: Bridge '6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1' can not use native RTP bridge as two channels are required [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:535 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge. [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:1] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "CDR_PROP(disable)=1") in new stack [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:525 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want. [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:525 find_best_technology: Bridge technology softmix does not have any capabilities we want. [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:549 find_best_technology: Chose bridge technology simple_bridge [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.939698 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Set AppData: CDR_PROP(disable)=1 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:1058 smart_bridge_operation: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 is already using the new technology. [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: bridge.c:448 bridge_channel_complete_join: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: 0x7f1ad01ed5e0(IAX2/ASTERISK-SIDE-B-IP:4569-12206) is joining simple_bridge technology [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ae0092778 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Answer' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:2] Answer("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "") in new stack [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ae0092778 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.940335 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 2 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Answer AppData: [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EXTEN' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge_channel.c:2911 bridge_channel_internal_join: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: 0x7f1ad00c1b80(Local/91200REDACTED@REDACTED-originate-local-000001fc;2) is joining [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge_channel.c:2251 bridge_channel_internal_push_full: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: pushing 0x7f1ad00c1b80(Local/91200REDACTED@REDACTED-originate-local-000001fc;2) [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:5762 iax2_indicate: Indicating condition 26 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:7764 send_command: Callno 12206: Blocked sending control frame 26. [2021-11-28 14:35:46] -- Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;2 joined 'simple_bridge' basic-bridge <6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1> [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ad00074d8 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge_native_rtp.c:647 native_rtp_bridge_compatible_check: Bridge '6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1'. Checking compatability for channels 'IAX2/ASTERISK-SIDE-B-IP:4569-12206' and 'Local/91200REDACTED@REDACTED-originate-local-000001fc;2' [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge_native_rtp.c:667 native_rtp_bridge_compatible_check: Bridge '6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1' can not use native RTP bridge as could not get details [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:535 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:525 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:525 find_best_technology: Bridge technology softmix does not have any capabilities we want. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:549 find_best_technology: Chose bridge technology simple_bridge [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:1058 smart_bridge_operation: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 is already using the new technology. [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: bridge.c:448 bridge_channel_complete_join: Bridge 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1: 0x7f1ad00c1b80(Local/91200REDACTED@REDACTED-originate-local-000001fc;2) is joining simple_bridge technology [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: channel.c:5826 set_format: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;2 setting read format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: channel.c:5826 set_format: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;2 setting write format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: channel.c:11182 ast_channel_request_stream_topology_change: Local/91200REDACTED@REDACTED-originate-local-000001fc;2: Topologies already match. Current: <0:audio-0:audio:sendrecv (slin)> Requested: <0:audio-0:audio:sendrecv (slin)> [2021-11-28 14:35:46] DEBUG[26619][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ad01e8838 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[1173]: cdr.c:1470 cdr_object_finalize: Finalized CDR for IAX2/ASTERISK-SIDE-B-IP:4569-12206 - start 1638110139.114107 answer 1638110146.913834 end 1638110146.938756 dur 7.824 bill 0.024 dispo ANSWERED [2021-11-28 14:35:46] DEBUG[1181]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ad00074d8 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[1181]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ad01e8838 Old: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 New: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.941055 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.941055 SystemName: REDACTED BridgeUniqueid: 6f2ec4d7-cc47-4b2d-87b0-fb63b40565e1 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.941091 SystemName: REDACTED Channel: IAX2/ASTERISK-SIDE-B-IP:4569-12206 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: start CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: Exten: Priority: 1 Uniqueid: REDACTED-1638110139.1537 Linkedid: REDACTED-1638110138.1531 Variable: BRIDGEPEER Value: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.941111 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: 91200REDACTED ConnectedLineName: Language: en AccountCode: Context: REDACTED Exten: start Priority: 4 Uniqueid: REDACTED-1638110138.1536 Linkedid: REDACTED-1638110138.1531 Variable: BRIDGEPEER Value: IAX2/ASTERISK-SIDE-B-IP:4569-12206 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:5762 iax2_indicate: Indicating condition -1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:3] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "fullpeername=PJSIP/ATAxGrandstream2") in new stack [2021-11-28 14:35:46] DEBUG[1268]: chan_iax2.c:3414 send_packet: Sending 7823 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 004 Type: CONTROL Subclass: (255?) [2021-11-28 14:35:46] Timestamp: 07823ms SCall: 12206 DCall: 06856 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.941906 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 3 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Set AppData: fullpeername=PJSIP/ATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.941985 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 3 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: fullpeername Value: PJSIP/ATAxGrandstream2 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP(lineinuseoutboundanswered) result is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL(PJSIP/ATAxGrandstream2) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:4] ExecIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?Set(GROUP(lineinuseoutboundunanswered)=PJSIP/ATAxGrandstream2)") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.942576 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 4 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: ExecIf AppData: 0?Set(GROUP(lineinuseoutboundunanswered)=PJSIP/ATAxGrandstream2) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:374 ast_str_retrieve_variable: Result of 'dbinitchan' is NULL [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL() result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EPOCH' is '1638110146' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EPOCH' is '1638110146' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function STRFTIME(1638110146,,%1q) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:5] ExecIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "1?Set(dbinitchan=REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0)") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.943356 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 5 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: ExecIf AppData: 1?Set(dbinitchan=REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0) [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.943669 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 5 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: dbinitchan Value: REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbinitchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'CHANNEL' is 'Local/91200REDACTED@REDACTED-originate-local-000001fc;1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:6] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.944116 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 6 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Set AppData: DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsinitoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function CHANNELS(^\bPJSIP/ATAxGrandstream2) result is 'PJSIP/ATAxGrandstream2-00000081' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'CHANNEL' is 'Local/91200REDACTED@REDACTED-originate-local-000001fc;1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:7] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "SHARED(latestoutgoingcall,PJSIP/ATAxGrandstream2-00000081)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.945472 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 7 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Set AppData: SHARED(latestoutgoingcall,PJSIP/ATAxGrandstream2-00000081)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.945799 SystemName: REDACTED Channel: PJSIP/ATAxGrandstream2-00000081 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-local Exten: s Priority: 3 Uniqueid: REDACTED-1638110137.1530 Linkedid: REDACTED-1638110137.1530 Variable: SHARED(latestoutgoingcall) Value: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Goto' [2021-11-28 14:35:46] -- Executing [PJSIP/ATAxGrandstream2@REDACTED-outgoing:8] Goto("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "s,1") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.946152 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: PJSIP/ATAxGrandstream2 Priority: 8 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: PJSIP/ATAxGrandstream2 Application: Goto AppData: s,1 [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing,s,1) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:374 ast_str_retrieve_variable: Result of 'dbchan' is NULL [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL() result is '1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:1] GotoIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "1?newchan") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.946608 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 1 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: GotoIf AppData: 1?newchan [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing,s,3) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EPOCH' is '1638110146' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'EPOCH' is '1638110146' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function STRFTIME(1638110146,,%1q) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'Set' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:3] Set("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "dbchan=REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.947222 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 3 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: Set AppData: dbchan=REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.947300 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 3 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: dbchan Value: REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: db.c:399 db_get_common: Unable to find key 'PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0' in family 'REDACTED' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function DB_EXISTS(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'GotoIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:4] GotoIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?:setchan") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.947808 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 4 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: GotoIf AppData: 0?:setchan [2021-11-28 14:35:46] -- Goto (REDACTED-outgoing,s,7) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP(lineinuseoutboundanswered) result is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function ISNULL(PJSIP/ATAxGrandstream2) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'CHANNEL' is 'Local/91200REDACTED@REDACTED-originate-local-000001fc;1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'dbchan' is 'REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'CHANNEL' is 'Local/91200REDACTED@REDACTED-originate-local-000001fc;1' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:7] ExecIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?Set(DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1):Set(DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1)") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.948818 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 7 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: ExecIf AppData: 0?Set(DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1):Set(DB(REDACTED/PJSIP/ATAxGrandstream2/tmp/chan/callsoutgoing/1638110146.0)=Local/91200REDACTED@REDACTED-originate-local-000001fc;1) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:759 pbx_substitute_variables_helper_full: Function GROUP_COUNT(PJSIP/ATAxGrandstream2@toneblock) result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:823 pbx_substitute_variables_helper_full: Expression result is '0' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ExecIf' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:8] ExecIf("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "0?Set(nodtmf=nodtmf)") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.949677 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 8 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: ExecIf AppData: 0?Set(nodtmf=nodtmf) [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:377 ast_str_retrieve_variable: Result of 'fullpeername' is 'PJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx_variables.c:374 ast_str_retrieve_variable: Result of 'nodtmf' is NULL [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: pbx.c:2938 pbx_extension_helper: Launching 'ConfBridge' [2021-11-28 14:35:46] -- Executing [s@REDACTED-outgoing:9] ConfBridge("Local/91200REDACTED@REDACTED-originate-local-000001fc;1", "linePJSIP/ATAxGrandstream2,silentbridge,incogtalker") in new stack [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: Newexten Privilege: dialplan,all Timestamp: 1638110146.950066 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Extension: s Application: ConfBridge AppData: linePJSIP/ATAxGrandstream2,silentbridge,incogtalker [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: app_confbridge.c:1688 join_conference_bridge: Trying to find conference bridge 'linePJSIP/ATAxGrandstream2' [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: app_confbridge.c:1297 conf_update_user_mute: User PJSIP/ATAxGrandstream2-00000081 is unmuted: user:0 system:0. [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: app_confbridge.c:1297 conf_update_user_mute: User Local/91200REDACTED@REDACTED-originate-local-000001fc;1 is unmuted: user:0 system:0. [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: confbridge/conf_state.c:84 conf_change_state: Changing conference 'linePJSIP/ATAxGrandstream2' state from SINGLE to MULTI [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_channel.c:2911 bridge_channel_internal_join: Bridge 8b8bd6e6-e43d-412d-966e-1312f64cf577: 0x7f1ae4033750(Local/91200REDACTED@REDACTED-originate-local-000001fc;1) is joining [2021-11-28 14:35:47] Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK [2021-11-28 14:35:47] Timestamp: 07823ms SCall: 06856 DCall: 12206 ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[1275][C-000000c9]: chan_iax2.c:10423 socket_process_helper: Received packet 4, (6, 4) [2021-11-28 14:35:46] DEBUG[1275][C-000000c9]: chan_iax2.c:10520 socket_process_helper: Cancelling transmission of packet 2 [2021-11-28 14:35:46] DEBUG[1275][C-000000c9]: chan_iax2.c:10694 socket_process_helper: IAX subclass 4 received [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_channel.c:2251 bridge_channel_internal_push_full: Bridge 8b8bd6e6-e43d-412d-966e-1312f64cf577: pushing 0x7f1ae4033750(Local/91200REDACTED@REDACTED-originate-local-000001fc;1) [2021-11-28 14:35:47] -- Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;1 joined 'softmix' base-bridge <8b8bd6e6-e43d-412d-966e-1312f64cf577> [2021-11-28 14:35:46] DEBUG[1173]: cdr.c:1470 cdr_object_finalize: Finalized CDR for Local/91200REDACTED@REDACTED-originate-local-000001fc;1 - start 1638110138.828462 answer 1638110146.914469 end 1638110146.951129 dur 8.122 bill 0.036 dispo ANSWERED [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.951259 SystemName: REDACTED BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: BridgeEnter Privilege: call,all Timestamp: 1638110146.951259 SystemName: REDACTED BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ae40fc938 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ae40fc938 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge.c:448 bridge_channel_complete_join: Bridge 8b8bd6e6-e43d-412d-966e-1312f64cf577: 0x7f1ae4033750(Local/91200REDACTED@REDACTED-originate-local-000001fc;1) is joining softmix technology [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_softmix.c:711 softmix_bridge_join: Local/91200REDACTED@REDACTED-originate-local-000001fc;1: [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: channel.c:5826 set_format: Channel Local/91200REDACTED@REDACTED-originate-local-000001fc;1 setting write format path: slin -> slin [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: dsp.c:508 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: dsp.c:508 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_softmix.c:774 softmix_bridge_join: [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_softmix.c:2472 softmix_bridge_stream_topology_changed: Local/91200REDACTED@REDACTED-originate-local-000001fc;1: [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: bridge_softmix.c:2480 softmix_bridge_stream_topology_changed: Local/91200REDACTED@REDACTED-originate-local-000001fc;1: Not in SFU mode [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.952505 SystemName: REDACTED Channel: PJSIP/ATAxGrandstream2-00000081 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-local Exten: s Priority: 3 Uniqueid: REDACTED-1638110137.1530 Linkedid: REDACTED-1638110137.1530 Variable: BRIDGEPEER Value: CBAnn/linePJSIP/ATAxGrandstream2-000001fb;2,Local/91200REDACTED@REDACTED-originate-local-000001fc;1 [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: VarSet Privilege: dialplan,all Timestamp: 1638110146.952719 SystemName: REDACTED Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Variable: BRIDGEPEER Value: CBAnn/linePJSIP/ATAxGrandstream2-000001fb;2,PJSIP/ATAxGrandstream2-00000081 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: stasis_bridges.c:290 bridge_snapshot_update_create: Update: 0x7f1ae407eba8 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26625][C-000000c9]: stasis_bridges.c:270 bridge_snapshot_update_dtor: Update: 0x7f1ae407eba8 Old: 8b8bd6e6-e43d-412d-966e-1312f64cf577 New: 8b8bd6e6-e43d-412d-966e-1312f64cf577 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:5762 iax2_indicate: Indicating condition 20 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:7764 send_command: Callno 12206: Blocked sending control frame 20. [2021-11-28 14:35:46] DEBUG[1263]: manager.c:6200 match_filter: Examining AMI event: Event: ConfbridgeJoin Privilege: call,all Timestamp: 1638110146.953205 SystemName: REDACTED Conference: linePJSIP/ATAxGrandstream2 BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Admin: No Muted: No [2021-11-28 14:35:46] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: ConfbridgeJoin Privilege: call,all Timestamp: 1638110146.953205 SystemName: REDACTED Conference: linePJSIP/ATAxGrandstream2 BridgeUniqueid: 8b8bd6e6-e43d-412d-966e-1312f64cf577 BridgeType: base BridgeTechnology: softmix BridgeCreator: ConfBridge BridgeName: linePJSIP/ATAxGrandstream2 BridgeNumChannels: 3 BridgeVideoSourceMode: none Channel: Local/91200REDACTED@REDACTED-originate-local-000001fc;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 91200REDACTED CallerIDName: ConnectedLineNum: REDACTED ConnectedLineName: InterLinked Language: en AccountCode: Context: REDACTED-outgoing Exten: s Priority: 9 Uniqueid: REDACTED-1638110138.1535 Linkedid: REDACTED-1638110138.1531 Admin: No Muted: No [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:5762 iax2_indicate: Indicating condition 20 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:7764 send_command: Callno 12206: Blocked sending control frame 20. [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7840 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:46] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7860 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:46] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7880 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7900 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7920 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7940 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip.c:4640 endpt_send_request_cb: 0x7f1af00ac7b0: PJSIP tsx timer expired [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip.c:4644 endpt_send_request_cb: 0x7f1af00ac7b0: Timeout already handled [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip.c:4748 send_request_wrapper_destructor: 0x7f1af00ac7b0: wrapper destroyed [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7960 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 7980 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8000 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_message_filter.c:297 filter_on_tx_message: Re-wrote Contact URI host/port to ASTERISK-SIDE-A-IP:17777 (this may be re-written again later) [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8020 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8040 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8060 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8080 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8100 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8120 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8140 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8160 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8180 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8200 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8220 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8240 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: res_rtp_asterisk.c:6147 ast_rtcp_interpret: (0x7f1ad0091f10) RTCP got report of 416 bytes from 128.91.217.181:5013 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: res_rtp_asterisk.c:6162 ast_rtcp_interpret: (0x7f1ad0091f10) RTCP 0x7f1ad00e2ae0 -- from 128.91.217.181:5013: Failed first packet validity check [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8260 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8280 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_message_filter.c:297 filter_on_tx_message: Re-wrote Contact URI host/port to ASTERISK-SIDE-A-IP:17777 (this may be re-written again later) [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8300 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_options.c:927 sip_options_qualify_aor: Qualifying all contacts on AOR 'ATAxPhilMcCarter2' [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_options.c:857 sip_options_qualify_contact: Qualifying contact 'ATAxPhilMcCarter2;@f5dff686a1a1c8821600e14cf600e926' on AOR 'ATAxPhilMcCarter2' [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip.c:4771 endpt_send_request: 0x7f1af0039010: Wrapper created [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip.c:4786 endpt_send_request: 0x7f1af0039010: Set timer to 10000 msec [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_resolver.c:479 sip_resolve: Performing SIP DNS resolution of target '64.25.144.115' [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_resolver.c:506 sip_resolve: Transport type for target '64.25.144.115' is 'UDP transport' [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_resolver.c:527 sip_resolve: Target '64.25.144.115' is an IP address, skipping resolution [2021-11-28 14:35:47] DEBUG[9540]: res_pjsip/pjsip_message_filter.c:297 filter_on_tx_message: Re-wrote Contact URI host/port to ASTERISK-SIDE-A-IP:17777 (this may be re-written again later) [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8320 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[19225]: manager.c:6200 match_filter: Examining AMI event: Event: RTCPSent Privilege: reporting,all Timestamp: 1638110147.455207 SystemName: REDACTED Channel: PJSIP/ATAxGrandstream2-00000081 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: REDACTED CallerIDName: InterLinked ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: REDACTED-local Exten: s Priority: 3 Uniqueid: REDACTED-1638110137.1530 Linkedid: REDACTED-1638110137.1530 To: 128.91.217.181:5013 From: ASTERISK-SIDE-A-IP:16335 SSRC: 0x40bc0e0e PT: 200(SR) ReportCount: 1 SentNTP: 1638110147.455021 SentRTP: 79763 SentPackets: 500 SentOctets: 84763 Report0SourceSSRC: 0x3b057d7e Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 18218 Report0SequenceNumberCycles: 0 Report0IAJitter: 9 Report0LSR: 0 Report0DLSR: 0.0000 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8340 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8360 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8380 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8400 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8420 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8440 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8460 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_distributor.c:520 distributor: No dialog serializer for Response msg 200/OPTIONS/cseq=54809 (rdata0x5612af06aa18). Using request transaction as basis. [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_distributor.c:128 find_request_serializer: Found transaction tsx0x7f1ad83721e8 for Response msg 200/OPTIONS/cseq=54809 (rdata0x5612af06aa18). [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_distributor.c:138 find_request_serializer: Found serializer pjsip/options/ATAxPhilMcCarter2-00000199 on transaction tsx0x7f1ad83721e8 [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip.c:4649 endpt_send_request_cb: 0x7f1af0039010: PJSIP tsx response received [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip.c:4662 endpt_send_request_cb: 0x7f1af0039010: Cancelling timer [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip.c:4671 endpt_send_request_cb: 0x7f1af0039010: Timer cancelled [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip.c:4692 endpt_send_request_cb: 0x7f1af0039010: Callbacks executed [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip.c:4748 send_request_wrapper_destructor: 0x7f1af0039010: wrapper destroyed [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip/pjsip_options.c:759 sip_options_contact_status_notify_task: Contact ATAxPhilMcCarter2/sip:ATAxPhilMcCarter2@64.25.144.115:51092;x-ast-orig-host=192.168.102.102:5062 status didn't change: Reachable, RTT: 164.732 msec [2021-11-28 14:35:47] DEBUG[14258]: res_pjsip/pjsip_options.c:777 sip_options_contact_status_notify_task: AOR 'ATAxPhilMcCarter2' now has 1 available contacts [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8480 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8500 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8520 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8540 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8560 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8580 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8600 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8620 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8640 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8660 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8680 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 [2021-11-28 14:35:47] DEBUG[1190]: res_pjsip/pjsip_transport_events.c:159 transport_state_callback: Reliable transport 'tcps0x5612b1814598' state:CONNECTED [2021-11-28 14:35:47] DEBUG[26611][C-000000c9]: translate.c:656 ast_translate: Sample size different 320 vs 160 [2021-11-28 14:35:47] DEBUG[26626][C-000000c9]: chan_iax2.c:3414 send_packet: Sending 8700 on 12206/6856 to ASTERISK-SIDE-B-IP:4569 voip*CLI>