[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