[2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: Timestamp: 00004ms SCall: 16489 DCall: 00000 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: VERSION : 2 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLED NUMBER : 5xxxx7 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CODEC_PREFS : (alaw) [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLING NUMBER : 017xxxxxxx5 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLING PRESNTN : 0 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLING TYPEOFN : 0 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLING TRANSIT : 0 [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: CALLING NAME : [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: LANGUAGE : en [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: USERNAME : trunk [2012-03-07 19:06:02.244] VERBOSE[27620] chan_iax2.c: FORMAT : 8 [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: FORMAT2 : alaw [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: CAPABILITY : 8 [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: CAPABILITY2 : alaw [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: ADSICPE : 2 [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: DATE TIME : 2012-03-07 19:06:02 [2012-03-07 19:06:02.245] VERBOSE[27620] chan_iax2.c: [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: Timestamp: 00065ms SCall: 16489 DCall: 00000 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: VERSION : 2 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLED NUMBER : 5xxxx7 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CODEC_PREFS : (alaw) [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLING NUMBER : 017xxxxxxx5 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLING PRESNTN : 0 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLING TYPEOFN : 0 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLING TRANSIT : 0 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLING NAME : [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: LANGUAGE : en [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: USERNAME : trunk [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: FORMAT : 8 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: FORMAT2 : alaw [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CAPABILITY : 8 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CAPABILITY2 : alaw [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: ADSICPE : 2 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: DATE TIME : 2012-03-07 19:06:02 [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: CALLTOKEN : 51 bytes [2012-03-07 19:06:02.304] VERBOSE[27621] chan_iax2.c: [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: ip callno count incremented to 2 for 10.xxx.xxx.xx2 [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: New max nontrunk callno is 1106 [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: Creating new call structure 1105 [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: Received packet 0, (6, 1) [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: IAX subclass 1 received [2012-03-07 19:06:02.304] DEBUG[27621] chan_iax2.c: For call=1105, set last=65 [2012-03-07 19:06:02.304] DEBUG[27616] chan_iax2.c: Sending 4 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.304] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: AUTHREQ [2012-03-07 19:06:02.304] VERBOSE[27616] chan_iax2.c: Timestamp: 00004ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.305] VERBOSE[27616] chan_iax2.c: AUTHMETHODS : 3 [2012-03-07 19:06:02.305] VERBOSE[27616] chan_iax2.c: CHALLENGE : [2012-03-07 19:06:02.305] VERBOSE[27616] chan_iax2.c: USERNAME : trunk [2012-03-07 19:06:02.305] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:02.362] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: AUTHREP [2012-03-07 19:06:02.362] VERBOSE[27622] chan_iax2.c: Timestamp: 00125ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.362] VERBOSE[27622] chan_iax2.c: MD5 RESULT : 66edfd983dca114b02a26426d8cdb005 [2012-03-07 19:06:02.362] VERBOSE[27622] chan_iax2.c: [2012-03-07 19:06:02.362] DEBUG[27622] chan_iax2.c: Received packet 1, (6, 9) [2012-03-07 19:06:02.362] DEBUG[27622] chan_iax2.c: Cancelling transmission of packet 0 [2012-03-07 19:06:02.362] DEBUG[27622] chan_iax2.c: IAX subclass 9 received [2012-03-07 19:06:02.362] DEBUG[27622] chan_iax2.c: For call=1105, set last=125 [2012-03-07 19:06:02.362] VERBOSE[27622] chan_iax2.c: -- Accepting AUTHENTICATED call from 10.xxx.xxx.xx2: [2012-03-07 19:06:02.362] DEBUG[27616] chan_iax2.c: Sending 62 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.362] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACCEPT [2012-03-07 19:06:02.362] VERBOSE[27616] chan_iax2.c: Timestamp: 00062ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.362] VERBOSE[27616] chan_iax2.c: FORMAT : 8 [2012-03-07 19:06:02.362] VERBOSE[27616] chan_iax2.c: FORMAT2 : alaw [2012-03-07 19:06:02.362] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Function result is '017xxxxxxx5' [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Launching 'NoOp' [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Executing [5xxxx7@callfromext:1] NoOp("IAX2/trunk-1105", "--- 017xxxxxxx5 calling on oh-trunk 5xxxx7 ---") in new stack [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Executing [5xxxx7@callfromext:2] Set("IAX2/trunk-1105", "trunkname=INTTRUNKPRIV") in new stack [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Function result is '017xxxxxxx5' [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Executing [5xxxx7@callfromext:3] Set("IAX2/trunk-1105", "CALLERID(all)=<9017xxxxxxx5>") in new stack [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Launching 'Goto' [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Executing [5xxxx7@callfromext:4] Goto("IAX2/trunk-1105", "out-to-pbx,5xxxx7,1") in new stack [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Goto (out-to-pbx,5xxxx7,1) [2012-03-07 19:06:02.362] DEBUG[27648] pbx.c: Launching 'Gosub' [2012-03-07 19:06:02.362] VERBOSE[27648] pbx.c: -- Executing [5xxxx7@out-to-pbx:1] Gosub("IAX2/trunk-1105", "dialpbx,s,1(5xxxx7,INTTRUNKPRIV,xx@xx.xx.xx)") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] app_stack.c: Channel IAX2/trunk-1105 has no datastore, so we're allocating one. [2012-03-07 19:06:02.363] DEBUG[27648] app_stack.c: Setting 'ARG1' to '5xxxx7' [2012-03-07 19:06:02.363] DEBUG[27648] app_stack.c: Setting 'ARG2' to 'INTTRUNKPRIV' [2012-03-07 19:06:02.363] DEBUG[27648] app_stack.c: Setting 'ARG3' to 'xx@xx.xx.xx' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Function result is '9017xxxxxxx5' [2012-03-07 19:06:02.363] DEBUG[27648] func_strings.c: Allowed: 0123456789 [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Function result is '9017xxxxxxx5' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:1] Set("IAX2/trunk-1105", "CALLERID(num)=9017xxxxxxx5") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Function result is '9017xxxxxxx5' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:2] Set("IAX2/trunk-1105", "DB(lastcaller/5xxxx7)=9017xxxxxxx5") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Function result is '1331147162' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:3] Set("IAX2/trunk-1105", "DB(lastcallertime/5xxxx7)=1331147162") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'Set' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:4] Set("IAX2/trunk-1105", "ExtenEmail=xx@xx.xx.xx") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Expression result is '0' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'GotoIf' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:5] GotoIf("IAX2/trunk-1105", "0?9:6") in new stack [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Goto (dialpbx,s,6) [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Function result is 'DAHDI/G3' [2012-03-07 19:06:02.363] DEBUG[27648] pbx.c: Launching 'Dial' [2012-03-07 19:06:02.363] VERBOSE[27648] pbx.c: -- Executing [s@dialpbx:6] Dial("IAX2/trunk-1105", "DAHDI/G3/5xxxx7,16") in new stack [2012-03-07 19:06:02.363] DEBUG[27648] chan_dahdi.c: Using channel 62 [2012-03-07 19:06:02.363] DEBUG[27648] sig_pri.c: sig_pri_request 62 [2012-03-07 19:06:02.363] DEBUG[27648] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2012-03-07 19:06:02.363] DEBUG[27648] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2012-03-07 19:06:02.364] DEBUG[27608] devicestate.c: Changing state for DAHDI/i2/5xxxx7 - state 2 (In use) [2012-03-07 19:06:02.364] DEBUG[27608] devicestate.c: device 'DAHDI/i2/5xxxx7' state '2' [2012-03-07 19:06:02.364] DEBUG[27648] rtp_engine.c: Can't find native functions for channel 'DAHDI/i2/5xxxx7-2' [2012-03-07 19:06:02.364] DEBUG[27648] rtp_engine.c: Seeded SDP of 'DAHDI/i2/5xxxx7-2' with that of 'IAX2/trunk-1105' [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable DIALEDTIME. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ANSWEREDTIME. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable DIALEDPEERNAME. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable DIALEDPEERNUMBER. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable DIALSTATUS. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ExtenEmail. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ARGC. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ARG3. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ARG2. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable ARG1. [2012-03-07 19:06:02.364] DEBUG[27648] channel.c: Not copying variable trunkname. [2012-03-07 19:06:02.364] DEBUG[27648] sig_pri.c: CALLER NAME: NUM: 9017xxxxxxx5 [2012-03-07 19:06:02.364] VERBOSE[27648] sig_pri.c: -- Requested transfer capability: 0x00 - SPEECH [2012-03-07 19:06:02.369] VERBOSE[27648] app_dial.c: -- Called DAHDI/G3/5xxxx7 [2012-03-07 19:06:02.369] DEBUG[27608] devicestate.c: Changing state for DAHDI/i2/5xxxx7 - state 2 (In use) [2012-03-07 19:06:02.369] DEBUG[27608] devicestate.c: device 'DAHDI/i2/5xxxx7' state '2' [2012-03-07 19:06:02.391] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK [2012-03-07 19:06:02.391] VERBOSE[27623] chan_iax2.c: Timestamp: 00062ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.391] DEBUG[27623] chan_iax2.c: Received packet 2, (6, 4) [2012-03-07 19:06:02.391] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 1 [2012-03-07 19:06:02.391] DEBUG[27623] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:02.429] DEBUG[27630] sig_pri.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/31 span 2 [2012-03-07 19:06:02.429] VERBOSE[27648] app_dial.c: -- DAHDI/i2/5xxxx7-2 is proceeding passing it to IAX2/trunk-1105 [2012-03-07 19:06:02.429] DEBUG[27648] chan_iax2.c: Indicating condition 15 [2012-03-07 19:06:02.429] DEBUG[27616] chan_iax2.c: Sending 65 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.429] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: PROCDNG [2012-03-07 19:06:02.429] VERBOSE[27616] chan_iax2.c: Timestamp: 00065ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.444] DEBUG[27616] chan_iax2.c: Sending 160 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.444] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: VOICE Subclass: 8 [2012-03-07 19:06:02.444] VERBOSE[27616] chan_iax2.c: Timestamp: 00160ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.464] DEBUG[27648] chan_iax2.c: Created trunk peer for '10.xxx.xxx.xx2:4569' [2012-03-07 19:06:02.464] DEBUG[27648] chan_iax2.c: Expanded trunk '10.xxx.xxx.xx2:4569' to 6400 bytes [2012-03-07 19:06:02.490] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK [2012-03-07 19:06:02.490] VERBOSE[27624] chan_iax2.c: Timestamp: 00065ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.490] DEBUG[27624] chan_iax2.c: Received packet 2, (6, 4) [2012-03-07 19:06:02.490] DEBUG[27624] chan_iax2.c: Cancelling transmission of packet 2 [2012-03-07 19:06:02.490] DEBUG[27624] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:02.492] VERBOSE[27625] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK [2012-03-07 19:06:02.492] VERBOSE[27625] chan_iax2.c: Timestamp: 00160ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.492] DEBUG[27625] chan_iax2.c: Received packet 2, (6, 4) [2012-03-07 19:06:02.492] DEBUG[27625] chan_iax2.c: Cancelling transmission of packet 3 [2012-03-07 19:06:02.492] DEBUG[27625] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:02.512] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE Subclass: 8 [2012-03-07 19:06:02.512] VERBOSE[27626] chan_iax2.c: Timestamp: 00295ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: Received packet 2, (2, 8) [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: Ooh, voice format changed to 'alaw' [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: Sending 295 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.512] VERBOSE[27626] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK [2012-03-07 19:06:02.512] VERBOSE[27626] chan_iax2.c: Timestamp: 00295ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: calc_rxstamp: call=1105: rxcore set to 1331147162.512614 - 295ms [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: calc_rxstamp: call=1105: works out as 1331147162.217614 [2012-03-07 19:06:02.512] DEBUG[27626] chan_iax2.c: For call=1105, set last=295 [2012-03-07 19:06:02.653] DEBUG[27630] chan_dahdi.c: Enabled echo cancellation on channel 62 [2012-03-07 19:06:02.653] VERBOSE[27648] app_dial.c: -- DAHDI/i2/5xxxx7-2 is ringing [2012-03-07 19:06:02.653] DEBUG[27608] devicestate.c: Changing state for DAHDI/i2/5xxxx7 - state 6 (Ringing) [2012-03-07 19:06:02.653] DEBUG[27648] chan_iax2.c: Indicating condition 3 [2012-03-07 19:06:02.653] DEBUG[27608] devicestate.c: device 'DAHDI/i2/5xxxx7' state '6' [2012-03-07 19:06:02.653] DEBUG[27616] chan_iax2.c: Sending 363 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.653] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass: RINGING [2012-03-07 19:06:02.653] VERBOSE[27616] chan_iax2.c: Timestamp: 00363ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.653] VERBOSE[27648] app_dial.c: -- DAHDI/i2/5xxxx7-2 is making progress passing it to IAX2/trunk-1105 [2012-03-07 19:06:02.653] DEBUG[27648] chan_iax2.c: Indicating condition 14 [2012-03-07 19:06:02.653] DEBUG[27616] chan_iax2.c: Sending 366 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:02.653] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 003 Type: CONTROL Subclass: PROGRES [2012-03-07 19:06:02.653] VERBOSE[27616] chan_iax2.c: Timestamp: 00366ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.699] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK [2012-03-07 19:06:02.699] VERBOSE[27618] chan_iax2.c: Timestamp: 00363ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.699] DEBUG[27618] chan_iax2.c: Received packet 3, (6, 4) [2012-03-07 19:06:02.699] DEBUG[27618] chan_iax2.c: Cancelling transmission of packet 4 [2012-03-07 19:06:02.699] DEBUG[27618] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:02.701] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 006 Type: IAX Subclass: ACK [2012-03-07 19:06:02.701] VERBOSE[27619] chan_iax2.c: Timestamp: 00366ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:02.701] DEBUG[27619] chan_iax2.c: Received packet 3, (6, 4) [2012-03-07 19:06:02.701] DEBUG[27619] chan_iax2.c: Cancelling transmission of packet 5 [2012-03-07 19:06:02.701] DEBUG[27619] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:03.382] DEBUG[27648] chan_iax2.c: Indicating condition 22 [2012-03-07 19:06:03.383] DEBUG[27630] chan_dahdi.c: Echo cancellation already on [2012-03-07 19:06:03.383] VERBOSE[27648] app_dial.c: -- DAHDI/i2/5xxxx7-2 answered IAX2/trunk-1105 [2012-03-07 19:06:03.383] DEBUG[27648] chan_iax2.c: Answering IAX2 call [2012-03-07 19:06:03.383] DEBUG[27648] chan_iax2.c: Indicating condition -1 [2012-03-07 19:06:03.383] DEBUG[27608] devicestate.c: Changing state for DAHDI/i2/5xxxx7 - state 2 (In use) [2012-03-07 19:06:03.383] DEBUG[27608] devicestate.c: device 'DAHDI/i2/5xxxx7' state '2' [2012-03-07 19:06:03.383] DEBUG[27608] chan_iax2.c: Checking device state for device trunk [2012-03-07 19:06:03.383] DEBUG[27608] chan_iax2.c: iax2_devicestate: Found peer. What's device state of trunk? addr=175059076, defaddr=0 maxms=300, lastms=20 [2012-03-07 19:06:03.383] DEBUG[27616] chan_iax2.c: Sending 1083 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 003 Type: CONTROL Subclass: ANSWER [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Timestamp: 01083ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.383] DEBUG[27616] chan_iax2.c: Sending 1086 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 003 Type: CONTROL Subclass: (255?) [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Timestamp: 01086ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.383] DEBUG[27648] features.c: Removing dialed interfaces datastore on DAHDI/i2/5xxxx7-2 since we're bridging [2012-03-07 19:06:03.383] DEBUG[27608] devicestate.c: Changing state for IAX2/trunk - state 2 (In use) [2012-03-07 19:06:03.383] DEBUG[27608] devicestate.c: device 'IAX2/trunk' state '2' [2012-03-07 19:06:03.383] DEBUG[27648] chan_iax2.c: Indicating condition 20 [2012-03-07 19:06:03.383] DEBUG[27616] chan_iax2.c: Sending 1089 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 003 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:03.383] VERBOSE[27616] chan_iax2.c: Timestamp: 01089ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.383] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:03.437] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 007 Type: IAX Subclass: ACK [2012-03-07 19:06:03.437] VERBOSE[27622] chan_iax2.c: Timestamp: 01083ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.437] DEBUG[27622] chan_iax2.c: Received packet 3, (6, 4) [2012-03-07 19:06:03.437] DEBUG[27622] chan_iax2.c: Cancelling transmission of packet 6 [2012-03-07 19:06:03.437] DEBUG[27622] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:03.439] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 008 Type: IAX Subclass: ACK [2012-03-07 19:06:03.439] VERBOSE[27623] chan_iax2.c: Timestamp: 01086ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.439] DEBUG[27623] chan_iax2.c: Received packet 3, (6, 4) [2012-03-07 19:06:03.439] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 7 [2012-03-07 19:06:03.439] DEBUG[27623] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:03.441] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 009 Type: IAX Subclass: ACK [2012-03-07 19:06:03.441] VERBOSE[27624] chan_iax2.c: Timestamp: 01089ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.441] DEBUG[27624] chan_iax2.c: Received packet 3, (6, 4) [2012-03-07 19:06:03.441] DEBUG[27624] chan_iax2.c: Cancelling transmission of packet 8 [2012-03-07 19:06:03.441] DEBUG[27624] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:03.536] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:03.536] VERBOSE[27622] chan_iax2.c: Timestamp: 01288ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.536] DEBUG[27622] chan_iax2.c: Received packet 3, (4, 20) [2012-03-07 19:06:03.536] DEBUG[27622] chan_iax2.c: Sending 1288 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.536] VERBOSE[27622] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 004 Type: IAX Subclass: ACK [2012-03-07 19:06:03.536] VERBOSE[27622] chan_iax2.c: Timestamp: 01288ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.536] DEBUG[27622] chan_iax2.c: For call=1105, set last=1288 [2012-03-07 19:06:03.537] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:03.537] VERBOSE[27623] chan_iax2.c: Timestamp: 01291ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.537] DEBUG[27623] chan_iax2.c: Received packet 4, (4, 20) [2012-03-07 19:06:03.537] DEBUG[27623] chan_iax2.c: Sending 1291 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.537] VERBOSE[27623] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 005 Type: IAX Subclass: ACK [2012-03-07 19:06:03.537] VERBOSE[27623] chan_iax2.c: Timestamp: 01291ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.537] DEBUG[27623] chan_iax2.c: For call=1105, set last=1291 [2012-03-07 19:06:03.539] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:03.539] VERBOSE[27624] chan_iax2.c: Timestamp: 01294ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.539] DEBUG[27624] chan_iax2.c: Received packet 5, (4, 20) [2012-03-07 19:06:03.539] DEBUG[27624] chan_iax2.c: Sending 1294 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:03.539] VERBOSE[27624] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 006 Type: IAX Subclass: ACK [2012-03-07 19:06:03.539] VERBOSE[27624] chan_iax2.c: Timestamp: 01294ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:03.539] DEBUG[27624] chan_iax2.c: For call=1105, set last=1294 [2012-03-07 19:06:03.642] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:03.642] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:03.642] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:08.128] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:08.128] VERBOSE[27618] chan_iax2.c: Timestamp: 05868ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.128] DEBUG[27618] chan_iax2.c: Received packet 6, (4, 20) [2012-03-07 19:06:08.128] DEBUG[27618] chan_iax2.c: Sending 5868 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:08.128] VERBOSE[27618] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 007 Type: IAX Subclass: ACK [2012-03-07 19:06:08.128] VERBOSE[27618] chan_iax2.c: Timestamp: 05868ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.128] DEBUG[27618] chan_iax2.c: For call=1105, set last=5868 [2012-03-07 19:06:08.129] VERBOSE[27620] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:08.129] VERBOSE[27620] chan_iax2.c: Timestamp: 05871ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.129] DEBUG[27620] chan_iax2.c: Received packet 7, (4, 20) [2012-03-07 19:06:08.129] DEBUG[27620] chan_iax2.c: Sending 5871 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:08.129] VERBOSE[27620] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 008 Type: IAX Subclass: ACK [2012-03-07 19:06:08.129] VERBOSE[27620] chan_iax2.c: Timestamp: 05871ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.129] DEBUG[27620] chan_iax2.c: For call=1105, set last=5871 [2012-03-07 19:06:08.131] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 009 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:08.131] VERBOSE[27619] chan_iax2.c: Timestamp: 05874ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.131] DEBUG[27619] chan_iax2.c: Received packet 8, (4, 20) [2012-03-07 19:06:08.131] DEBUG[27619] chan_iax2.c: Sending 5874 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:08.131] VERBOSE[27619] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 009 Type: IAX Subclass: ACK [2012-03-07 19:06:08.131] VERBOSE[27619] chan_iax2.c: Timestamp: 05874ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:08.131] DEBUG[27619] chan_iax2.c: For call=1105, set last=5874 [2012-03-07 19:06:08.262] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:08.262] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:08.262] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:12.221] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 009 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:12.221] VERBOSE[27621] chan_iax2.c: Timestamp: 10017ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.221] DEBUG[27621] chan_iax2.c: Received packet 9, (6, 11) [2012-03-07 19:06:12.221] DEBUG[27621] chan_iax2.c: IAX subclass 11 received [2012-03-07 19:06:12.221] DEBUG[27621] chan_iax2.c: For call=1105, set last=10017 [2012-03-07 19:06:12.221] DEBUG[27616] chan_iax2.c: Sending 10017 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.221] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 010 Type: IAX Subclass: LAGRP [2012-03-07 19:06:12.221] VERBOSE[27616] chan_iax2.c: Timestamp: 10017ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.281] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 010 Type: IAX Subclass: ACK [2012-03-07 19:06:12.281] VERBOSE[27626] chan_iax2.c: Timestamp: 10017ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.281] DEBUG[27626] chan_iax2.c: Received packet 10, (6, 4) [2012-03-07 19:06:12.281] DEBUG[27626] chan_iax2.c: Cancelling transmission of packet 9 [2012-03-07 19:06:12.281] DEBUG[27626] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:12.304] DEBUG[27616] chan_iax2.c: Sending 10023 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.304] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 010 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:12.304] VERBOSE[27616] chan_iax2.c: Timestamp: 10023ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.361] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 011 Type: IAX Subclass: LAGRP [2012-03-07 19:06:12.361] VERBOSE[27623] chan_iax2.c: Timestamp: 10023ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.361] DEBUG[27623] chan_iax2.c: Received packet 10, (6, 12) [2012-03-07 19:06:12.361] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 10 [2012-03-07 19:06:12.361] DEBUG[27623] chan_iax2.c: IAX subclass 12 received [2012-03-07 19:06:12.361] DEBUG[27623] chan_iax2.c: Peer 10.xxx.xxx.xx2 lag measured as 54ms [2012-03-07 19:06:12.361] DEBUG[27623] chan_iax2.c: Sending 10023 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.361] VERBOSE[27623] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 011 Type: IAX Subclass: ACK [2012-03-07 19:06:12.361] VERBOSE[27623] chan_iax2.c: Timestamp: 10023ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.526] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:12.526] VERBOSE[27626] chan_iax2.c: Timestamp: 10303ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.526] DEBUG[27626] chan_iax2.c: Received packet 11, (4, 20) [2012-03-07 19:06:12.526] DEBUG[27626] chan_iax2.c: Sending 10303 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.526] VERBOSE[27626] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 012 Type: IAX Subclass: ACK [2012-03-07 19:06:12.526] VERBOSE[27626] chan_iax2.c: Timestamp: 10303ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.526] DEBUG[27626] chan_iax2.c: For call=1105, set last=10303 [2012-03-07 19:06:12.528] VERBOSE[27627] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 012 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:12.528] VERBOSE[27627] chan_iax2.c: Timestamp: 10306ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.528] DEBUG[27627] chan_iax2.c: Received packet 12, (4, 20) [2012-03-07 19:06:12.528] DEBUG[27627] chan_iax2.c: Sending 10306 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.528] VERBOSE[27627] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 013 Type: IAX Subclass: ACK [2012-03-07 19:06:12.528] VERBOSE[27627] chan_iax2.c: Timestamp: 10306ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.528] DEBUG[27627] chan_iax2.c: For call=1105, set last=10306 [2012-03-07 19:06:12.529] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:12.529] VERBOSE[27618] chan_iax2.c: Timestamp: 10309ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.530] DEBUG[27618] chan_iax2.c: Received packet 13, (4, 20) [2012-03-07 19:06:12.530] DEBUG[27618] chan_iax2.c: Sending 10309 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:12.530] VERBOSE[27618] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 014 Type: IAX Subclass: ACK [2012-03-07 19:06:12.530] VERBOSE[27618] chan_iax2.c: Timestamp: 10309ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:12.530] DEBUG[27618] chan_iax2.c: For call=1105, set last=10309 [2012-03-07 19:06:12.696] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:12.697] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:12.697] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:12.865] WARNING[27621] chan_iax2.c: Resyncing the jb. last_delay 60, this delay 4700, threshold 1182, new offset -4700 [2012-03-07 19:06:16.764] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:16.764] VERBOSE[27621] chan_iax2.c: Timestamp: 14564ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.764] DEBUG[27621] chan_iax2.c: Received packet 14, (4, 20) [2012-03-07 19:06:16.764] DEBUG[27621] chan_iax2.c: Sending 14564 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:16.764] VERBOSE[27621] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 015 Type: IAX Subclass: ACK [2012-03-07 19:06:16.764] VERBOSE[27621] chan_iax2.c: Timestamp: 14564ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.764] DEBUG[27621] chan_iax2.c: For call=1105, set last=14564 [2012-03-07 19:06:16.766] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 015 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:16.766] VERBOSE[27622] chan_iax2.c: Timestamp: 14567ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.766] DEBUG[27622] chan_iax2.c: Received packet 15, (4, 20) [2012-03-07 19:06:16.766] DEBUG[27622] chan_iax2.c: Sending 14567 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:16.766] VERBOSE[27622] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 016 Type: IAX Subclass: ACK [2012-03-07 19:06:16.766] VERBOSE[27622] chan_iax2.c: Timestamp: 14567ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.766] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:16.766] DEBUG[27622] chan_iax2.c: For call=1105, set last=14567 [2012-03-07 19:06:16.767] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 016 ISeqno: 011 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:16.767] VERBOSE[27623] chan_iax2.c: Timestamp: 14570ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.767] DEBUG[27623] chan_iax2.c: Received packet 16, (4, 20) [2012-03-07 19:06:16.768] DEBUG[27623] chan_iax2.c: Sending 14570 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:16.768] VERBOSE[27623] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 017 Type: IAX Subclass: ACK [2012-03-07 19:06:16.768] VERBOSE[27623] chan_iax2.c: Timestamp: 14570ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:16.768] DEBUG[27623] chan_iax2.c: For call=1105, set last=14570 [2012-03-07 19:06:16.922] WARNING[27623] chan_iax2.c: Resyncing the jb. last_delay -22, this delay -4675, threshold 1128, new offset -25 [2012-03-07 19:06:16.922] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.016] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.128] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.218] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.330] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.426] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.520] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.622] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.783] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.876] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:17.972] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.064] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.158] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.269] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.383] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.479] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.561] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.721] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.818] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:18.918] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.017] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.108] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.214] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.329] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.422] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.519] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.627] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.720] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.820] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:19.917] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:20.030] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:20.116] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:20.230] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:20.329] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:20.417] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:21.562] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:22.219] VERBOSE[27627] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 017 ISeqno: 011 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:22.219] VERBOSE[27627] chan_iax2.c: Timestamp: 20033ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:22.219] DEBUG[27627] chan_iax2.c: Received packet 17, (6, 11) [2012-03-07 19:06:22.220] DEBUG[27627] chan_iax2.c: IAX subclass 11 received [2012-03-07 19:06:22.220] DEBUG[27627] chan_iax2.c: For call=1105, set last=20033 [2012-03-07 19:06:22.220] DEBUG[27616] chan_iax2.c: Sending 20033 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:22.220] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 011 ISeqno: 018 Type: IAX Subclass: LAGRP [2012-03-07 19:06:22.220] VERBOSE[27616] chan_iax2.c: Timestamp: 20033ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:22.276] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 018 ISeqno: 012 Type: IAX Subclass: ACK [2012-03-07 19:06:22.277] VERBOSE[27622] chan_iax2.c: Timestamp: 20033ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:22.277] DEBUG[27622] chan_iax2.c: Received packet 18, (6, 4) [2012-03-07 19:06:22.277] DEBUG[27622] chan_iax2.c: Cancelling transmission of packet 11 [2012-03-07 19:06:22.277] DEBUG[27622] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:22.303] DEBUG[27616] chan_iax2.c: Sending 20019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:22.303] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 012 ISeqno: 018 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:22.303] VERBOSE[27616] chan_iax2.c: Timestamp: 20019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:22.352] VERBOSE[27620] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 018 ISeqno: 013 Type: IAX Subclass: LAGRP [2012-03-07 19:06:22.352] VERBOSE[27620] chan_iax2.c: Timestamp: 20019ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:22.353] DEBUG[27620] chan_iax2.c: Received packet 18, (6, 12) [2012-03-07 19:06:22.353] DEBUG[27620] chan_iax2.c: Cancelling transmission of packet 12 [2012-03-07 19:06:22.353] DEBUG[27620] chan_iax2.c: IAX subclass 12 received [2012-03-07 19:06:22.353] DEBUG[27620] chan_iax2.c: Peer 10.xxx.xxx.xx2 lag measured as 49ms [2012-03-07 19:06:22.353] DEBUG[27620] chan_iax2.c: Sending 20019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:22.353] VERBOSE[27620] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 019 Type: IAX Subclass: ACK [2012-03-07 19:06:22.353] VERBOSE[27620] chan_iax2.c: Timestamp: 20019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.217] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 019 ISeqno: 013 Type: IAX Subclass: PING [2012-03-07 19:06:23.217] VERBOSE[27621] chan_iax2.c: Timestamp: 21032ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.217] DEBUG[27621] chan_iax2.c: Received packet 19, (6, 2) [2012-03-07 19:06:23.217] DEBUG[27621] chan_iax2.c: IAX subclass 2 received [2012-03-07 19:06:23.217] DEBUG[27621] chan_iax2.c: For call=1105, set last=21032 [2012-03-07 19:06:23.217] DEBUG[27616] chan_iax2.c: Sending 21032 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 013 ISeqno: 020 Type: IAX Subclass: PONG [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: Timestamp: 21032ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_JITTER : 53 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_LOSS : 335544494 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_PKTS : 875 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_DELAY : 115 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_DROPPED : 156 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: RR_OUTOFORDER : 86 [2012-03-07 19:06:23.217] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:23.272] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 020 ISeqno: 014 Type: IAX Subclass: ACK [2012-03-07 19:06:23.272] VERBOSE[27626] chan_iax2.c: Timestamp: 21032ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.272] DEBUG[27626] chan_iax2.c: Received packet 20, (6, 4) [2012-03-07 19:06:23.272] DEBUG[27626] chan_iax2.c: Cancelling transmission of packet 13 [2012-03-07 19:06:23.272] DEBUG[27626] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:23.304] DEBUG[27616] chan_iax2.c: Sending 21023 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:23.304] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 014 ISeqno: 020 Type: IAX Subclass: PING [2012-03-07 19:06:23.304] VERBOSE[27616] chan_iax2.c: Timestamp: 21023ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 020 ISeqno: 015 Type: IAX Subclass: PONG [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: Timestamp: 21023ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_JITTER : 41 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_LOSS : 0 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_PKTS : 1047 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_DELAY : 91 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_DROPPED : 0 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: RR_OUTOFORDER : 3 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: [2012-03-07 19:06:23.352] DEBUG[27623] chan_iax2.c: Received packet 20, (6, 3) [2012-03-07 19:06:23.352] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 14 [2012-03-07 19:06:23.352] DEBUG[27623] chan_iax2.c: IAX subclass 3 received [2012-03-07 19:06:23.352] DEBUG[27623] chan_iax2.c: JB STATS:IAX2/trunk-1105 ping=45 ljitterms=57 ljbdelayms=119 ltotlost=174 lrecentlosspct=20 ldropped=156 looo=86 lrecvd=880 rjitterms=41 rjbdelayms=91 rtotlost=0 rrecentlosspct=0 rdropped=0 rooo=3 rrecvd=1047 [2012-03-07 19:06:23.352] DEBUG[27623] chan_iax2.c: Sending 21023 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 021 Type: IAX Subclass: ACK [2012-03-07 19:06:23.352] VERBOSE[27623] chan_iax2.c: Timestamp: 21023ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.232] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 021 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:27.232] VERBOSE[27619] chan_iax2.c: Timestamp: 25023ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.232] DEBUG[27619] chan_iax2.c: Received packet 21, (4, 20) [2012-03-07 19:06:27.232] DEBUG[27619] chan_iax2.c: Sending 25023 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:27.232] VERBOSE[27619] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 022 Type: IAX Subclass: ACK [2012-03-07 19:06:27.232] VERBOSE[27619] chan_iax2.c: Timestamp: 25023ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.232] DEBUG[27619] chan_iax2.c: For call=1105, set last=25023 [2012-03-07 19:06:27.233] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 022 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:27.233] VERBOSE[27621] chan_iax2.c: Timestamp: 25026ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.233] DEBUG[27621] chan_iax2.c: Received packet 22, (4, 20) [2012-03-07 19:06:27.234] DEBUG[27621] chan_iax2.c: Sending 25026 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:27.234] VERBOSE[27621] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 023 Type: IAX Subclass: ACK [2012-03-07 19:06:27.234] VERBOSE[27621] chan_iax2.c: Timestamp: 25026ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.234] DEBUG[27621] chan_iax2.c: For call=1105, set last=25026 [2012-03-07 19:06:27.235] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 023 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:27.235] VERBOSE[27622] chan_iax2.c: Timestamp: 25029ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.235] DEBUG[27622] chan_iax2.c: Received packet 23, (4, 20) [2012-03-07 19:06:27.235] DEBUG[27622] chan_iax2.c: Sending 25029 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:27.235] VERBOSE[27622] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 024 Type: IAX Subclass: ACK [2012-03-07 19:06:27.235] VERBOSE[27622] chan_iax2.c: Timestamp: 25029ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:27.235] DEBUG[27622] chan_iax2.c: For call=1105, set last=25029 [2012-03-07 19:06:27.361] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:27.361] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:27.362] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:27.554] WARNING[27624] chan_iax2.c: Resyncing the jb. last_delay 0, this delay 15359, threshold 1120, new offset -15384 [2012-03-07 19:06:31.385] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 024 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:31.385] VERBOSE[27626] chan_iax2.c: Timestamp: 29180ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.385] DEBUG[27626] chan_iax2.c: Received packet 24, (4, 20) [2012-03-07 19:06:31.385] DEBUG[27626] chan_iax2.c: Sending 29180 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:31.385] VERBOSE[27626] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 025 Type: IAX Subclass: ACK [2012-03-07 19:06:31.386] VERBOSE[27626] chan_iax2.c: Timestamp: 29180ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.386] DEBUG[27626] chan_iax2.c: For call=1105, set last=29180 [2012-03-07 19:06:31.387] VERBOSE[27627] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 025 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:31.387] VERBOSE[27627] chan_iax2.c: Timestamp: 29183ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.387] DEBUG[27627] chan_iax2.c: Received packet 25, (4, 20) [2012-03-07 19:06:31.387] DEBUG[27627] chan_iax2.c: Sending 29183 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:31.387] VERBOSE[27627] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 026 Type: IAX Subclass: ACK [2012-03-07 19:06:31.387] VERBOSE[27627] chan_iax2.c: Timestamp: 29183ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.387] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:31.387] DEBUG[27627] chan_iax2.c: For call=1105, set last=29183 [2012-03-07 19:06:31.389] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 026 ISeqno: 015 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:31.389] VERBOSE[27618] chan_iax2.c: Timestamp: 29186ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.389] DEBUG[27618] chan_iax2.c: Received packet 26, (4, 20) [2012-03-07 19:06:31.389] DEBUG[27618] chan_iax2.c: Sending 29186 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:31.389] VERBOSE[27618] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 027 Type: IAX Subclass: ACK [2012-03-07 19:06:31.389] VERBOSE[27618] chan_iax2.c: Timestamp: 29186ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:31.389] DEBUG[27618] chan_iax2.c: For call=1105, set last=29186 [2012-03-07 19:06:31.526] WARNING[27618] chan_iax2.c: Resyncing the jb. last_delay 24, this delay -15356, threshold 1122, new offset -28 [2012-03-07 19:06:31.526] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:31.671] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:31.778] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:31.864] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:31.975] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.069] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.165] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.225] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 027 ISeqno: 015 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:32.225] VERBOSE[27619] chan_iax2.c: Timestamp: 30034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.225] DEBUG[27619] chan_iax2.c: Received packet 27, (6, 11) [2012-03-07 19:06:32.225] DEBUG[27619] chan_iax2.c: IAX subclass 11 received [2012-03-07 19:06:32.225] DEBUG[27619] chan_iax2.c: For call=1105, set last=30034 [2012-03-07 19:06:32.225] DEBUG[27616] chan_iax2.c: Sending 30034 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:32.225] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 015 ISeqno: 028 Type: IAX Subclass: LAGRP [2012-03-07 19:06:32.225] VERBOSE[27616] chan_iax2.c: Timestamp: 30034ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.265] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.269] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 028 ISeqno: 016 Type: IAX Subclass: ACK [2012-03-07 19:06:32.269] VERBOSE[27624] chan_iax2.c: Timestamp: 30034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.269] DEBUG[27624] chan_iax2.c: Received packet 28, (6, 4) [2012-03-07 19:06:32.269] DEBUG[27624] chan_iax2.c: Cancelling transmission of packet 15 [2012-03-07 19:06:32.269] DEBUG[27624] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:32.303] DEBUG[27616] chan_iax2.c: Sending 30019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:32.303] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 016 ISeqno: 028 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:32.303] VERBOSE[27616] chan_iax2.c: Timestamp: 30019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.336] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 028 ISeqno: 017 Type: IAX Subclass: LAGRP [2012-03-07 19:06:32.336] VERBOSE[27622] chan_iax2.c: Timestamp: 30019ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.336] DEBUG[27622] chan_iax2.c: Received packet 28, (6, 12) [2012-03-07 19:06:32.336] DEBUG[27622] chan_iax2.c: Cancelling transmission of packet 16 [2012-03-07 19:06:32.336] DEBUG[27622] chan_iax2.c: IAX subclass 12 received [2012-03-07 19:06:32.336] DEBUG[27622] chan_iax2.c: Peer 10.xxx.xxx.xx2 lag measured as 33ms [2012-03-07 19:06:32.336] DEBUG[27622] chan_iax2.c: Sending 30019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:32.336] VERBOSE[27622] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 017 ISeqno: 029 Type: IAX Subclass: ACK [2012-03-07 19:06:32.336] VERBOSE[27622] chan_iax2.c: Timestamp: 30019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:32.343] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.472] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.569] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.665] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.782] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.867] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:32.971] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.068] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.179] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.279] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.368] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.449] DEBUG[27621] chan_iax2.c: New max nontrunk callno is 4584 [2012-03-07 19:06:33.449] DEBUG[27621] chan_iax2.c: Creating new call structure 4583 [2012-03-07 19:06:33.449] DEBUG[27616] chan_iax2.c: Sending 9 on 4583/0 to 10.xxx.xxx.12:4569 [2012-03-07 19:06:33.449] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [2012-03-07 19:06:33.449] VERBOSE[27616] chan_iax2.c: Timestamp: 00009ms SCall: 04583 DCall: 00000 [10.xxx.xxx.12:4569] [2012-03-07 19:06:33.449] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:33.458] DEBUG[27617] chan_iax2.c: ip callno count decremented to 1 for 10.xxx.xxx.xx2 [2012-03-07 19:06:33.458] DEBUG[27623] chan_iax2.c: ip callno count incremented to 2 for 10.xxx.xxx.xx2 [2012-03-07 19:06:33.458] DEBUG[27623] chan_iax2.c: New max nontrunk callno is 4584 [2012-03-07 19:06:33.458] DEBUG[27623] chan_iax2.c: Creating new call structure 194 [2012-03-07 19:06:33.458] DEBUG[27616] chan_iax2.c: Sending 18 on 194/0 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:33.458] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [2012-03-07 19:06:33.458] VERBOSE[27616] chan_iax2.c: Timestamp: 00018ms SCall: 00194 DCall: 00000 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:33.458] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:33.465] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[Yes] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [2012-03-07 19:06:33.465] VERBOSE[27624] chan_iax2.c: Timestamp: 00009ms SCall: 00001 DCall: 04583 [10.xxx.xxx.12:4569] [2012-03-07 19:06:33.465] DEBUG[27624] chan_iax2.c: Received packet 0, (6, 3) [2012-03-07 19:06:33.465] DEBUG[27624] chan_iax2.c: Cancelling transmission of packet 0 [2012-03-07 19:06:33.465] DEBUG[27624] chan_iax2.c: IAX subclass 3 received [2012-03-07 19:06:33.466] DEBUG[27624] chan_iax2.c: Sending 9 on 4583/1 to 10.xxx.xxx.12:4569 [2012-03-07 19:06:33.466] VERBOSE[27624] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [2012-03-07 19:06:33.466] VERBOSE[27624] chan_iax2.c: Timestamp: 00009ms SCall: 04583 DCall: 00001 [10.xxx.xxx.12:4569] [2012-03-07 19:06:33.466] DEBUG[27624] chan_iax2.c: schedule decrement of callno used for 10.xxx.xxx.12 in 60 seconds [2012-03-07 19:06:33.466] DEBUG[27624] chan_iax2.c: Peer ohtrunk: got pong, lastms 16, historicms 16, maxms 300 [2012-03-07 19:06:33.468] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.519] VERBOSE[27620] chan_iax2.c: Rx-Frame Retry[Yes] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG [2012-03-07 19:06:33.519] VERBOSE[27620] chan_iax2.c: Timestamp: 00018ms SCall: 00001 DCall: 00194 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: Received packet 0, (6, 3) [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: Cancelling transmission of packet 0 [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: IAX subclass 3 received [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: Sending 18 on 194/1 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:33.519] VERBOSE[27620] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [2012-03-07 19:06:33.519] VERBOSE[27620] chan_iax2.c: Timestamp: 00018ms SCall: 00194 DCall: 00001 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: schedule decrement of callno used for 10.xxx.xxx.xx2 in 60 seconds [2012-03-07 19:06:33.519] DEBUG[27620] chan_iax2.c: Peer trunk: got pong, lastms 61, historicms 61, maxms 300 [2012-03-07 19:06:33.581] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.680] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.769] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.865] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:33.978] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.074] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.171] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.257] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.373] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.474] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.562] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.678] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.782] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.878] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:34.973] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.071] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.169] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.272] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.369] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.483] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.579] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.655] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.777] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.874] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:35.970] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.083] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.173] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.231] VERBOSE[27622] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE [2012-03-07 19:06:36.231] VERBOSE[27622] chan_iax2.c: Timestamp: 00019ms SCall: 16200 DCall: 00000 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:36.231] VERBOSE[27622] chan_iax2.c: [2012-03-07 19:06:36.271] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.272] VERBOSE[27626] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [2012-03-07 19:06:36.272] VERBOSE[27626] chan_iax2.c: Timestamp: 00019ms SCall: 16200 DCall: 00001 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:36.365] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.482] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.583] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.671] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.766] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.881] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:36.976] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.068] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.182] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.275] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.372] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.482] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.541] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.666] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.779] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.872] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:37.982] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.084] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.177] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.270] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.378] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.464] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.576] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.668] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.781] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.879] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:38.941] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.065] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.180] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.278] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.375] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.478] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.578] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.675] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.768] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.869] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:39.972] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.069] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.168] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.280] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.359] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.469] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.580] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.677] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.776] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.842] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:40.980] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.078] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.171] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.271] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.377] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.473] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.572] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.671] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.768] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.882] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:41.978] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.072] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.172] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.231] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 029 ISeqno: 017 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:42.231] VERBOSE[27624] chan_iax2.c: Timestamp: 40034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.231] DEBUG[27624] chan_iax2.c: Received packet 29, (6, 11) [2012-03-07 19:06:42.231] DEBUG[27624] chan_iax2.c: IAX subclass 11 received [2012-03-07 19:06:42.231] DEBUG[27624] chan_iax2.c: For call=1105, set last=40034 [2012-03-07 19:06:42.231] DEBUG[27616] chan_iax2.c: Sending 40034 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:42.231] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 017 ISeqno: 030 Type: IAX Subclass: LAGRP [2012-03-07 19:06:42.231] VERBOSE[27616] chan_iax2.c: Timestamp: 40034ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.263] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.266] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 030 ISeqno: 018 Type: IAX Subclass: ACK [2012-03-07 19:06:42.266] VERBOSE[27618] chan_iax2.c: Timestamp: 40034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.266] DEBUG[27618] chan_iax2.c: Received packet 30, (6, 4) [2012-03-07 19:06:42.266] DEBUG[27618] chan_iax2.c: Cancelling transmission of packet 17 [2012-03-07 19:06:42.266] DEBUG[27618] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:42.303] DEBUG[27616] chan_iax2.c: Sending 40019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:42.303] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 018 ISeqno: 030 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:42.303] VERBOSE[27616] chan_iax2.c: Timestamp: 40019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.356] VERBOSE[27627] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 030 ISeqno: 019 Type: IAX Subclass: LAGRP [2012-03-07 19:06:42.356] VERBOSE[27627] chan_iax2.c: Timestamp: 40019ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.356] DEBUG[27627] chan_iax2.c: Received packet 30, (6, 12) [2012-03-07 19:06:42.356] DEBUG[27627] chan_iax2.c: Cancelling transmission of packet 18 [2012-03-07 19:06:42.356] DEBUG[27627] chan_iax2.c: IAX subclass 12 received [2012-03-07 19:06:42.356] DEBUG[27627] chan_iax2.c: Peer 10.xxx.xxx.xx2 lag measured as 53ms [2012-03-07 19:06:42.356] DEBUG[27627] chan_iax2.c: Sending 40019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:42.356] VERBOSE[27627] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 019 ISeqno: 031 Type: IAX Subclass: ACK [2012-03-07 19:06:42.356] VERBOSE[27627] chan_iax2.c: Timestamp: 40019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:42.363] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.473] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.573] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.672] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.744] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.872] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:42.972] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.066] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.181] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.271] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.368] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.481] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.579] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.673] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.782] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.872] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:43.972] DEBUG[27621] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.066] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.172] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.232] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 031 ISeqno: 019 Type: IAX Subclass: PING [2012-03-07 19:06:44.232] VERBOSE[27619] chan_iax2.c: Timestamp: 42034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.232] DEBUG[27619] chan_iax2.c: Received packet 31, (6, 2) [2012-03-07 19:06:44.232] DEBUG[27619] chan_iax2.c: IAX subclass 2 received [2012-03-07 19:06:44.232] DEBUG[27619] chan_iax2.c: For call=1105, set last=42034 [2012-03-07 19:06:44.232] DEBUG[27616] chan_iax2.c: Sending 42034 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 019 ISeqno: 032 Type: IAX Subclass: PONG [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: Timestamp: 42034ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_JITTER : 39 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_LOSS : 1006633658 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_PKTS : 1398 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_DELAY : 92 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_DROPPED : 676 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: RR_OUTOFORDER : 214 [2012-03-07 19:06:44.232] VERBOSE[27616] chan_iax2.c: [2012-03-07 19:06:44.272] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.274] VERBOSE[27624] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 032 ISeqno: 020 Type: IAX Subclass: ACK [2012-03-07 19:06:44.274] VERBOSE[27624] chan_iax2.c: Timestamp: 42034ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.274] DEBUG[27624] chan_iax2.c: Received packet 32, (6, 4) [2012-03-07 19:06:44.274] DEBUG[27624] chan_iax2.c: Cancelling transmission of packet 19 [2012-03-07 19:06:44.274] DEBUG[27624] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:44.304] DEBUG[27616] chan_iax2.c: Sending 42019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:44.304] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 020 ISeqno: 032 Type: IAX Subclass: PING [2012-03-07 19:06:44.304] VERBOSE[27616] chan_iax2.c: Timestamp: 42019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 032 ISeqno: 021 Type: IAX Subclass: PONG [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: Timestamp: 42019ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_JITTER : 41 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_LOSS : 0 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_PKTS : 2097 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_DELAY : 91 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_DROPPED : 0 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: RR_OUTOFORDER : 3 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: [2012-03-07 19:06:44.364] DEBUG[27623] chan_iax2.c: Received packet 32, (6, 3) [2012-03-07 19:06:44.364] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 20 [2012-03-07 19:06:44.364] DEBUG[27623] chan_iax2.c: IAX subclass 3 received [2012-03-07 19:06:44.364] DEBUG[27623] chan_iax2.c: JB STATS:IAX2/trunk-1105 ping=64 ljitterms=39 ljbdelayms=92 ltotlost=703 lrecentlosspct=60 ldropped=680 looo=215 lrecvd=1399 rjitterms=41 rjbdelayms=91 rtotlost=0 rrecentlosspct=0 rdropped=0 rooo=3 rrecvd=2097 [2012-03-07 19:06:44.364] DEBUG[27623] chan_iax2.c: Sending 42019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 021 ISeqno: 033 Type: IAX Subclass: ACK [2012-03-07 19:06:44.364] VERBOSE[27623] chan_iax2.c: Timestamp: 42019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:44.371] DEBUG[27624] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.467] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.582] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.662] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.767] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.863] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:44.984] DEBUG[27618] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.080] DEBUG[27625] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.142] DEBUG[27619] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.280] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.380] DEBUG[27626] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.474] DEBUG[27622] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.573] DEBUG[27620] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.680] DEBUG[27627] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:45.772] DEBUG[27623] jitterbuf.c: Attempting to exceed Jitterbuf max 1000 timeslots [2012-03-07 19:06:46.855] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:52.074] VERBOSE[27625] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 033 ISeqno: 021 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:52.074] VERBOSE[27625] chan_iax2.c: Timestamp: 49843ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.074] DEBUG[27625] chan_iax2.c: Received packet 33, (4, 20) [2012-03-07 19:06:52.074] DEBUG[27625] chan_iax2.c: Sending 49843 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.074] VERBOSE[27625] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 021 ISeqno: 034 Type: IAX Subclass: ACK [2012-03-07 19:06:52.074] VERBOSE[27625] chan_iax2.c: Timestamp: 49843ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.074] DEBUG[27625] chan_iax2.c: For call=1105, set last=49843 [2012-03-07 19:06:52.076] VERBOSE[27627] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 034 ISeqno: 021 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:52.076] VERBOSE[27627] chan_iax2.c: Timestamp: 49846ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.076] DEBUG[27627] chan_iax2.c: Received packet 34, (4, 20) [2012-03-07 19:06:52.076] DEBUG[27627] chan_iax2.c: Sending 49846 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.076] VERBOSE[27627] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 021 ISeqno: 035 Type: IAX Subclass: ACK [2012-03-07 19:06:52.076] VERBOSE[27627] chan_iax2.c: Timestamp: 49846ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.076] DEBUG[27627] chan_iax2.c: For call=1105, set last=49846 [2012-03-07 19:06:52.077] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 035 ISeqno: 021 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:52.077] VERBOSE[27618] chan_iax2.c: Timestamp: 49849ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.077] DEBUG[27618] chan_iax2.c: Received packet 35, (4, 20) [2012-03-07 19:06:52.077] DEBUG[27618] chan_iax2.c: Sending 49849 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.078] VERBOSE[27618] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 021 ISeqno: 036 Type: IAX Subclass: ACK [2012-03-07 19:06:52.078] VERBOSE[27618] chan_iax2.c: Timestamp: 49849ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.078] DEBUG[27618] chan_iax2.c: For call=1105, set last=49849 [2012-03-07 19:06:52.174] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:52.174] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:52.174] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:52.246] VERBOSE[27621] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 036 ISeqno: 021 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:52.246] VERBOSE[27621] chan_iax2.c: Timestamp: 50035ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.246] DEBUG[27621] chan_iax2.c: Received packet 36, (6, 11) [2012-03-07 19:06:52.246] DEBUG[27621] chan_iax2.c: IAX subclass 11 received [2012-03-07 19:06:52.246] DEBUG[27621] chan_iax2.c: For call=1105, set last=50035 [2012-03-07 19:06:52.246] DEBUG[27616] chan_iax2.c: Sending 50035 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.246] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 021 ISeqno: 037 Type: IAX Subclass: LAGRP [2012-03-07 19:06:52.246] VERBOSE[27616] chan_iax2.c: Timestamp: 50035ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.266] VERBOSE[27623] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 037 ISeqno: 022 Type: IAX Subclass: ACK [2012-03-07 19:06:52.267] VERBOSE[27623] chan_iax2.c: Timestamp: 50035ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.267] DEBUG[27623] chan_iax2.c: Received packet 37, (6, 4) [2012-03-07 19:06:52.267] DEBUG[27623] chan_iax2.c: Cancelling transmission of packet 21 [2012-03-07 19:06:52.267] DEBUG[27623] chan_iax2.c: IAX subclass 4 received [2012-03-07 19:06:52.303] DEBUG[27616] chan_iax2.c: Sending 50019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.303] VERBOSE[27616] chan_iax2.c: Tx-Frame Retry[000] -- OSeqno: 022 ISeqno: 037 Type: IAX Subclass: LAGRQ [2012-03-07 19:06:52.303] VERBOSE[27616] chan_iax2.c: Timestamp: 50019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.368] VERBOSE[27619] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 037 ISeqno: 023 Type: IAX Subclass: LAGRP [2012-03-07 19:06:52.368] VERBOSE[27619] chan_iax2.c: Timestamp: 50019ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.368] DEBUG[27619] chan_iax2.c: Received packet 37, (6, 12) [2012-03-07 19:06:52.368] DEBUG[27619] chan_iax2.c: Cancelling transmission of packet 22 [2012-03-07 19:06:52.368] DEBUG[27619] chan_iax2.c: IAX subclass 12 received [2012-03-07 19:06:52.368] DEBUG[27619] chan_iax2.c: Peer 10.xxx.xxx.xx2 lag measured as 65ms [2012-03-07 19:06:52.368] DEBUG[27619] chan_iax2.c: Sending 50019 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:52.368] VERBOSE[27619] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 023 ISeqno: 038 Type: IAX Subclass: ACK [2012-03-07 19:06:52.368] VERBOSE[27619] chan_iax2.c: Timestamp: 50019ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:52.416] WARNING[27623] chan_iax2.c: Resyncing the jb. last_delay -3, this delay 36327, threshold 1118, new offset -36355 [2012-03-07 19:06:55.197] VERBOSE[27618] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 038 ISeqno: 023 Type: CONTROL Subclass: SRCUPDT [2012-03-07 19:06:55.197] VERBOSE[27618] chan_iax2.c: Timestamp: 53004ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:55.197] DEBUG[27618] chan_iax2.c: Received packet 38, (4, 20) [2012-03-07 19:06:55.197] DEBUG[27618] chan_iax2.c: Sending 53004 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:55.198] VERBOSE[27618] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 023 ISeqno: 039 Type: IAX Subclass: ACK [2012-03-07 19:06:55.198] VERBOSE[27618] chan_iax2.c: Timestamp: 53004ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:55.198] DEBUG[27618] chan_iax2.c: For call=1105, set last=53004 [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: Rx-Frame Retry[ No] -- OSeqno: 039 ISeqno: 023 Type: IAX Subclass: HANGUP [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: Timestamp: 53007ms SCall: 16489 DCall: 01105 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: CAUSE CODE : 16 [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: [2012-03-07 19:06:55.199] DEBUG[27620] chan_iax2.c: Received packet 39, (6, 5) [2012-03-07 19:06:55.199] DEBUG[27620] chan_iax2.c: IAX subclass 5 received [2012-03-07 19:06:55.199] DEBUG[27620] chan_iax2.c: For call=1105, set last=53007 [2012-03-07 19:06:55.199] DEBUG[27620] chan_iax2.c: Immediately destroying 1105, having received hangup [2012-03-07 19:06:55.199] DEBUG[27620] chan_iax2.c: Sending 53007 on 1105/16489 to 10.xxx.xxx.xx2:4569 [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: Tx-Frame Retry[-01] -- OSeqno: 023 ISeqno: 040 Type: IAX Subclass: ACK [2012-03-07 19:06:55.199] VERBOSE[27620] chan_iax2.c: Timestamp: 53007ms SCall: 01105 DCall: 16489 [10.xxx.xxx.xx2:4569] [2012-03-07 19:06:55.199] DEBUG[27648] channel.c: Didn't get a frame from channel: IAX2/trunk-1105 [2012-03-07 19:06:55.199] DEBUG[27648] chan_dahdi.c: Requested indication 20 on channel DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:55.199] DEBUG[27648] channel.c: Bridge stops bridging channels IAX2/trunk-1105 and DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:55.199] DEBUG[27648] channel.c: Soft-Hanging up channel 'IAX2/trunk-1105' [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Launching 'NoOp' [2012-03-07 19:06:55.199] VERBOSE[27648] pbx.c: -- Executing [h@dialpbx:1] NoOp("IAX2/trunk-1105", "--- Hangup for 5xxxx7 in dialpbx context ---") in new stack [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Expression result is '1' [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Launching 'GotoIf' [2012-03-07 19:06:55.199] VERBOSE[27648] pbx.c: -- Executing [h@dialpbx:2] GotoIf("IAX2/trunk-1105", "1?h-email,1") in new stack [2012-03-07 19:06:55.199] VERBOSE[27648] pbx.c: -- Goto (dialpbx,h-email,1) [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Launching 'NoOp' [2012-03-07 19:06:55.199] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:1] NoOp("IAX2/trunk-1105", "--- Processing email notification ---") in new stack [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Function result is '9017xxxxxxx5' [2012-03-07 19:06:55.199] DEBUG[27648] pbx.c: Expression result is '0' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'GotoIf' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:2] GotoIf("IAX2/trunk-1105", "0?done") in new stack [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Not taking any branch [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Expression result is '0' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Function result is '"" <9017xxxxxxx5>' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'ExecIf' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:3] ExecIf("IAX2/trunk-1105", "0?Set(EmailMessage=You have missed a call from "" <9017xxxxxxx5>)") in new stack [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Expression result is '0' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Function result is '"" <9017xxxxxxx5>' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'ExecIf' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:4] ExecIf("IAX2/trunk-1105", "0?Set(EmailMessage="" <9017xxxxxxx5> hung up VM)") in new stack [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Expression result is '0' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Function result is '"" <9017xxxxxxx5>' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'ExecIf' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:5] ExecIf("IAX2/trunk-1105", "0?Set(EmailMessage="" <9017xxxxxxx5> hung up VM)") in new stack [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Function result is '1' [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'GotoIf' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:6] GotoIf("IAX2/trunk-1105", "1?done") in new stack [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Goto (dialpbx,h-email,8) [2012-03-07 19:06:55.200] DEBUG[27648] pbx.c: Launching 'Return' [2012-03-07 19:06:55.200] VERBOSE[27648] pbx.c: -- Executing [h-email@dialpbx:8] Return("IAX2/trunk-1105", "") in new stack [2012-03-07 19:06:55.200] DEBUG[27648] channel.c: Hanging up channel 'DAHDI/i2/5xxxx7-2' [2012-03-07 19:06:55.200] DEBUG[27648] chan_dahdi.c: dahdi_hangup(DAHDI/i2/5xxxx7-2) [2012-03-07 19:06:55.200] DEBUG[27648] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:55.201] DEBUG[27648] sig_pri.c: sig_pri_hangup 62 [2012-03-07 19:06:55.201] DEBUG[27648] sig_pri.c: Not yet hungup... Calling hangup with cause 16, and clearing call [2012-03-07 19:06:55.206] DEBUG[27648] chan_dahdi.c: Disabled echo cancellation on channel 62 [2012-03-07 19:06:55.206] DEBUG[27648] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:55.206] DEBUG[27648] chan_dahdi.c: Updated conferencing on 62, with 0 conference users [2012-03-07 19:06:55.206] DEBUG[27648] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/i2/5xxxx7-2 [2012-03-07 19:06:55.206] VERBOSE[27648] chan_dahdi.c: -- Hungup 'DAHDI/i2/5xxxx7-2' [2012-03-07 19:06:55.206] DEBUG[27608] devicestate.c: Changing state for DAHDI/i2/5xxxx7 - state 0 (Unknown) [2012-03-07 19:06:55.206] DEBUG[27608] devicestate.c: device 'DAHDI/i2/5xxxx7' state '0' [2012-03-07 19:06:55.206] DEBUG[27648] app_dial.c: Exiting with DIALSTATUS=ANSWER. [2012-03-07 19:06:55.206] DEBUG[27648] pbx.c: Spawn extension (dialpbx,s,6) exited non-zero on 'IAX2/trunk-1105' [2012-03-07 19:06:55.206] VERBOSE[27648] pbx.c: == Spawn extension (dialpbx, s, 6) exited non-zero on 'IAX2/trunk-1105' [2012-03-07 19:06:55.206] DEBUG[27648] channel.c: Soft-Hanging up channel 'IAX2/trunk-1105' [2012-03-07 19:06:55.206] DEBUG[27648] channel.c: Hanging up channel 'IAX2/trunk-1105' [2012-03-07 19:06:55.206] DEBUG[27648] chan_iax2.c: We're hanging up IAX2/trunk-1105 now... [2012-03-07 19:06:55.206] DEBUG[27648] chan_iax2.c: Really destroying IAX2/trunk-1105 now... [2012-03-07 19:06:55.206] DEBUG[27648] chan_iax2.c: schedule decrement of callno used for 10.xxx.xxx.xx2 in 60 seconds [2012-03-07 19:06:55.206] VERBOSE[27648] chan_iax2.c: -- Hungup 'IAX2/trunk-1105' [2012-03-07 19:06:55.206] DEBUG[27608] chan_iax2.c: Checking device state for device trunk [2012-03-07 19:06:55.206] DEBUG[27608] chan_iax2.c: iax2_devicestate: Found peer. What's device state of trunk? addr=175059076, defaddr=0 maxms=300, lastms=61 [2012-03-07 19:06:55.206] DEBUG[27608] devicestate.c: Changing state for IAX2/trunk - state 0 (Unknown) [2012-03-07 19:06:55.206] DEBUG[27608] devicestate.c: device 'IAX2/trunk' state '0'