[asterisk-users] transfer=mediaonly : can't hear nothing

Tim Panton tim at mexuar.com
Wed Mar 21 01:37:07 MST 2007


I am not up on the detail of the media-only transfer, but I did  
notice that in the second example
the "weas" one you get a VNAK from 192.168.52.94:4569 in response to  
the first
post transfer VOICE packet, then everything starts to go wrong !

In the first example you also see VNAKs and the
"Ooh, voice format changed to 8" message.

I'd be tempted to simplify things even more by removing the codec  
negotiation
and have all the boxes be _forced_ to use alaw.

Tim


On 20 Mar 2007, at 10:36, Simone Cittadini wrote:

> Kevin P. Fleming ha scritto:
>>
>> OK, then you'll need to get a verbose/debug console trace, and
>> preferably a packet capture of the IAX2 traffic on 'Server', and  
>> post a
>> bug on bugs.digium.com with those files attached.
>> _______________________________________________
> While setting up the servers to gather the logs I've tryed a  
> configuration which is so "hello world" it seems unprobable to me  
> it can't work due to a bug.
>
> I post once again here, sorry for the verbosity, if then in your  
> opinion there's still something wrong with * internals and not with  
> my understanding of the configs I'll open the bug.
> I anticipate that only with mediaonly (when I can't hear) I get  
> these messages : "Received iseqno 4 not within window 5->5" which  
> seems to remand to bug number 0006808, but I've tested also with  
> jitterbuffer=no on all machines and the problem remains.
> Also I get some "Subclass: (38?)" packets, only in mediaonly mode.
>
> 3 machines, all on the same class C net (192.168.52.x), 2 are  
> "clients" (C001 and C002) and one is the "server"
>
> C001 has two nics, the second being 192.168.0.1 connected to a  
> switch with a linksys pap in it, which generates the call:
>
> C001 and C002 sip.conf, iax.conf and extensions.conf are the same  
> (except of course for IPs where to listen and credentials)
>
> C00x sip.conf:
>
> [general]
> context=default                 ; Default context for incoming calls
> realm=retireti.it
> bindport=5060                   ; UDP Port to bind to (SIP standard  
> port is 5060)
> bindaddr=192.168.0.1                ; IP address to bind to  
> (0.0.0.0 binds to all)
> srvlookup=no
> tos_sip=cs3                    ; Sets TOS for SIP packets.
> tos_audio=ef                   ; Sets TOS for RTP audio packets.
> disallow=all
> allow = alaw
> language=it
> dtmfmode = inband
> progressinband=no
> canreinvite=no
> qualify=yes
>
> jbenable = no
> jbforce = no
> jbmaxsize = 400
> jbimpl = adaptive
>
> [0100x01]
> type=friend
> secret=0100x00
> context=outgoing
> callerid=("whatever" <0100x01>)
> host=dynamic
>
>
> C00x iax.conf:
>
> [general]
> bindport=4569
> bindaddr=192.168.52.9x (C001 .94 and C002 .95)
> language=it
> disallow=all
> allow = alaw
> allow = gsm
> jitterbuffer = yes
> forcejitterbuffer = no
> maxjitterbuffer = 400
> dropcount=2
> maxjitterinterps=10
> resyncthreshold=1000
> maxexcessbuffer=80
> minexcessbuffer=10
> jittershrinkrate=1
>
> autokill=yes
> auth=md5
>
> register => 0100x01:0100x00 at 192.168.52.56
>
> [server]
> type=friend
> context=incoming
> secret=pwd
> auth=md5
> host=192.168.52.56
> disallow=all
> allow=alaw
> allow=gsm
>
>
> C00x extensions.conf :
>
> [general]
> static = yes
> writeprotect = no
> clearglobalvars = no
>
> [globals]
> CODACCOUNT = 0100x01
> PWD = 0100x00
> SERVER = 192.168.52.56
>
> [outgoing]
> exten => _X.,1,NoOp(esco)
> ;exten => _X.,n,Dial(IAX2/${CODACCOUNT}:${PWD}@${SERVER}/${EXTEN})
> exten => _X.,n,Dial(IAX2/${CODACCOUNT}:${PWD}@server/${EXTEN})
> exten => _X.,n,Hangup
>
> [incoming]
> exten => _X.,1,NoOp(entro)
> exten => _X.,n,Answer
> exten => _X.,n,Playback(tt-weasels)
> exten => _X.,n,Echo
> exten => _X.,n,Hangup
>
>
> now Server configs :
>
> iax.conf :
>
> [general]
> bindport=4569
> bindaddr=192.168.52.56
> language=it
> disallow=all
> allow=alaw
> allow=gsm
> jitterbuffer = yes
> forcejitterbuffer = no
> maxjitterbuffer = 100
> dropcount=2
> maxjitterinterps=10
> resyncthreshold=1000
> maxexcessbuffer=80
> minexcessbuffer=10
> jittershrinkrate=1
> context=default
> autokill=yes
>
> [0100101]
> username=0100101
> type=friend
> secret=0100100
> auth=md5
> host=dynamic
> context=default
> callerid=0100101
> transfer=no
> qualify=yes
>
> [0100201]
> username=0100201
> type=friend
> secret=0100200
> auth=md5
> host=dynamic
> context=default
> callerid=0100201
> transfer=no
> qualify=yes
>
>
> extensions.conf
>
> [general]
> static=yes
> writeprotect=no
> clearglobalvars=no
>
> [globals]
>
> [default]
>
> exten => _X.,1,NoOp(here we are)
> exten => _X.,n,Dial(IAX2/server:pwd at 0100201/${EXTEN})
> exten => _X.,n,Hangup
>
> As you can see I've removed the realtime engine, and I've no "input  
> client" and "termination clients" difference, C001 calls the  
> server, which calls C002, which playback something and then Echoes,  
> anyway both C001 and C002 are the same type of "registered,  
> monitored friends" for the Server.
>
> transfer=no, and all works ok, with debug,verbose and 'iax2 set  
> debug' I see in Server's CLI :
>
> *CLI> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX      
> Subclass: NEW
>   Timestamp: 00010ms  SCall: 00006  DCall: 00000 [192.168.52.94:4569]
>   VERSION         : 2
>   CALLED NUMBER   : 12
>   CODEC_PREFS     : (alaw|gsm)
>   CALLING NUMBER  : 0100101
>   CALLING PRESNTN : 0
>   CALLING TYPEOFN : 0
>   CALLING TRANSIT : 0
>   CALLING NAME    : whatever
>   LANGUAGE        : it
>   USERNAME        : 0100101
>   FORMAT          : 8
>   CAPABILITY      : 57354
>   ADSICPE         : 2
>   DATE TIME       : 2007-03-20  12:16:30
>
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX      
> Subclass: AUTHREQ
>   Timestamp: 00013ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
>   AUTHMETHODS     : 2
>   CHALLENGE       : 347981677
>   USERNAME        : 0100101
>
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX      
> Subclass: AUTHREP
>   Timestamp: 00030ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
>   MD5 RESULT      : 32e6d2ead1582051eee0d54060bd00de
>
>    -- Accepting AUTHENTICATED call from 192.168.52.94:
>       > requested format = alaw,
>       > requested prefs = (alaw|gsm),
>       > actual format = alaw,
>       > host prefs = (alaw|gsm),
>       > priority = mine
> Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX      
> Subclass: ACCEPT
>   Timestamp: 00014ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
>   FORMAT          : 8
>
>    -- Executing [12 at default:1] NoOp("IAX2/0100101-3", "here we  
> are") in new stack
>    -- Executing [12 at default:2] Dial("IAX2/0100101-3", "IAX2/ 
> server:pwd at 0100201/12") in new stack
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX      
> Subclass: ACK
>   Timestamp: 00014ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
>    -- Called server:pwd at 0100201/12
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX      
> Subclass: NEW
>   Timestamp: 00017ms  SCall: 00004  DCall: 00000 [192.168.52.95:4569]
>   VERSION         : 2
>   CALLED NUMBER   : 12
>   CODEC_PREFS     : (alaw|gsm)
>   CALLING NUMBER  : 0100101
>   CALLING PRESNTN : 1
>   CALLING TYPEOFN : 0
>   CALLING TRANSIT : 0
>   CALLING NAME    :
>   LANGUAGE        : it
>   USERNAME        : server
>   FORMAT          : 8
>   CAPABILITY      : 57354
>   ADSICPE         : 2
>   DATE TIME       : 2007-03-20  11:12:24
>
> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX      
> Subclass: AUTHREQ
>   Timestamp: 00015ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
>   AUTHMETHODS     : 2
>   CHALLENGE       : 167609855
>   USERNAME        : server
>
> Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX      
> Subclass: AUTHREP
>   Timestamp: 00022ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
>   MD5 RESULT      : 9a8b1911a409f8823563157ffea9f8d2
>
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX      
> Subclass: ACCEPT
>   Timestamp: 00017ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
>   FORMAT          : 8
>
>    -- Call accepted by 192.168.52.95 (format alaw)
>    -- Format for call is alaw
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX      
> Subclass: ACK
>   Timestamp: 00017ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL  
> Subclass: ANSWER
>   Timestamp: 00020ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00020ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00040ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
> [Mar 20 11:12:25] DEBUG[8019]: chan_iax2.c:6649 socket_process:  
> Ooh, voice format changed to 8
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00040ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
>    -- IAX2/0100201-4 answered IAX2/0100101-3
> Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL  
> Subclass: ANSWER
>   Timestamp: 00017ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00017ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00055ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00108ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:12:25] DEBUG[8025]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[001] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00055ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00111ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:12:25] DEBUG[8026]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[001] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00055ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00114ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:12:25] DEBUG[8027]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[001] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00055ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00055ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00055ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00055ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00055ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE    
> Subclass: 8
>   Timestamp: 00175ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:12:25] DEBUG[8026]: chan_iax2.c:6649 socket_process:  
> Ooh, voice format changed to 8
> Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00175ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> [Mar 20 11:12:25] DEBUG[8043]: chan_iax2.c:3454 calc_timestamp:  
> predicted timestamp skew (175) > max (160), using real ts instead.
> Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 004 Type: VOICE    
> Subclass: 8
>   Timestamp: 00180ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00180ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: IAX      
> Subclass: HANGUP
>   Timestamp: 08576ms  SCall: 00006  DCall: 00003 [192.168.52.94:4569]
>   CAUSE CODE      : 16
>
> [Mar 20 11:12:33] DEBUG[8018]: chan_iax2.c:6944 socket_process:  
> Immediately destroying 3, having received hangup
> Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 08576ms  SCall: 00003  DCall: 00006 [192.168.52.94:4569]
> [Mar 20 11:12:34] DEBUG[8043]: chan_iax2.c:2937 iax2_hangup: We're  
> hanging up IAX2/0100201-4 now...
>    -- Hungup 'IAX2/0100201-4'
>  == Spawn extension (default, 12, 2) exited non-zero on  
> 'IAX2/0100101-3'
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 004 Type: IAX      
> Subclass: HANGUP
>   Timestamp: 08602ms  SCall: 00004  DCall: 00006 [192.168.52.95:4569]
>   CAUSE CODE      : 16
>
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 08602ms  SCall: 00006  DCall: 00004 [192.168.52.95:4569]
> [Mar 20 11:12:34] DEBUG[8043]: cdr_addon_mysql.c:210 mysql_log:  
> cdr_mysql: inserting a CDR record.
> [Mar 20 11:12:34] DEBUG[8043]: cdr_addon_mysql.c:226 mysql_log:  
> cdr_mysql: SQL command as follows: INSERT INTO cdr  
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,du 
> ration,billsec,disposition,amaflags,accountcode,userfield) VALUES  
> ('2007-03-20 11:12:25','0100101','0100101','12','default',  
> 'IAX2/0100101-3','IAX2/0100201-4','Dial','IAX2/ 
> server:pwd at 0100201/12',9,9,'ANSWERED',3,'','')
> [Mar 20 11:12:34] DEBUG[8043]: chan_iax2.c:2937 iax2_hangup: We're  
> hanging up IAX2/0100101-3 now...
> [Mar 20 11:12:34] DEBUG[8043]: chan_iax2.c:2947 iax2_hangup: Really  
> destroying IAX2/0100101-3 now...
>    -- Hungup 'IAX2/0100101-3'
>
>
> ##############################
> Lets change transfer=mediaonly in Server's iax.conf (both entries),  
> I hear only "wease.." from the playback, then nothing
> I go verbose, look for : "Received iseqno 4 not within window 5->5"  
> and "Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 004 Type: IAX      
> Subclass: (38?)"
>
>
> *CLI> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX      
> Subclass: NEW
>   Timestamp: 00009ms  SCall: 00005  DCall: 00000 [192.168.52.94:4569]
>   VERSION         : 2
>   CALLED NUMBER   : 12
>   CODEC_PREFS     : (alaw|gsm)
>   CALLING NUMBER  : 0100101
>   CALLING PRESNTN : 0
>   CALLING TYPEOFN : 0
>   CALLING TRANSIT : 0
>   CALLING NAME    : whatever
>   LANGUAGE        : it
>   USERNAME        : 0100101
>   FORMAT          : 8
>   CAPABILITY      : 57354
>   ADSICPE         : 2
>   DATE TIME       : 2007-03-20  12:19:52
>
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX      
> Subclass: AUTHREQ
>   Timestamp: 00014ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
>   AUTHMETHODS     : 2
>   CHALLENGE       : 170169981
>   USERNAME        : 0100101
>
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX      
> Subclass: AUTHREP
>   Timestamp: 00034ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
>   MD5 RESULT      : a9065963c5fbae3d35bf39bb3e92699b
>
>    -- Accepting AUTHENTICATED call from 192.168.52.94:
>       > requested format = alaw,
>       > requested prefs = (alaw|gsm),
>       > actual format = alaw,
>       > host prefs = (alaw|gsm),
>       > priority = mine
> Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX      
> Subclass: ACCEPT
>   Timestamp: 00040ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
>   FORMAT          : 8
>
>    -- Executing [12 at default:1] NoOp("IAX2/0100101-3", "here we  
> are") in new stack
>    -- Executing [12 at default:2] Dial("IAX2/0100101-3", "IAX2/ 
> server:pwd at 0100201/12") in new stack
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX      
> Subclass: ACK
>   Timestamp: 00040ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
>    -- Called server:pwd at 0100201/12
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX      
> Subclass: NEW
>   Timestamp: 00002ms  SCall: 00004  DCall: 00000 [192.168.52.95:4569]
>   VERSION         : 2
>   CALLED NUMBER   : 12
>   CODEC_PREFS     : (alaw|gsm)
>   CALLING NUMBER  : 0100101
>   CALLING PRESNTN : 1
>   CALLING TYPEOFN : 0
>   CALLING TRANSIT : 0
>   CALLING NAME    :
>   LANGUAGE        : it
>   USERNAME        : server
>   FORMAT          : 8
>   CAPABILITY      : 57354
>   ADSICPE         : 2
>   DATE TIME       : 2007-03-20  11:15:46
>
> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX      
> Subclass: AUTHREQ
>   Timestamp: 00006ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
>   AUTHMETHODS     : 2
>   CHALLENGE       : 818191730
>   USERNAME        : server
>
> Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX      
> Subclass: AUTHREP
>   Timestamp: 00006ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
>   MD5 RESULT      : a76bfbc04b8d5b71af86cc9ccf4cb819
>
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX      
> Subclass: ACCEPT
>   Timestamp: 00007ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
>   FORMAT          : 8
>
>    -- Call accepted by 192.168.52.95 (format alaw)
>    -- Format for call is alaw
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX      
> Subclass: ACK
>   Timestamp: 00007ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL  
> Subclass: ANSWER
>   Timestamp: 00010ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00010ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00020ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> [Mar 20 11:15:47] DEBUG[8170]: chan_iax2.c:6649 socket_process:  
> Ooh, voice format changed to 8
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00020ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
>    -- IAX2/0100201-4 answered IAX2/0100101-3
> Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL  
> Subclass: ANSWER
>   Timestamp: 00043ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: IAX      
> Subclass: TXREQ
>   Timestamp: 00095ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
>   APPARENT ADDRES : IPV4 192.168.52.95:4569
>   CALL NUMBER     : 5
>   TRANSFER ID     : 133782656
>
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00043ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00095ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 004 Type: IAX      
> Subclass: TXREQ
>   Timestamp: 00056ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
>   APPARENT ADDRES : IPV4 192.168.52.94:4569
>   CALL NUMBER     : 5
>   TRANSFER ID     : 133782656
>
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00056ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX      
> Subclass: TXREADY
>   Timestamp: 00066ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
>   CALL NUMBER     : 5
>
>    -- Channel 'IAX2/0100201-4' ready to transfer
> Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00066ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00059ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00171ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:47] DEBUG[8174]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[001] -- OSeqno: 004 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00059ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00059ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00059ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00162ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:47] DEBUG[8171]: chan_iax2.c:6618 socket_process:  
> Received iseqno 4 not within window 5->5
> [Mar 20 11:15:47] DEBUG[8171]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00059ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00165ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:47] DEBUG[8172]: chan_iax2.c:6618 socket_process:  
> Received iseqno 4 not within window 5->5
> [Mar 20 11:15:47] DEBUG[8172]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00059ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00059ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: IAX      
> Subclass: VNAK
>   Timestamp: 00168ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:47] DEBUG[8173]: chan_iax2.c:6618 socket_process:  
> Received iseqno 4 not within window 5->5
> [Mar 20 11:15:47] DEBUG[8173]: chan_iax2.c:7333 socket_process:  
> Received VNAK: resending outstanding frames
> Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 002 Type: VOICE    
> Subclass: 8
>   Timestamp: 00059ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00059ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 00059ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 005 Type: VOICE    
> Subclass: 8
>   Timestamp: 00201ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:47] DEBUG[8176]: chan_iax2.c:6649 socket_process:  
> Ooh, voice format changed to 8
> Tx-Frame Retry[-01] -- OSeqno: 005 ISeqno: 003 Type: IAX      
> Subclass: ACK
>   Timestamp: 00201ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: VOICE    
> Subclass: 8
>   Timestamp: 00160ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX      
> Subclass: ACK
>   Timestamp: 00160ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX      
> Subclass: TXREADY
>   Timestamp: 02135ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
>   CALL NUMBER     : 5
>
>    -- Channel 'IAX2/0100101-3' ready to transfer
>    -- Attempting media bridge of IAX2/0100101-3 and IAX2/0100201-4
> Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 004 Type: IAX      
> Subclass: (38?)
>   Timestamp: 02122ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
>   CALL NUMBER     : 5
>
> Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 005 Type: IAX      
> Subclass: (38?)
>   Timestamp: 02094ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
>   CALL NUMBER     : 5
>
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 006 Type: IAX      
> Subclass: ACK
>   Timestamp: 02122ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 005 Type: IAX      
> Subclass: ACK
>   Timestamp: 02094ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 005 Type: IAX      
> Subclass: TXREJ
>   Timestamp: 07100ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
>    -- Channel 'IAX2/0100201-4' unable to transfer
> Tx-Frame Retry[-01] -- OSeqno: 005 ISeqno: 006 Type: IAX      
> Subclass: ACK
>   Timestamp: 07100ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 004 Type: IAX      
> Subclass: TXREJ
>   Timestamp: 07133ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 007 Type: IAX      
> Subclass: ACK
>   Timestamp: 07133ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> [Mar 20 11:15:54] DEBUG[8204]: chan_iax2.c:3454 calc_timestamp:  
> predicted timestamp skew (5020) > max (160), using real ts instead.
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 007 Type: IAX      
> Subclass: LAGRQ
>   Timestamp: 10024ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 005 Type: IAX      
> Subclass: LAGRP
>   Timestamp: 10024ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 008 Type: IAX      
> Subclass: ACK
>   Timestamp: 10024ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 005 Type: IAX      
> Subclass: LAGRQ
>   Timestamp: 10018ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 009 Type: IAX      
> Subclass: LAGRP
>   Timestamp: 10018ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
> Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 006 Type: IAX      
> Subclass: ACK
>   Timestamp: 10018ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 005 Type: IAX      
> Subclass: LAGRQ
>   Timestamp: 10028ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 006 Type: IAX      
> Subclass: LAGRQ
>   Timestamp: 10029ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 007 Type: IAX      
> Subclass: LAGRP
>   Timestamp: 10028ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 007 Type: IAX      
> Subclass: ACK
>   Timestamp: 10028ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 006 Type: IAX      
> Subclass: LAGRP
>   Timestamp: 10029ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> [Mar 20 11:15:57] DEBUG[8173]: chan_iax2.c:6618 socket_process:  
> Received iseqno 6 not within window 7->7
> Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 008 Type: IAX      
> Subclass: ACK
>   Timestamp: 10029ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
> Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 009 Type: IAX      
> Subclass: HANGUP
>   Timestamp: 12486ms  SCall: 00005  DCall: 00003 [192.168.52.94:4569]
>   CAUSE CODE      : 16
>
> [Mar 20 11:15:59] DEBUG[8178]: chan_iax2.c:6944 socket_process:  
> Immediately destroying 3, having received hangup
> Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 007 Type: IAX      
> Subclass: ACK
>   Timestamp: 12486ms  SCall: 00003  DCall: 00005 [192.168.52.94:4569]
> [Mar 20 11:15:59] DEBUG[8204]: chan_iax2.c:2937 iax2_hangup: We're  
> hanging up IAX2/0100201-4 now...
>    -- Hungup 'IAX2/0100201-4'
>  == Spawn extension (default, 12, 2) exited non-zero on  
> 'IAX2/0100101-3'
> Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 008 Type: IAX      
> Subclass: HANGUP
>   Timestamp: 12467ms  SCall: 00004  DCall: 00005 [192.168.52.95:4569]
>   CAUSE CODE      : 16
>
> Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 008 Type: IAX      
> Subclass: ACK
>   Timestamp: 12467ms  SCall: 00005  DCall: 00004 [192.168.52.95:4569]
> [Mar 20 11:15:59] DEBUG[8204]: cdr_addon_mysql.c:210 mysql_log:  
> cdr_mysql: inserting a CDR record.
> [Mar 20 11:15:59] DEBUG[8204]: cdr_addon_mysql.c:226 mysql_log:  
> cdr_mysql: SQL command as follows: INSERT INTO cdr  
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,du 
> ration,billsec,disposition,amaflags,accountcode,userfield) VALUES  
> ('2007-03-20 11:15:47','0100101','0100101','12','default',  
> 'IAX2/0100101-3','IAX2/0100201-4','Dial','IAX2/ 
> server:pwd at 0100201/12',12,12,'ANSWERED',3,'','')
> [Mar 20 11:15:59] DEBUG[8204]: chan_iax2.c:2937 iax2_hangup: We're  
> hanging up IAX2/0100101-3 now...
> [Mar 20 11:15:59] DEBUG[8204]: chan_iax2.c:2947 iax2_hangup: Really  
> destroying IAX2/0100101-3 now...
>    -- Hungup 'IAX2/0100101-3'
>
> *CLI> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX      
> Subclass: REGREQ
>   Timestamp: 00006ms  SCall: 00006  DCall: 00000 [192.168.52.95:4569]
>   USERNAME        : 0100201
>   REFRESH         : 60
>
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX      
> Subclass: REGACK
>   Timestamp: 00007ms  SCall: 00005  DCall: 00006 [192.168.52.95:4569]
>   USERNAME        : 0100201
>   DATE TIME       : 2007-03-20  11:16:02
>   REFRESH         : 60
>   APPARENT ADDRES : IPV4 192.168.52.95:4569
>   CALLING NUMBER  : 0100201
>
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX      
> Subclass: ACK
>   Timestamp: 00007ms  SCall: 00006  DCall: 00005 [192.168.52.95:4569]
>
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>   http://lists.digium.com/mailman/listinfo/asterisk-users

Tim Panton

www.mexuar.net
www.westhawk.co.uk/





More information about the asterisk-users mailing list