[asterisk-users] transfer=mediaonly : can't hear nothing
Simone Cittadini
mymailforlists at gmail.com
Tue Mar 20 03:36:17 MST 2007
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,duration,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,duration,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]
More information about the asterisk-users
mailing list