[Feb 15 22:39:28] VERBOSE[17716] logger.c: -- AGI Script fixlocalprefix completed, returning 0 [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: AGI [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("IAX2/96021-3", "OUTNUM=840809080080") in new stack [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: Set [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("IAX2/96021-3", "custom=ZAP/g60") in new stack [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: Set [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:15] GotoIf("IAX2/96021-3", "1?gocall") in new stack [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Goto (macro-dialout-trunk,s,17) [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:17] Macro("IAX2/96021-3", "dialout-trunk-predial-hook|") in new stack [Feb 15 22:39:28] WARNING[17716] app_macro.c: Context 'macro-dialout-trunk-predial-hook' for macro 'dialout-trunk-predial-hook' lacks 's' extension, priority 1 [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: Macro [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("IAX2/96021-3", "0?bypass|1") in new stack [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:19] GotoIf("IAX2/96021-3", "0?customtrunk") in new stack [Feb 15 22:39:28] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Executing [s@macro-dialout-trunk:20] Dial("IAX2/96021-3", "ZAP/g60/840809080080|300|") in new stack [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Requested transfer capability: 0x00 - SPEECH [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Called g60/840809080080 [Feb 15 22:39:28] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: VOICE Subclass: 2 [Feb 15 22:39:28] VERBOSE[17537] logger.c: Timestamp: 00440ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:28] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK [Feb 15 22:39:28] VERBOSE[17528] logger.c: Timestamp: 00230ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:28] DEBUG[17541] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1 [Feb 15 22:39:28] VERBOSE[17716] logger.c: -- Zap/1-1 is proceeding passing it to IAX2/96021-3 [Feb 15 22:39:28] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass: PROCDNG [Feb 15 22:39:28] VERBOSE[17537] logger.c: Timestamp: 00443ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:28] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK [Feb 15 22:39:28] VERBOSE[17530] logger.c: Timestamp: 00440ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:28] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK [Feb 15 22:39:28] VERBOSE[17531] logger.c: Timestamp: 00443ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:28] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE Subclass: 2 [Feb 15 22:39:28] VERBOSE[17532] logger.c: Timestamp: 00680ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:28] VERBOSE[17532] logger.c: Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK [Feb 15 22:39:28] VERBOSE[17532] logger.c: Timestamp: 00680ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:29] VERBOSE[17716] logger.c: -- Zap/1-1 is ringing [Feb 15 22:39:29] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass: RINGING [Feb 15 22:39:29] VERBOSE[17537] logger.c: Timestamp: 01663ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:29] DEBUG[17541] chan_zap.c: Queuing frame from PRI_EVENT_PROGRESS on channel 0/1 span 1 [Feb 15 22:39:29] VERBOSE[17716] logger.c: -- Zap/1-1 is making progress passing it to IAX2/96021-3 [Feb 15 22:39:29] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 003 Type: CONTROL Subclass: PROGRES [Feb 15 22:39:29] VERBOSE[17537] logger.c: Timestamp: 01723ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:29] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK [Feb 15 22:39:29] VERBOSE[17531] logger.c: Timestamp: 01663ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:29] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 006 Type: IAX Subclass: ACK [Feb 15 22:39:29] VERBOSE[17535] logger.c: Timestamp: 01723ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:31] DEBUG[17541] chan_zap.c: Echo cancellation already on [Feb 15 22:39:31] VERBOSE[17716] logger.c: -- Zap/1-1 answered IAX2/96021-3 [Feb 15 22:39:31] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 003 Type: CONTROL Subclass: (255?) [Feb 15 22:39:31] VERBOSE[17537] logger.c: Timestamp: 03583ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:31] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 003 Type: CONTROL Subclass: ANSWER [Feb 15 22:39:31] VERBOSE[17537] logger.c: Timestamp: 03586ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:31] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 007 Type: IAX Subclass: ACK [Feb 15 22:39:31] VERBOSE[17531] logger.c: Timestamp: 03583ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:31] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 008 Type: IAX Subclass: ACK [Feb 15 22:39:31] VERBOSE[17532] logger.c: Timestamp: 03586ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:37] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 003 Type: IAX Subclass: LAGRQ [Feb 15 22:39:37] VERBOSE[17537] logger.c: Timestamp: 10023ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:38] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 009 Type: IAX Subclass: ACK [Feb 15 22:39:38] VERBOSE[17532] logger.c: Timestamp: 10023ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:38] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 009 Type: IAX Subclass: LAGRP [Feb 15 22:39:38] VERBOSE[17533] logger.c: Timestamp: 10023ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:38] VERBOSE[17533] logger.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 004 Type: IAX Subclass: ACK [Feb 15 22:39:38] VERBOSE[17533] logger.c: Timestamp: 10023ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:39] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 009 Type: DTMF_E Subclass: 1 [Feb 15 22:39:39] VERBOSE[17530] logger.c: Timestamp: 11323ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:39] VERBOSE[17530] logger.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 005 Type: IAX Subclass: ACK [Feb 15 22:39:39] VERBOSE[17530] logger.c: Timestamp: 11323ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:39] DTMF[17716] channel.c: DTMF end '1' received on IAX2/96021-3, duration 0 ms [Feb 15 22:39:39] DTMF[17716] channel.c: DTMF begin emulation of '1' with duration 130 queued on IAX2/96021-3 [Feb 15 22:39:39] DEBUG[17716] chan_zap.c: Started VLDTMF digit '1' [Feb 15 22:39:39] DTMF[17716] channel.c: DTMF end emulation of '1' queued on IAX2/96021-3 [Feb 15 22:39:39] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '1' [Feb 15 22:39:47] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 005 Type: IAX Subclass: LAGRQ [Feb 15 22:39:47] VERBOSE[17537] logger.c: Timestamp: 19887ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:48] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 009 Type: DTMF_E Subclass: 2 [Feb 15 22:39:48] VERBOSE[17533] logger.c: Timestamp: 19963ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:48] VERBOSE[17533] logger.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 006 Type: IAX Subclass: ACK [Feb 15 22:39:48] VERBOSE[17533] logger.c: Timestamp: 19963ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:48] DTMF[17716] channel.c: DTMF end '2' received on IAX2/96021-3, duration 0 ms [Feb 15 22:39:48] DTMF[17716] channel.c: DTMF begin emulation of '2' with duration 130 queued on IAX2/96021-3 [Feb 15 22:39:48] DEBUG[17716] chan_zap.c: Started VLDTMF digit '2' [Feb 15 22:39:48] DTMF[17716] channel.c: DTMF end emulation of '2' queued on IAX2/96021-3 [Feb 15 22:39:48] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '2' [Feb 15 22:39:48] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 010 Type: IAX Subclass: ACK [Feb 15 22:39:48] VERBOSE[17532] logger.c: Timestamp: 19887ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:48] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 010 Type: IAX Subclass: LAGRP [Feb 15 22:39:48] VERBOSE[17535] logger.c: Timestamp: 19887ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:48] VERBOSE[17535] logger.c: Tx-Frame Retry[-01] -- OSeqno: 010 ISeqno: 007 Type: IAX Subclass: ACK [Feb 15 22:39:48] VERBOSE[17535] logger.c: Timestamp: 19887ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:48] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 007 Type: IAX Subclass: PING [Feb 15 22:39:48] VERBOSE[17537] logger.c: Timestamp: 20903ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:49] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 011 Type: IAX Subclass: ACK [Feb 15 22:39:49] VERBOSE[17534] logger.c: Timestamp: 20903ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:49] VERBOSE[17527] logger.c: Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 011 Type: IAX Subclass: PONG [Feb 15 22:39:49] VERBOSE[17527] logger.c: Timestamp: 20903ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:49] VERBOSE[17527] logger.c: RR_JITTER : 0 [Feb 15 22:39:49] VERBOSE[17527] logger.c: [Feb 15 22:39:49] VERBOSE[17527] logger.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 008 Type: IAX Subclass: ACK [Feb 15 22:39:49] VERBOSE[17527] logger.c: Timestamp: 20903ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:51] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 011 Type: DTMF_E Subclass: 1 [Feb 15 22:39:51] VERBOSE[17534] logger.c: Timestamp: 23043ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:51] VERBOSE[17534] logger.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 009 Type: IAX Subclass: ACK [Feb 15 22:39:51] VERBOSE[17534] logger.c: Timestamp: 23043ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:51] DTMF[17716] channel.c: DTMF end '1' received on IAX2/96021-3, duration 0 ms [Feb 15 22:39:51] DTMF[17716] channel.c: DTMF begin emulation of '1' with duration 130 queued on IAX2/96021-3 [Feb 15 22:39:51] DEBUG[17716] chan_zap.c: Started VLDTMF digit '1' [Feb 15 22:39:52] DTMF[17716] channel.c: DTMF end emulation of '1' queued on IAX2/96021-3 [Feb 15 22:39:52] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '1' [Feb 15 22:39:55] VERBOSE[17526] logger.c: Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 011 Type: DTMF_E Subclass: 1 [Feb 15 22:39:55] VERBOSE[17526] logger.c: Timestamp: 26443ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:55] VERBOSE[17526] logger.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 010 Type: IAX Subclass: ACK [Feb 15 22:39:55] VERBOSE[17526] logger.c: Timestamp: 26443ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:55] DTMF[17716] channel.c: DTMF end '1' received on IAX2/96021-3, duration 0 ms [Feb 15 22:39:55] DTMF[17716] channel.c: DTMF begin emulation of '1' with duration 130 queued on IAX2/96021-3 [Feb 15 22:39:55] DEBUG[17716] chan_zap.c: Started VLDTMF digit '1' [Feb 15 22:39:55] DTMF[17716] channel.c: DTMF end emulation of '1' queued on IAX2/96021-3 [Feb 15 22:39:55] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '1' [Feb 15 22:39:57] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 011 ISeqno: 010 Type: IAX Subclass: LAGRQ [Feb 15 22:39:57] VERBOSE[17537] logger.c: Timestamp: 29630ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:58] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 011 Type: DTMF_E Subclass: 1 [Feb 15 22:39:58] VERBOSE[17528] logger.c: Timestamp: 29663ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:58] VERBOSE[17528] logger.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass: ACK [Feb 15 22:39:58] VERBOSE[17528] logger.c: Timestamp: 29663ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:39:58] DTMF[17716] channel.c: DTMF end '1' received on IAX2/96021-3, duration 0 ms [Feb 15 22:39:58] DTMF[17716] channel.c: DTMF begin emulation of '1' with duration 130 queued on IAX2/96021-3 [Feb 15 22:39:58] DEBUG[17716] chan_zap.c: Started VLDTMF digit '1' [Feb 15 22:39:58] DTMF[17716] channel.c: DTMF end emulation of '1' queued on IAX2/96021-3 [Feb 15 22:39:58] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '1' [Feb 15 22:39:59] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 012 Type: IAX Subclass: ACK [Feb 15 22:39:59] VERBOSE[17535] logger.c: Timestamp: 29630ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:59] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 012 Type: IAX Subclass: LAGRP [Feb 15 22:39:59] VERBOSE[17534] logger.c: Timestamp: 29630ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:39:59] VERBOSE[17534] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 012 Type: IAX Subclass: ACK [Feb 15 22:39:59] VERBOSE[17534] logger.c: Timestamp: 29630ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 012 ISeqno: 012 Type: DTMF_E Subclass: 1 [Feb 15 22:40:02] VERBOSE[17531] logger.c: Timestamp: 33223ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17531] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 013 Type: IAX Subclass: ACK [Feb 15 22:40:02] VERBOSE[17531] logger.c: Timestamp: 33223ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end '1' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF begin emulation of '1' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Started VLDTMF digit '1' [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end emulation of '1' queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '1' [Feb 15 22:40:02] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 012 Type: DTMF_E Subclass: 2 [Feb 15 22:40:02] VERBOSE[17532] logger.c: Timestamp: 33423ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17532] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 014 Type: IAX Subclass: ACK [Feb 15 22:40:02] VERBOSE[17532] logger.c: Timestamp: 33423ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end '2' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end '2' put into dtmf queue on IAX2/96021-3 [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF begin emulation of '2' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Started VLDTMF digit '2' [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end emulation of '2' queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '2' [Feb 15 22:40:02] VERBOSE[17526] logger.c: Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 012 Type: DTMF_E Subclass: 3 [Feb 15 22:40:02] VERBOSE[17526] logger.c: Timestamp: 33683ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17526] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 015 Type: IAX Subclass: ACK [Feb 15 22:40:02] VERBOSE[17526] logger.c: Timestamp: 33683ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end '3' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF begin emulation of '3' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Started VLDTMF digit '3' [Feb 15 22:40:02] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ [Feb 15 22:40:02] VERBOSE[17530] logger.c: Timestamp: 00003ms SCall: 00096 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17530] logger.c: USERNAME : 96021 [Feb 15 22:40:02] VERBOSE[17530] logger.c: REFRESH : 60 [Feb 15 22:40:02] VERBOSE[17530] logger.c: [Feb 15 22:40:02] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGACK [Feb 15 22:40:02] VERBOSE[17537] logger.c: Timestamp: 00012ms SCall: 00001 DCall: 00096 [61.57.3.177:4569] [Feb 15 22:40:02] VERBOSE[17537] logger.c: USERNAME : 96021 [Feb 15 22:40:02] VERBOSE[17537] logger.c: DATE TIME : 2008-02-15 22:40:02 [Feb 15 22:40:02] VERBOSE[17537] logger.c: REFRESH : 60 [Feb 15 22:40:02] VERBOSE[17537] logger.c: APPARENT ADDRES : IPV4 61.57.3.177:4569 [Feb 15 22:40:02] VERBOSE[17537] logger.c: MESSAGE COUNT : 0 [Feb 15 22:40:02] VERBOSE[17537] logger.c: CALLING NUMBER : 96021 [Feb 15 22:40:02] VERBOSE[17537] logger.c: CALLING NAME : device [Feb 15 22:40:02] VERBOSE[17537] logger.c: [Feb 15 22:40:02] DTMF[17716] channel.c: DTMF end emulation of '3' queued on IAX2/96021-3 [Feb 15 22:40:02] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '3' [Feb 15 22:40:03] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 015 ISeqno: 012 Type: DTMF_E Subclass: 4 [Feb 15 22:40:03] VERBOSE[17528] logger.c: Timestamp: 33903ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:03] VERBOSE[17528] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 016 Type: IAX Subclass: ACK [Feb 15 22:40:03] VERBOSE[17528] logger.c: Timestamp: 33903ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '4' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF begin emulation of '4' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Started VLDTMF digit '4' [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end emulation of '4' queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '4' [Feb 15 22:40:03] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 016 ISeqno: 012 Type: DTMF_E Subclass: 5 [Feb 15 22:40:03] VERBOSE[17531] logger.c: Timestamp: 34123ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:03] VERBOSE[17531] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 017 Type: IAX Subclass: ACK [Feb 15 22:40:03] VERBOSE[17531] logger.c: Timestamp: 34123ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '5' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF begin emulation of '5' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Started VLDTMF digit '5' [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end emulation of '5' queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '5' [Feb 15 22:40:03] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 017 ISeqno: 012 Type: DTMF_E Subclass: 6 [Feb 15 22:40:03] VERBOSE[17533] logger.c: Timestamp: 34343ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:03] VERBOSE[17533] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 018 Type: IAX Subclass: ACK [Feb 15 22:40:03] VERBOSE[17533] logger.c: Timestamp: 34343ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '6' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF begin emulation of '6' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Started VLDTMF digit '6' [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end emulation of '6' queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '6' [Feb 15 22:40:03] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 018 ISeqno: 012 Type: DTMF_E Subclass: 7 [Feb 15 22:40:03] VERBOSE[17534] logger.c: Timestamp: 34563ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:03] VERBOSE[17534] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 019 Type: IAX Subclass: ACK [Feb 15 22:40:03] VERBOSE[17534] logger.c: Timestamp: 34563ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '7' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF begin emulation of '7' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Started VLDTMF digit '7' [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end emulation of '7' queued on IAX2/96021-3 [Feb 15 22:40:03] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '7' [Feb 15 22:40:03] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 019 ISeqno: 012 Type: DTMF_E Subclass: 8 [Feb 15 22:40:03] VERBOSE[17535] logger.c: Timestamp: 34723ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:03] VERBOSE[17535] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 020 Type: IAX Subclass: ACK [Feb 15 22:40:03] VERBOSE[17535] logger.c: Timestamp: 34723ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '8' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:03] DTMF[17716] channel.c: DTMF end '8' put into dtmf queue on IAX2/96021-3 [Feb 15 22:40:04] DTMF[17716] channel.c: DTMF begin emulation of '8' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:04] DEBUG[17716] chan_zap.c: Started VLDTMF digit '8' [Feb 15 22:40:04] DTMF[17716] channel.c: DTMF end emulation of '8' queued on IAX2/96021-3 [Feb 15 22:40:04] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '8' [Feb 15 22:40:04] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:04] VERBOSE[17534] logger.c: Timestamp: 00012ms SCall: 00096 DCall: 00001 [61.57.3.177:4569] [Feb 15 22:40:07] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 012 ISeqno: 020 Type: IAX Subclass: LAGRQ [Feb 15 22:40:07] VERBOSE[17537] logger.c: Timestamp: 39293ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:09] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 020 ISeqno: 013 Type: IAX Subclass: ACK [Feb 15 22:40:09] VERBOSE[17531] logger.c: Timestamp: 39293ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:09] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 020 ISeqno: 013 Type: IAX Subclass: LAGRP [Feb 15 22:40:09] VERBOSE[17532] logger.c: Timestamp: 39293ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:09] VERBOSE[17532] logger.c: Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 021 Type: IAX Subclass: ACK [Feb 15 22:40:09] VERBOSE[17532] logger.c: Timestamp: 39293ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:09] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 013 ISeqno: 021 Type: IAX Subclass: PING [Feb 15 22:40:09] VERBOSE[17537] logger.c: Timestamp: 41285ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:11] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 021 ISeqno: 014 Type: IAX Subclass: ACK [Feb 15 22:40:11] VERBOSE[17532] logger.c: Timestamp: 41285ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:11] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 021 ISeqno: 014 Type: IAX Subclass: PONG [Feb 15 22:40:11] VERBOSE[17533] logger.c: Timestamp: 41285ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:11] VERBOSE[17533] logger.c: RR_JITTER : 0 [Feb 15 22:40:11] VERBOSE[17533] logger.c: [Feb 15 22:40:11] VERBOSE[17533] logger.c: Tx-Frame Retry[-01] -- OSeqno: 014 ISeqno: 022 Type: IAX Subclass: ACK [Feb 15 22:40:11] VERBOSE[17533] logger.c: Timestamp: 41285ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:11] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [Feb 15 22:40:11] VERBOSE[17537] logger.c: Timestamp: 00002ms SCall: 00004 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:40:12] VERBOSE[17528] logger.c: Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [Feb 15 22:40:12] VERBOSE[17528] logger.c: Timestamp: 00002ms SCall: 00004 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:40:13] VERBOSE[17527] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:13] VERBOSE[17527] logger.c: Timestamp: 00002ms SCall: 00097 DCall: 00004 [61.57.3.177:4569] [Feb 15 22:40:13] VERBOSE[17529] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [Feb 15 22:40:13] VERBOSE[17529] logger.c: Timestamp: 00002ms SCall: 00097 DCall: 00004 [61.57.3.177:4569] [Feb 15 22:40:13] VERBOSE[17529] logger.c: RR_JITTER : 0 [Feb 15 22:40:13] VERBOSE[17529] logger.c: [Feb 15 22:40:13] NOTICE[17529] chan_iax2.c: Peer '96021' is now TOO LAGGED (2006 ms)! [Feb 15 22:40:13] VERBOSE[17529] logger.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:13] VERBOSE[17529] logger.c: Timestamp: 00002ms SCall: 00004 DCall: 00097 [61.57.3.177:4569] [Feb 15 22:40:14] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:14] VERBOSE[17531] logger.c: Timestamp: 00002ms SCall: 00098 DCall: 00004 [61.57.3.177:4569] [Feb 15 22:40:14] VERBOSE[17531] logger.c: Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL [Feb 15 22:40:14] VERBOSE[17531] logger.c: Timestamp: 00000ms SCall: 00004 DCall: 00098 [61.57.3.177:4569] [Feb 15 22:40:14] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [Feb 15 22:40:14] VERBOSE[17532] logger.c: Timestamp: 00002ms SCall: 00098 DCall: 00004 [61.57.3.177:4569] [Feb 15 22:40:14] VERBOSE[17532] logger.c: RR_JITTER : 0 [Feb 15 22:40:14] VERBOSE[17532] logger.c: [Feb 15 22:40:14] VERBOSE[17532] logger.c: Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL [Feb 15 22:40:14] VERBOSE[17532] logger.c: Timestamp: 00000ms SCall: 00004 DCall: 00098 [61.57.3.177:4569] [Feb 15 22:40:16] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 022 ISeqno: 014 Type: DTMF_E Subclass: 2 [Feb 15 22:40:16] VERBOSE[17528] logger.c: Timestamp: 46443ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:16] VERBOSE[17528] logger.c: Tx-Frame Retry[-01] -- OSeqno: 014 ISeqno: 023 Type: IAX Subclass: ACK [Feb 15 22:40:16] VERBOSE[17528] logger.c: Timestamp: 46443ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:16] DTMF[17716] channel.c: DTMF end '2' received on IAX2/96021-3, duration 0 ms [Feb 15 22:40:16] DTMF[17716] channel.c: DTMF begin emulation of '2' with duration 130 queued on IAX2/96021-3 [Feb 15 22:40:16] DEBUG[17716] chan_zap.c: Started VLDTMF digit '2' [Feb 15 22:40:16] DTMF[17716] channel.c: DTMF end emulation of '2' queued on IAX2/96021-3 [Feb 15 22:40:16] DEBUG[17716] chan_zap.c: Ending VLDTMF digit '2' [Feb 15 22:40:17] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 014 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:17] VERBOSE[17537] logger.c: Timestamp: 49157ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:21] VERBOSE[17534] logger.c: Rx-Frame Retry[ No] -- OSeqno: 024 ISeqno: 015 Type: DTMF_E Subclass: 8 [Feb 15 22:40:21] VERBOSE[17534] logger.c: Timestamp: 51983ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:21] VERBOSE[17534] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:21] VERBOSE[17534] logger.c: Timestamp: 52967ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:21] VERBOSE[17528] logger.c: Tx-Frame Retry[001] -- OSeqno: 014 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:21] VERBOSE[17528] logger.c: Timestamp: 49157ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:21] VERBOSE[17529] logger.c: Rx-Frame Retry[ No] -- OSeqno: 025 ISeqno: 015 Type: DTMF_E Subclass: 7 [Feb 15 22:40:21] VERBOSE[17529] logger.c: Timestamp: 52203ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:21] VERBOSE[17529] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:21] VERBOSE[17529] logger.c: Timestamp: 53201ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 026 ISeqno: 015 Type: DTMF_E Subclass: 6 [Feb 15 22:40:22] VERBOSE[17530] logger.c: Timestamp: 52423ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17530] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:22] VERBOSE[17530] logger.c: Timestamp: 53448ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 027 ISeqno: 015 Type: DTMF_E Subclass: 5 [Feb 15 22:40:22] VERBOSE[17532] logger.c: Timestamp: 52643ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17532] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:22] VERBOSE[17532] logger.c: Timestamp: 53679ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17526] logger.c: Rx-Frame Retry[ No] -- OSeqno: 028 ISeqno: 015 Type: DTMF_E Subclass: 4 [Feb 15 22:40:22] VERBOSE[17526] logger.c: Timestamp: 52863ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17526] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:22] VERBOSE[17526] logger.c: Timestamp: 53752ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 029 ISeqno: 015 Type: DTMF_E Subclass: 3 [Feb 15 22:40:22] VERBOSE[17530] logger.c: Timestamp: 53123ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17530] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:22] VERBOSE[17530] logger.c: Timestamp: 54023ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 030 ISeqno: 015 Type: DTMF_E Subclass: 2 [Feb 15 22:40:22] VERBOSE[17535] logger.c: Timestamp: 53363ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:22] VERBOSE[17535] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:22] VERBOSE[17535] logger.c: Timestamp: 54276ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:23] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 031 ISeqno: 015 Type: DTMF_E Subclass: 1 [Feb 15 22:40:23] VERBOSE[17535] logger.c: Timestamp: 53543ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:23] VERBOSE[17535] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:23] VERBOSE[17535] logger.c: Timestamp: 54467ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:23] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 023 ISeqno: 015 Type: IAX Subclass: ACK [Feb 15 22:40:23] VERBOSE[17533] logger.c: Timestamp: 49157ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:23] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [Feb 15 22:40:23] VERBOSE[17537] logger.c: Timestamp: 00015ms SCall: 00002 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:40:24] VERBOSE[17535] logger.c: Tx-Frame Retry[001] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [Feb 15 22:40:24] VERBOSE[17535] logger.c: Timestamp: 00015ms SCall: 00002 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:40:25] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:25] VERBOSE[17530] logger.c: Timestamp: 00015ms SCall: 00099 DCall: 00002 [61.57.3.177:4569] [Feb 15 22:40:25] VERBOSE[17531] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [Feb 15 22:40:25] VERBOSE[17531] logger.c: Timestamp: 00015ms SCall: 00099 DCall: 00002 [61.57.3.177:4569] [Feb 15 22:40:25] VERBOSE[17531] logger.c: RR_JITTER : 0 [Feb 15 22:40:25] VERBOSE[17531] logger.c: [Feb 15 22:40:25] NOTICE[17531] chan_iax2.c: Peer '96021' is now REACHABLE! Time: 1938 [Feb 15 22:40:25] VERBOSE[17531] logger.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:25] VERBOSE[17531] logger.c: Timestamp: 00015ms SCall: 00002 DCall: 00099 [61.57.3.177:4569] [Feb 15 22:40:26] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:40:26] VERBOSE[17532] logger.c: Timestamp: 00015ms SCall: 00100 DCall: 00002 [61.57.3.177:4569] [Feb 15 22:40:26] VERBOSE[17532] logger.c: Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL [Feb 15 22:40:26] VERBOSE[17532] logger.c: Timestamp: 00000ms SCall: 00002 DCall: 00100 [61.57.3.177:4569] [Feb 15 22:40:26] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [Feb 15 22:40:26] VERBOSE[17533] logger.c: Timestamp: 00015ms SCall: 00100 DCall: 00002 [61.57.3.177:4569] [Feb 15 22:40:26] VERBOSE[17533] logger.c: RR_JITTER : 0 [Feb 15 22:40:26] VERBOSE[17533] logger.c: [Feb 15 22:40:26] VERBOSE[17533] logger.c: Tx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL [Feb 15 22:40:26] VERBOSE[17533] logger.c: Timestamp: 00000ms SCall: 00002 DCall: 00100 [61.57.3.177:4569] [Feb 15 22:40:27] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 015 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:27] VERBOSE[17537] logger.c: Timestamp: 59161ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:30] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 023 ISeqno: 016 Type: IAX Subclass: ACK [Feb 15 22:40:30] VERBOSE[17528] logger.c: Timestamp: 59161ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:30] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 032 ISeqno: 016 Type: IAX Subclass: LAGRP [Feb 15 22:40:30] VERBOSE[17530] logger.c: Timestamp: 59161ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:30] VERBOSE[17530] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:30] VERBOSE[17530] logger.c: Timestamp: 61356ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:30] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 016 ISeqno: 023 Type: IAX Subclass: PING [Feb 15 22:40:30] VERBOSE[17537] logger.c: Timestamp: 62149ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:32] VERBOSE[17529] logger.c: Rx-Frame Retry[ No] -- OSeqno: 023 ISeqno: 017 Type: IAX Subclass: ACK [Feb 15 22:40:32] VERBOSE[17529] logger.c: Timestamp: 62149ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:32] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 033 ISeqno: 017 Type: IAX Subclass: PONG [Feb 15 22:40:32] VERBOSE[17528] logger.c: Timestamp: 62149ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:32] VERBOSE[17528] logger.c: RR_JITTER : 0 [Feb 15 22:40:32] VERBOSE[17528] logger.c: [Feb 15 22:40:32] VERBOSE[17528] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:32] VERBOSE[17528] logger.c: Timestamp: 64212ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:35] VERBOSE[17529] logger.c: Rx-Frame Retry[ No] -- OSeqno: 034 ISeqno: 017 Type: VOICE Subclass: 2 [Feb 15 22:40:35] VERBOSE[17529] logger.c: Timestamp: 65540ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:35] VERBOSE[17529] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:35] VERBOSE[17529] logger.c: Timestamp: 66463ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:37] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 035 ISeqno: 017 Type: DTMF_E Subclass: 2 [Feb 15 22:40:37] VERBOSE[17530] logger.c: Timestamp: 67963ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:37] VERBOSE[17530] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:37] VERBOSE[17530] logger.c: Timestamp: 68947ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:37] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 017 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:37] VERBOSE[17537] logger.c: Timestamp: 69163ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:39] VERBOSE[17532] logger.c: Rx-Frame Retry[ No] -- OSeqno: 023 ISeqno: 018 Type: IAX Subclass: ACK [Feb 15 22:40:39] VERBOSE[17532] logger.c: Timestamp: 69163ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:39] VERBOSE[17535] logger.c: Rx-Frame Retry[ No] -- OSeqno: 036 ISeqno: 018 Type: IAX Subclass: LAGRP [Feb 15 22:40:39] VERBOSE[17535] logger.c: Timestamp: 69163ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:39] VERBOSE[17535] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:39] VERBOSE[17535] logger.c: Timestamp: 71255ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:47] VERBOSE[17533] logger.c: Rx-Frame Retry[ No] -- OSeqno: 037 ISeqno: 018 Type: IAX Subclass: HANGUP [Feb 15 22:40:47] VERBOSE[17533] logger.c: Timestamp: 77828ms SCall: 00095 DCall: 00003 [61.57.3.177:4569] [Feb 15 22:40:47] VERBOSE[17533] logger.c: CAUSE : User call hangup [Feb 15 22:40:47] VERBOSE[17533] logger.c: [Feb 15 22:40:47] VERBOSE[17533] logger.c: Tx-Frame Retry[000] -- OSeqno: 023 ISeqno: 023 Type: IAX Subclass: VNAK [Feb 15 22:40:47] VERBOSE[17533] logger.c: Timestamp: 78595ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:47] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 018 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:47] VERBOSE[17537] logger.c: Timestamp: 79167ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:51] VERBOSE[17534] logger.c: Tx-Frame Retry[001] -- OSeqno: 018 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:51] VERBOSE[17534] logger.c: Timestamp: 79167ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:51] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 019 ISeqno: 023 Type: IAX Subclass: PING [Feb 15 22:40:51] VERBOSE[17537] logger.c: Timestamp: 83151ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:55] VERBOSE[17527] logger.c: Tx-Frame Retry[001] -- OSeqno: 019 ISeqno: 023 Type: IAX Subclass: PING [Feb 15 22:40:55] VERBOSE[17527] logger.c: Timestamp: 83151ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:40:57] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 020 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:40:57] VERBOSE[17537] logger.c: Timestamp: 89170ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:41:01] VERBOSE[17528] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ [Feb 15 22:41:01] VERBOSE[17528] logger.c: Timestamp: 00003ms SCall: 00101 DCall: 00000 [61.57.3.177:4569] [Feb 15 22:41:01] VERBOSE[17528] logger.c: USERNAME : 96021 [Feb 15 22:41:01] VERBOSE[17528] logger.c: REFRESH : 60 [Feb 15 22:41:01] VERBOSE[17528] logger.c: [Feb 15 22:41:01] VERBOSE[17537] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGACK [Feb 15 22:41:01] VERBOSE[17537] logger.c: Timestamp: 00015ms SCall: 00005 DCall: 00101 [61.57.3.177:4569] [Feb 15 22:41:01] VERBOSE[17537] logger.c: USERNAME : 96021 [Feb 15 22:41:01] VERBOSE[17537] logger.c: DATE TIME : 2008-02-15 22:41:00 [Feb 15 22:41:01] VERBOSE[17537] logger.c: REFRESH : 60 [Feb 15 22:41:01] VERBOSE[17537] logger.c: APPARENT ADDRES : IPV4 61.57.3.177:4569 [Feb 15 22:41:01] VERBOSE[17537] logger.c: MESSAGE COUNT : 0 [Feb 15 22:41:01] VERBOSE[17537] logger.c: CALLING NUMBER : 96021 [Feb 15 22:41:01] VERBOSE[17537] logger.c: CALLING NAME : device [Feb 15 22:41:01] VERBOSE[17537] logger.c: [Feb 15 22:41:01] VERBOSE[17530] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [Feb 15 22:41:01] VERBOSE[17530] logger.c: Timestamp: 00015ms SCall: 00101 DCall: 00005 [61.57.3.177:4569] [Feb 15 22:41:01] VERBOSE[17531] logger.c: Tx-Frame Retry[002] -- OSeqno: 018 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:41:01] VERBOSE[17531] logger.c: Timestamp: 79167ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:41:01] VERBOSE[17532] logger.c: Tx-Frame Retry[001] -- OSeqno: 020 ISeqno: 023 Type: IAX Subclass: LAGRQ [Feb 15 22:41:01] VERBOSE[17532] logger.c: Timestamp: 89170ms SCall: 00003 DCall: 00095 [61.57.3.177:4569] [Feb 15 22:41:07] VERBOSE[17701] logger.c: -- Remote UNIX connection disconnected [Feb 15 22:41:21] WARNING[17535] chan_iax2.c: Max retries exceeded to host 61.57.3.177 on IAX2/96021-3 (type = 6, subclass = 11, ts=79167, seqno=18) [Feb 15 22:41:21] DEBUG[17716] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1 [Feb 15 22:41:21] DEBUG[17716] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Feb 15 22:41:21] DEBUG[17716] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Hungup 'Zap/1-1' [Feb 15 22:41:21] VERBOSE[17716] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'IAX2/96021-3' in macro 'dialout-trunk' [Feb 15 22:41:21] VERBOSE[17716] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'IAX2/96021-3' [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [h@macro-dialout-trunk:1] Macro("IAX2/96021-3", "hangupcall|") in new stack [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("IAX2/96021-3", "w") in new stack [Feb 15 22:41:21] DEBUG[17716] app_macro.c: Executed application: ResetCDR [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("IAX2/96021-3", "") in new stack [Feb 15 22:41:21] DEBUG[17716] app_macro.c: Executed application: NoCDR [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("IAX2/96021-3", "1?skiprg") in new stack [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Goto (macro-hangupcall,s,6) [Feb 15 22:41:21] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("IAX2/96021-3", "1?skipblkvm") in new stack [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Goto (macro-hangupcall,s,9) [Feb 15 22:41:21] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("IAX2/96021-3", "1?theend") in new stack [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Goto (macro-hangupcall,s,11) [Feb 15 22:41:21] DEBUG[17716] app_macro.c: Executed application: GotoIf [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("IAX2/96021-3", "") in new stack [Feb 15 22:41:21] VERBOSE[17716] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'IAX2/96021-3' in macro 'hangupcall' [Feb 15 22:41:21] VERBOSE[17716] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'IAX2/96021-3' [Feb 15 22:41:21] VERBOSE[17716] logger.c: -- Hungup 'IAX2/96021-3'