22 Oct
2014
22 Oct
'14
10:48 p.m.
Hi,
I just updated to 4.2 stable along with latest rtpengine module compiled
today from git.
I'm also running latest (compiled today) RFC5766 turn server on the same
Debian 7 host.
I noticed that sometimes I get one way audio with linphone client in
Android, and looking through the logs I see these STUN error messages:
rtpengine[4633]: [port 10448] Not handling potential STUN packet from
85.xx.xx.xx:7076: FINGERPRINT attribute missing
That 85.xx.xx.xx address is indeed the public IP of the linphone client.
Looking further in the RTP engine logs you can see it's not getting the IP
which I believe would explain the 1 way audio issues.
Media #1, port 10468 <> [::]:0 , 0 p, 0 b, 0 e
Now why would rtpengine be dealing with STUN packets at all? I imagine the
RFC5766 stun server would handle that completely.
I guess the more I dig, the more confused I get. Has anything changed
recently in rtpengine or kamailio 4.2 to produce this behavior?
Thanks
22 Oct
22 Oct
11 p.m.
On 10/22/14 15:48, Peter Villeneuve wrote:
Hi,
I just updated to 4.2 stable along with latest rtpengine module compiled
today from git.
I'm also running latest (compiled today) RFC5766 turn server on the same
Debian 7 host.
I noticed that sometimes I get one way audio with linphone client in
Android, and looking through the logs I see these STUN error messages:
rtpengine[4633]: [port 10448] Not handling potential STUN packet from
85.xx.xx.xx:7076: FINGERPRINT attribute missing
That 85.xx.xx.xx address is indeed the public IP of the linphone client.
Looking further in the RTP engine logs you can see it's not getting the
IP which I believe would explain the 1 way audio issues.
Media #1, port 10468 <> [::]:0 , 0 p, 0 b, 0 e
Now why would rtpengine be dealing with STUN packets at all? I imagine
the RFC5766 stun server would handle that completely.
I guess the more I dig, the more confused I get. Has anything changed
recently in rtpengine or kamailio 4.2 to produce this behavior?
This is part of ICE (RFC 5245 and RFC 5389). If ICE is enabled,
rtpengine will listen for and handle STUN packets, which in this context
require the fingerprint attribute.
I don't think this explains your 1-way audio issue though. From the log
message you posted, I suspect that no "answer" was received by rtpengine.
cheers
11:53 p.m.
Thanks Richard.
I guess I'll have to keep looking then.
Have there been any changes in the syntax for rtpengine and its integration
with Kamailio 4.2 lately?
I have quite a few of those "empty IPs" (for lack of a better word) in the
rtpengine logs and I can't figure out why they occur.
I have the following in my kamailio config
# RTPProxy control
route[NATMANAGE] {
#!ifdef WITH_NAT
if (is_request()) {
if(has_totag()) {
if(check_route_param("nat=yes")) {
setbflag(FLB_NATB);
}
}
}
if (!(isflagset(FLT_NATS) || isbflagset(FLB_NATB)))
return;
rtpengine_manage("replace-origin replace-session-connection");
if (is_request()) {
if (!has_totag()) {
if(t_is_branch_route()) {
add_rr_param(";nat=yes");
}
}
}
if (is_reply()) {
if(isbflagset(FLB_NATB)) {
if(is_first_hop())
set_contact_alias();
}
}
#!endif
return;
}
Does anything jump out at you as being wrong?
My goal is to have linphone clients (android) with ICE enabled call
Groundwire clients (iOS) also with ICE enabled. Both are using the same
STUN server that sits on the same machine as Kamailio.
Ideally rtpengine wouldn't get involved at all and would ignore the SDP
since both UACs should be able to use ICE to negotiate a p2p connection
between them.
However, if one is behind symmetric NAT than rtpengine should be called in
to relay the media.
I've also tried the above config by adding rtpengine_manage("replace-origin
replace-session-connection ICE=force-relay"); but I think that's made
debugging even harder.
I'm not sure if the problem lies with kamailio/rtpengine (or my config for
them) or if it is the UACs that aren't playing nicely even though they
supposedly support SIP and ICE RFCs. It seems when they call each other ICE
isn't being used at all (at least linphone display shows ICE not activated)
even though the media is flowing normally.
Anyway, I don't need to be spoon fed, but a push in the right direction
would be much appreciated.
Thanks,
Peter
On Wed, Oct 22, 2014 at 9:00 PM, Richard Fuchs <rfuchs(a)sipwise.com> wrote:
On 10/22/14 15:48, Peter Villeneuve wrote:
Hi,
I just updated to 4.2 stable along with latest rtpengine module compiled
today from git.
I'm also running latest (compiled today) RFC5766 turn server on the same
Debian 7 host.
I noticed that sometimes I get one way audio with linphone client in
Android, and looking through the logs I see these STUN error messages:
rtpengine[4633]: [port 10448] Not handling potential STUN packet from
85.xx.xx.xx:7076: FINGERPRINT attribute missing
That 85.xx.xx.xx address is indeed the public IP of the linphone client.
Looking further in the RTP engine logs you can see it's not getting the
IP which I believe would explain the 1 way audio issues.
Media #1, port 10468 <> [::]:0 , 0 p, 0 b, 0 e
Now why would rtpengine be dealing with STUN packets at all? I imagine
the RFC5766 stun server would handle that completely.
I guess the more I dig, the more confused I get. Has anything changed
recently in rtpengine or kamailio 4.2 to produce this behavior?
This is part of ICE (RFC 5245 and RFC 5389). If ICE is enabled,
rtpengine will listen for and handle STUN packets, which in this context
require the fingerprint attribute.
I don't think this explains your 1-way audio issue though. From the log
message you posted, I suspect that no "answer" was received by rtpengine.
cheers
_______________________________________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
23 Oct
23 Oct
1:04 a.m.
On 10/22/14 16:53, Peter Villeneuve wrote:
Thanks Richard.
I guess I'll have to keep looking then.
Have there been any changes in the syntax for rtpengine and its
integration with Kamailio 4.2 lately?
I have quite a few of those "empty IPs" (for lack of a better word) in
the rtpengine logs and I can't figure out why they occur.
I have the following in my kamailio config
# RTPProxy control
route[NATMANAGE] {
#!ifdef WITH_NAT
if (is_request()) {
if(has_totag()) {
if(check_route_param("nat=yes")) {
setbflag(FLB_NATB);
}
}
}
if (!(isflagset(FLT_NATS) || isbflagset(FLB_NATB)))
return;
rtpengine_manage("replace-origin replace-session-connection");
if (is_request()) {
if (!has_totag()) {
if(t_is_branch_route()) {
add_rr_param(";nat=yes");
}
}
}
if (is_reply()) {
if(isbflagset(FLB_NATB)) {
if(is_first_hop())
set_contact_alias();
}
}
#!endif
return;
}
Does anything jump out at you as being wrong?
My goal is to have linphone clients (android) with ICE enabled call
Groundwire clients (iOS) also with ICE enabled. Both are using the same
STUN server that sits on the same machine as Kamailio.
Ideally rtpengine wouldn't get involved at all and would ignore the SDP
since both UACs should be able to use ICE to negotiate a p2p connection
between them.
However, if one is behind symmetric NAT than rtpengine should be called
in to relay the media.
I've also tried the above config by
adding rtpengine_manage("replace-origin replace-session-connection
ICE=force-relay"); but I think that's made debugging even harder.
I'm not sure if the problem lies with kamailio/rtpengine (or my config
for them) or if it is the UACs that aren't playing nicely even though
they supposedly support SIP and ICE RFCs. It seems when they call each
other ICE isn't being used at all (at least linphone display shows ICE
not activated) even though the media is flowing normally.
Anyway, I don't need to be spoon fed, but a push in the right direction
would be much appreciated.
The best way to find out what could be going on is to post the complete
log from rtpengine for one such call. This will show all the SDP bodies
and everything else involved.
cheers
8:44 p.m.
Thanks again for your help Richard.
Here's the complete log from a call from 1000 to 1104. This time both are
linphone Android UACs sitting behind the same NAT router.
Sorry about the length but it's probably best if you can see the whole
logs. I have xxed out the public IPs to protect the innocent.
You'll also notice I have tried adding ICE=force-relay and indeed it seems
to be creating the proper relay candidates.
Thanks again,
Peter
Oct 23 17:35:50 pbx rtpengine[4633]: Got valid command from 127.0.0.1:55139:
offer - { "sdp": "v=0#015#012o=1000 3601 330 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:61bd100089ee2177c7cae0bb#015#012a=ice-ufrag:03cbec52#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012 ...
Oct 23 17:35:50 pbx rtpengine[4633]: ... a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"gBRbDZzJvq", "received ...
Oct 23 17:35:50 pbx rtpengine[4633]: ... -from": [ "IP4",
"85.xx.xx.247" ],
"from-tag": "R7wGZh8mM", "command": "offer" }
Oct 23 17:35:50 pbx rtpengine[4633]: [gBRbDZzJvq] Creating new call
Oct 23 17:35:50 pbx rtpengine[4633]: [gBRbDZzJvq] Returning to SIP proxy:
d3:sdp1000:v=0#015#012o=1000 3601 330 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:61bd100089ee2177c7cae0bb#015#012a=ice-ufrag:03cbec52#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/8000 ...
Oct 23 17:35:50 pbx rtpengine[4633]: [gBRbDZzJvq] ... #015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.4 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 7076 typ srflx
raddr 192.168.1.4 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 7077 typ srflx raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12006 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
167772 ...
Oct 23 17:35:50 pbx rtpengine[4633]: [gBRbDZzJvq] ... 14 79.xx.xx.153 12007
typ relay#015#0126:result2:oke
Oct 23 17:35:53 pbx rtpengine[4633]: Got valid command from 127.0.0.1:46671:
answer - { "sdp": "v=0#015#012o=1104 1621 1986 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:922295838662ba3be2a9c973#015#012a=ice-ufrag:3fd0ad3b#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 1049 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr= ...
Oct 23 17:35:53 pbx rtpengine[4633]: ... on#015#012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 1049 typ srflx raddr 192.168.1.16 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 1050 typ srflx
raddr 192.168.1.16 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"gBRbDZzJvq", " ...
Oct 23 17:35:53 pbx rtpengine[4633]: ... received-from": [ "IP4",
"85.xx.xx.247" ], "from-tag": "R7wGZh8mM",
"to-tag": "--XZThM", "command":
"answer" }
Oct 23 17:35:53 pbx rtpengine[4633]: [gBRbDZzJvq] Returning to SIP proxy:
d3:sdp1007:v=0#015#012o=1104 1621 1986 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:922295838662ba3be2a9c973#015#012a=ice-ufrag:3fd0ad3b#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 1049 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/8 ...
Oct 23 17:35:53 pbx rtpengine[4633]: [gBRbDZzJvq] ... 000#015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.16 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.16 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 1049 typ srflx
raddr 192.168.1.16 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 1050 typ srflx raddr 192.168.1.16 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12020 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP ...
Oct 23 17:35:53 pbx rtpengine[4633]: [gBRbDZzJvq] ... 16777214
79.xx.xx.153 12021 typ relay#015#0126:result2:oke
Oct 23 17:35:56 pbx rtpengine[4633]: Got valid command from 127.0.0.1:55139:
offer - { "sdp": "v=0#015#012o=1000 3601 331 IN IP4
85.xx.xx.247#015#012s=Talk#015#012c=IN IP4
85.xx.xx.247#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:61bd100089ee2177c7cae0bb#015#012a=ice-ufrag:03cbec52#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a ...
Oct 23 17:35:56 pbx rtpengine[4633]: ... =rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012a=remote-candidates:1 192.168.1.1 7076
2 192.168.1.1 7077#015#012", "ICE": "force-relay",
"replace": [ "origin",
"session-connection" ], "call-id": "gBRbDZzJvq",
"received-from": [ "IP4",
"85.xx.xx.247" ], "fr ...
Oct 23 17:35:56 pbx rtpengine[4633]: ... om-tag": "R7wGZh8mM",
"to-tag":
"--XZThM", "command": "offer" }
Oct 23 17:35:56 pbx rtpengine[4633]: [gBRbDZzJvq] Returning to SIP proxy:
d3:sdp960:v=0#015#012o=1000 3601 331 IN IP4
85.xx.xx.247#015#012s=Talk#015#012c=IN IP4
85.xx.xx.247#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:61bd100089ee2177c7cae0bb#015#012a=ice-ufrag:03cbec52#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000#015#012 ...
Oct 23 17:35:56 pbx rtpengine[4633]: [gBRbDZzJvq] ... a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012a=remote-candidates:1 192.168.1.1 7076
2 192.168.1.1 7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1
UDP 16777215 79.xx.xx.153 12006 typ
relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP 16777214 79.xx.xx.153 12007
typ relay#015#0126:resu ...
Oct 23 17:35:56 pbx rtpengine[4633]: [gBRbDZzJvq] ... lt2:oke
Oct 23 17:35:56 pbx rtpengine[4633]: Got valid command from 127.0.0.1:46671:
answer - { "sdp": "v=0#015#012o=1104 1621 1988 IN IP4
192.168.1.1#015#012s=Talk#015#012c=IN IP4
192.168.1.1#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:922295838662ba3be2a9c973#015#012a=ice-ufrag:3fd0ad3b#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtp ...
Oct 23 17:35:56 pbx rtpengine[4633]: ... map:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:3 1 UDP 1862270975
192.168.1.1 7076 typ prflx raddr 192.168.1.16 rport
7076#015#012a=candidate:3 2 UDP 1862270974 192.168.1.1 7077 typ prflx raddr
192.168.1.16 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"gBRbDZzJvq", "received-from":
[ "IP4", "85.xx.xx.247" ], "from-tag":
"R7wGZh8mM", "to-tag": "--XZThM",
"command": "answer" }
Oct 23 17:35:56 pbx rtpengine[4633]: [gBRbDZzJvq] Returning to SIP proxy:
d3:sdp892:v=0#015#012o=1104 1621 1988 IN IP4
192.168.1.1#015#012s=Talk#015#012c=IN IP4
192.168.1.1#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:922295838662ba3be2a9c973#015#012a=ice-ufrag:3fd0ad3b#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000#015#012a=fmt ...
Oct 23 17:35:56 pbx rtpengine[4633]: [gBRbDZzJvq] ... p:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:3 1 UDP 1862270975
192.168.1.1 7076 typ prflx raddr 192.168.1.16 rport
7076#015#012a=candidate:3 2 UDP 1862270974 192.168.1.1 7077 typ prflx raddr
192.168.1.16 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12036 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
16777214 79.xx.xx.153 12037 typ relay#015#0126:result2:oke
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] Closing call due to
timeout
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] Final packet stats:
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] --- Tag '--XZThM',
created 1:05 ago, in dialogue with 'R7wGZh8mM'
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] ------ Media #1, port
12006 <> 85.xx.xx.247:7076 , 3 p, 256 b, 0 e
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] ------ Media #1, port
12007 <> 85.xx.xx.247:7077 (RTCP), 4 p, 352 b, 0 e
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] --- Tag 'R7wGZh8mM',
created 1:05 ago, in dialogue with '--XZThM'
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] ------ Media #1, port
12036 <> 85.xx.xx.247:7076 , 4 p, 352 b, 0 e
Oct 23 17:36:55 pbx rtpengine[4633]: [gBRbDZzJvq] ------ Media #1, port
12037 <> 85.xx.xx.247:7077 (RTCP), 6 p, 480 b, 0 e
Oct 23 17:37:02 pbx rtpengine[4633]: Got valid command from 127.0.0.1:46671:
delete - { "ICE": "force-relay", "call-id":
"gBRbDZzJvq", "received-from":
[ "IP4", "85.xx.xx.247" ], "from-tag":
"R7wGZh8mM", "command": "delete" }
Oct 23 17:37:02 pbx rtpengine[4633]: [gBRbDZzJvq] Call-ID to delete not
found
Oct 23 17:37:02 pbx rtpengine[4633]: Returning to SIP proxy:
d7:warning38:Call-ID not found or tags didn't match6:result2:oke
On Wed, Oct 22, 2014 at 11:04 PM, Richard Fuchs <rfuchs(a)sipwise.com> wrote:
On 10/22/14 16:53, Peter Villeneuve wrote:
Thanks Richard.
I guess I'll have to keep looking then.
Have there been any changes in the syntax for rtpengine and its
integration with Kamailio 4.2 lately?
I have quite a few of those "empty IPs" (for lack of a better word) in
the rtpengine logs and I can't figure out why they occur.
I have the following in my kamailio config
# RTPProxy control
route[NATMANAGE] {
#!ifdef WITH_NAT
if (is_request()) {
if(has_totag()) {
if(check_route_param("nat=yes")) {
setbflag(FLB_NATB);
}
}
}
if (!(isflagset(FLT_NATS) || isbflagset(FLB_NATB)))
return;
rtpengine_manage("replace-origin replace-session-connection");
if (is_request()) {
if (!has_totag()) {
if(t_is_branch_route()) {
add_rr_param(";nat=yes");
}
}
}
if (is_reply()) {
if(isbflagset(FLB_NATB)) {
if(is_first_hop())
set_contact_alias();
}
}
#!endif
return;
}
Does anything jump out at you as being wrong?
My goal is to have linphone clients (android) with ICE enabled call
Groundwire clients (iOS) also with ICE enabled. Both are using the same
STUN server that sits on the same machine as Kamailio.
Ideally rtpengine wouldn't get involved at all and would ignore the SDP
since both UACs should be able to use ICE to negotiate a p2p connection
between them.
However, if one is behind symmetric NAT than rtpengine should be called
in to relay the media.
I've also tried the above config by
adding rtpengine_manage("replace-origin replace-session-connection
ICE=force-relay"); but I think that's made debugging even harder.
I'm not sure if the problem lies with kamailio/rtpengine (or my config
for them) or if it is the UACs that aren't playing nicely even though
they supposedly support SIP and ICE RFCs. It seems when they call each
other ICE isn't being used at all (at least linphone display shows ICE
not activated) even though the media is flowing normally.
Anyway, I don't need to be spoon fed, but a push in the right direction
would be much appreciated.
The best way to find out what could be going on is to post the complete
log from rtpengine for one such call. This will show all the SDP bodies
and everything else involved.
cheers
_______________________________________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
9:14 p.m.
On 10/23/14 13:44, Peter Villeneuve wrote:
Thanks again for your help Richard.
Here's the complete log from a call from 1000 to 1104. This time both
are linphone Android UACs sitting behind the same NAT router.
Sorry about the length but it's probably best if you can see the whole
logs. I have xxed out the public IPs to protect the innocent.
You'll also notice I have tried adding ICE=force-relay and indeed it
seems to be creating the proper relay candidates.
I don't really see anything wrong with this call and it doesn't seem to
exhibit the issues you've mentioned, as there are no error messages or
anything else strange. Both clients are ICE and you're using
ICE=force-relay, so I'm guessing that the clients have established
communications outside of rtpengine's path, which is why it closes the
call with a timeout (no packets received).
cheers
9:44 p.m.
You're right. That call went through without any problems.
Here are the logs for 2 more calls. One from 1000 (Linphone on Android with
ICE enabled) to 1010 (Groundwire on iOS with ICE enabled), resulting in no
audio in either direction.
And call 2 from 1000 to 1104 (Linphone on Android with ICE enabled). This
resulted in 1 way audio.
Both of these calls had the ICE=force-relay flag set
I then tried the same exact calls, this time without ICE=force-relay, and
both calls went through fine. Also, I don't see that Missing STUN
fingerprint that shows up once in awhile
Weird.
I hope you can make some sense of this.
Cheers,
Peter
Here are the logs
rtpengine_manage("replace-origin replace-session-connection
ICE=force-relay");
Oct 23 18:23:36 pbx rtpengine[4633]: Got valid command from 127.0.0.1:58816:
offer - { "sdp": "v=0#015#012o=1000 2180 1168 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:fc97aefa4dc375ac8b8eb358#015#012a=ice-ufrag:97dc6a58#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015 ...
Oct 23 18:23:36 pbx rtpengine[4633]: ... #012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"3FPovr0noK", "receive ...
Oct 23 18:23:36 pbx rtpengine[4633]: ... d-from": [ "IP4",
"85.xx.xx.247"
], "from-tag": "ypjpPM5OI", "command": "offer" }
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] Creating new call
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] Returning to SIP proxy:
d3:sdp1001:v=0#015#012o=1000 2180 1168 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:fc97aefa4dc375ac8b8eb358#015#012a=ice-ufrag:97dc6a58#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/800 ...
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] ... 0#015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.4 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 7076 typ srflx
raddr 192.168.1.4 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 7077 typ srflx raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12230 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
16777 ...
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] ... 214 79.xx.xx.153
12231 typ relay#015#0126:result2:oke
Oct 23 18:23:36 pbx rtpengine[4633]: Got valid command from 127.0.0.1:58816:
offer - { "sdp": "v=0#015#012o=1000 2180 1168 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:fc97aefa4dc375ac8b8eb358#015#012a=ice-ufrag:97dc6a58#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015 ...
Oct 23 18:23:36 pbx rtpengine[4633]: ... #012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"3FPovr0noK", "receive ...
Oct 23 18:23:36 pbx rtpengine[4633]: ... d-from": [ "IP4",
"85.xx.xx.247"
], "from-tag": "ypjpPM5OI", "command": "offer" }
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] Returning to SIP proxy:
d3:sdp1001:v=0#015#012o=1000 2180 1168 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:fc97aefa4dc375ac8b8eb358#015#012a=ice-ufrag:97dc6a58#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/800 ...
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] ... 0#015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.4 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 7076 typ srflx
raddr 192.168.1.4 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 7077 typ srflx raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12230 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
16777 ...
Oct 23 18:23:36 pbx rtpengine[4633]: [3FPovr0noK] ... 214 79.xx.xx.153
12231 typ relay#015#0126:result2:oke
Oct 23 18:23:49 pbx rtpengine[4633]: Got valid command from 127.0.0.1:42531:
answer - { "sdp": "v=0#015#012o=- 18970 59662 IN IP4
85.xx.xx.247#015#012s=wpxmvks#015#012c=IN IP4 85.xx.xx.247#015#012t=0
0#015#012m=audio 48886 RTP/AVP 124 101#015#012a=rtpmap:101
TELEPHONE-EVENT/8000#015#012a=rtpmap:124 OPUS/48000/2#015#012a=fmtp:101
0-15#015#012a=fmtp:124
maxplaybackrate=16000;useinbandfec=1#015#012a=ice-ufrag:B6427B#015#012a=ice-pwd:A0342B9F09BCB4AE207C5A8A146321BF#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ==
1 UDP 2130706431 192.168.1.3 48886 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 1 UDP 169449 ...
Oct 23 18:23:49 pbx rtpengine[4633]: ... 8815 85.xx.xx.247 48886 typ srflx
raddr 192.168.1.3 rport 48886#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ== 2
UDP 2130706430 192.168.1.3 48887 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 2 UDP 1694498814
85.xx.xx.247 48887 typ srflx raddr 192.168.1.3 rport
48887#015#012a=ptime:20#015#012a=sendrecv#015#012", "ICE":
"force-relay",
"replace": [ "origin", "session-connection" ],
"call-id": "3FPovr0noK",
"received-from": [ "IP4", "162.243.35.55" ],
"from-tag": "ypjpPM5OI",
"to-tag": "1A19A9FE28B2BBC914495C1A3B5ACA0F" ...
Oct 23 18:23:49 pbx rtpengine[4633]: ... , "command": "answer" }
Oct 23 18:23:49 pbx rtpengine[4633]: [3FPovr0noK] Returning to SIP proxy:
d3:sdp882:v=0#015#012o=- 18970 59662 IN IP4
85.xx.xx.247#015#012s=wpxmvks#015#012c=IN IP4 85.xx.xx.247#015#012t=0
0#015#012m=audio 48886 RTP/AVP 124 101#015#012a=rtpmap:101
TELEPHONE-EVENT/8000#015#012a=rtpmap:124 OPUS/48000/2#015#012a=fmtp:101
0-15#015#012a=fmtp:124
maxplaybackrate=16000;useinbandfec=1#015#012a=ice-ufrag:B6427B#015#012a=ice-pwd:A0342B9F09BCB4AE207C5A8A146321BF#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ==
1 UDP 2130706431 192.168.1.3 48886 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 1 UDP 1694498815
85.xx.xx.247 48886 ...
Oct 23 18:23:49 pbx rtpengine[4633]: [3FPovr0noK] ... typ srflx raddr
192.168.1.3 rport 48886#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ== 2 UDP
2130706430 192.168.1.3 48887 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 2 UDP 1694498814
85.xx.xx.247 48887 typ srflx raddr 192.168.1.3 rport
48887#015#012a=ptime:20#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 16777215 79.xx.xx.153 12250 typ
relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP 16777214 79.xx.xx.153 12251
typ relay#015#0126:result2:oke
Oct 23 18:24:19 pbx rtpengine[4633]: Got valid command from 127.0.0.1:59621:
delete - { "ICE": "force-relay", "call-id":
"3FPovr0noK", "received-from":
[ "IP4", "85.xx.xx.247" ], "from-tag":
"ypjpPM5OI", "command": "delete" }
Oct 23 18:24:19 pbx rtpengine[4633]: [3FPovr0noK] Scheduling deletion of
call branch 'ypjpPM5OI' in 30 seconds
Oct 23 18:24:19 pbx rtpengine[4633]: [3FPovr0noK] Returning to SIP proxy:
d7:createdi1414088616e11:last
signali1414088629e4:tagsd9:ypjpPM5OId3:tag9:ypjpPM5OI7:createdi1414088616e16:in
dialogue
with32:1A19A9FE28B2BBC914495C1A3B5ACA0F6:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12250e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414088616e5:flagsl3:RTP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeed10:
...
Oct 23 18:24:19 pbx rtpengine[4633]: [3FPovr0noK] ... local
porti12251e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414088616e5:flagsl4:RTCP6:fillede5:statsd7:packetsi0e5:bytesi0e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeee32:1A19A9FE28B2BBC914495C1A3B5ACA0Fd3:tag32:1A19A9FE28B2BBC914495C1A3B5ACA0F7:createdi1414088616e16:in
dialogue
with9:ypjpPM5OI6:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti1 ...
Oct 23 18:24:19 pbx rtpengine[4633]: [3FPovr0noK] ...
2230e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti48886ee19:advertised
endpointd6:family4:IPv47:address13:162.243.35.554:porti48886ee11:last
packeti1414088631e5:flagsl3:RTP6:fillede5:statsd7:packetsi5e5:bytesi460e6:errorsi0eeed10:local
porti12231e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti48887ee19:advertised
endpointd6:family4:IPv47:address13:162.243.35.554:porti48887ee11:last
packeti1414088632e5:flagsl4:RTCP6:fillede5:statsd7:packetsi5e5:bytesi460e6:errorsi0eeee5:fl
...
Oct 23 18:24:19 pbx rtpengine[4633]: [3FPovr0noK] ...
agsl11:initialized11:passthrough3:ICEeeeee6:totalsd3:RTPd7:packetsi5e5:bytesi460e6:errorsi0ee4:RTCPd7:packetsi5e5:bytesi460e6:errorsi0eee6:result2:oke
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] Call branch 'ypjpPM5OI'
deleted, no more branches remaining
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] Final packet stats:
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] --- Tag
'1A19A9FE28B2BBC914495C1A3B5ACA0F', created 1:13 ago, in dialogue with
'ypjpPM5OI'
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] ------ Media #1, port
12230 <> 85.xx.xx.247:48886, 5 p, 460 b, 0 e
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] ------ Media #1, port
12231 <> 85.xx.xx.247:48887 (RTCP), 5 p, 460 b, 0 e
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] --- Tag 'ypjpPM5OI',
created 1:13 ago, in dialogue with '1A19A9FE28B2BBC914495C1A3B5ACA0F'
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] ------ Media #1, port
12250 <> 85.xx.xx.247:7076 , 0 p, 0 b, 0 e
Oct 23 18:24:49 pbx rtpengine[4633]: [3FPovr0noK] ------ Media #1, port
12251 <> 85.xx.xx.247:7077 (RTCP), 0 p, 0 b, 0 e
Oct 23 18:25:11 pbx rtpengine[4633]: Got valid command from 127.0.0.1:59621:
offer - { "sdp": "v=0#015#012o=1000 2963 761 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:da4ac4e59c3fbbde88b55a6d#015#012a=ice-ufrag:2a32181a#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012 ...
Oct 23 18:25:11 pbx rtpengine[4633]: ... a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"6bRH2rngPS", "received ...
Oct 23 18:25:11 pbx rtpengine[4633]: ... -from": [ "IP4",
"85.xx.xx.247" ],
"from-tag": "x9WGjS4~9", "command": "offer" }
Oct 23 18:25:11 pbx rtpengine[4633]: [6bRH2rngPS] Creating new call
Oct 23 18:25:11 pbx rtpengine[4633]: [6bRH2rngPS] Returning to SIP proxy:
d3:sdp1000:v=0#015#012o=1000 2963 761 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:da4ac4e59c3fbbde88b55a6d#015#012a=ice-ufrag:2a32181a#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/8000 ...
Oct 23 18:25:11 pbx rtpengine[4633]: [6bRH2rngPS] ... #015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.4 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 7076 typ srflx
raddr 192.168.1.4 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 7077 typ srflx raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12268 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
167772 ...
Oct 23 18:25:11 pbx rtpengine[4633]: [6bRH2rngPS] ... 14 79.xx.xx.153 12269
typ relay#015#0126:result2:oke
Oct 23 18:25:14 pbx rtpengine[4633]: Got valid command from 127.0.0.1:42531:
answer - { "sdp": "v=0#015#012o=1104 2835 2386 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:57046d3e78d22a34b13ce526#015#012a=ice-ufrag:5b4f3e35#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 1051 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr= ...
Oct 23 18:25:14 pbx rtpengine[4633]: ... on#015#012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 1051 typ srflx raddr 192.168.1.16 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 1052 typ srflx
raddr 192.168.1.16 rport 7077#015#012", "ICE": "force-relay",
"replace": [
"origin", "session-connection" ], "call-id":
"6bRH2rngPS", " ...
Oct 23 18:25:14 pbx rtpengine[4633]: ... received-from": [ "IP4",
"85.xx.xx.247" ], "from-tag": "x9WGjS4~9",
"to-tag": "nfaREr4", "command":
"answer" }
Oct 23 18:25:14 pbx rtpengine[4633]: [6bRH2rngPS] Returning to SIP proxy:
d3:sdp1007:v=0#015#012o=1104 2835 2386 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:57046d3e78d22a34b13ce526#015#012a=ice-ufrag:5b4f3e35#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 1051 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 speex/8 ...
Oct 23 18:25:14 pbx rtpengine[4633]: [6bRH2rngPS] ... 000#015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=candidate:1 1 UDP 2130706431 192.168.1.16 7076 typ
host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.16 7077 typ
host#015#012a=candidate:2 1 UDP 1694498815 85.xx.xx.247 1051 typ srflx
raddr 192.168.1.16 rport 7076#015#012a=candidate:2 2 UDP 1694498814
85.xx.xx.247 1052 typ srflx raddr 192.168.1.16 rport
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12278 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP ...
Oct 23 18:25:14 pbx rtpengine[4633]: [6bRH2rngPS] ... 16777214
79.xx.xx.153 12279 typ relay#015#0126:result2:oke
Oct 23 18:25:18 pbx rtpengine[4633]: [6bRH2rngPS port 12268] Confirmed peer
address as 85.xx.xx.247:7076
Oct 23 18:25:18 pbx rtpengine[4633]: [6bRH2rngPS port 12278] Confirmed peer
address as 85.xx.xx.247:7076
Oct 23 18:25:18 pbx rtpengine[4633]: [6bRH2rngPS port 12278] Kernelizing
media stream
Oct 23 18:25:18 pbx rtpengine[4633]: [6bRH2rngPS port 12269] Confirmed peer
address as 85.xx.xx.247:7077
Oct 23 18:25:18 pbx rtpengine[4633]: [6bRH2rngPS port 12279] Confirmed peer
address as 85.xx.xx.247:7077
Oct 23 18:25:21 pbx rtpengine[4633]: [6bRH2rngPS port 12268] Kernelizing
media stream
Oct 23 18:25:27 pbx rtpengine[4633]: Got valid command from 127.0.0.1:59621:
offer - { "sdp": "v=0#015#012o=1000 2963 762 IN IP4
85.xx.xx.247#015#012s=Talk#015#012c=IN IP4
85.xx.xx.247#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:da4ac4e59c3fbbde88b55a6d#015#012a=ice-ufrag:2a32181a#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a ...
Oct 23 18:25:27 pbx rtpengine[4633]: ... =rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=rtcp:7077 IN IP4
192.168.1.4#015#012a=nortpproxy:yes#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=remote-candidates:1 192.168.1.1 7076 2 192.168.1.16
7077#015#012", "ICE": "force-relay", "replace": [
"origin",
"session-connection" ], "call-id": "6bRH2rngPS",
"received-from": [ "IP4",
"85.xx.xx.247" ], "fr ...
Oct 23 18:25:27 pbx rtpengine[4633]: ... om-tag": "x9WGjS4~9",
"to-tag":
"nfaREr4", "command": "offer" }
Oct 23 18:25:27 pbx rtpengine[4633]: [6bRH2rngPS] Returning to SIP proxy:
d3:sdp960:v=0#015#012o=1000 2963 762 IN IP4
85.xx.xx.247#015#012s=Talk#015#012c=IN IP4
85.xx.xx.247#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:da4ac4e59c3fbbde88b55a6d#015#012a=ice-ufrag:2a32181a#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000#015#012 ...
Oct 23 18:25:27 pbx rtpengine[4633]: [6bRH2rngPS] ... a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=rtcp:7077 IN IP4
192.168.1.4#015#012a=nortpproxy:yes#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=remote-candidates:1 192.168.1.1 7076 2 192.168.1.16
7077#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12268 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
16777214 79.xx.xx.153 12269 typ relay#015#0126:resu ...
Oct 23 18:25:27 pbx rtpengine[4633]: [6bRH2rngPS] ... lt2:oke
Oct 23 18:25:27 pbx rtpengine[4633]: Got valid command from 127.0.0.1:42531:
answer - { "sdp": "v=0#015#012o=1104 2835 2388 IN IP4
192.168.1.1#015#012s=Talk#015#012c=IN IP4
192.168.1.1#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:57046d3e78d22a34b13ce526#015#012a=ice-ufrag:5b4f3e35#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtp ...
Oct 23 18:25:27 pbx rtpengine[4633]: ... map:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=rtcp:7077 IN IP4
192.168.1.16#015#012a=nortpproxy:yes#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:3 1 UDP 1862270975
192.168.1.1 7076 typ prflx raddr 192.168.1.16 rport 7076#015#012", "ICE":
"force-relay", "replace": [ "origin",
"session-connection" ], "call-id":
"6bRH2rngPS", "received-from": [ "IP4",
"85.xx.xx.247" ], "from-tag":
"x9WGjS4~9", "to-tag": "nfaREr4", "command":
"answer" }
Oct 23 18:25:27 pbx rtpengine[4633]: [6bRH2rngPS] Returning to SIP proxy:
d3:sdp895:v=0#015#012o=1104 2835 2388 IN IP4
192.168.1.1#015#012s=Talk#015#012c=IN IP4
192.168.1.1#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:57046d3e78d22a34b13ce526#015#012a=ice-ufrag:5b4f3e35#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000#015#012a=fmt ...
Oct 23 18:25:27 pbx rtpengine[4633]: [6bRH2rngPS] ... p:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=rtcp:7077 IN IP4
192.168.1.16#015#012a=nortpproxy:yes#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:3 1 UDP 1862270975
192.168.1.1 7076 typ prflx raddr 192.168.1.16 rport
7076#015#012a=sendrecv#015#012a=candidate:GGlJTGIsZALVPUmm 1 UDP 16777215
79.xx.xx.153 12290 typ relay#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP
16777214 79.xx.xx.153 12291 typ relay#015#0126:result2:oke
Oct 23 18:26:23 pbx rtpengine[4633]: Got valid command from 127.0.0.1:58816:
delete - { "ICE": "force-relay", "call-id":
"6bRH2rngPS", "received-from":
[ "IP4", "85.xx.xx.247" ], "from-tag": "nfaREr4",
"command": "delete" }
Oct 23 18:26:23 pbx rtpengine[4633]: [6bRH2rngPS] Scheduling deletion of
call branch 'nfaREr4' in 30 seconds
Oct 23 18:26:23 pbx rtpengine[4633]: [6bRH2rngPS] Returning to SIP proxy:
d7:createdi1414088711e11:last
signali1414088727e4:tagsd7:nfaREr4d3:tag7:nfaREr47:createdi1414088711e16:in
dialogue
with9:x9WGjS4~96:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12268e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414088727e5:flagsl3:RTP6:fillede5:statsd7:packetsi22e5:bytesi2272e6:errorsi0eeed10:local
porti12269e8:endpo ...
Oct 23 18:26:23 pbx rtpengine[4633]: [6bRH2rngPS] ...
intd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414088727e5:flagsl4:RTCP6:filled10:kernelized17:no kernel
supporte5:statsd7:packetsi23e5:bytesi1664e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeee9:x9WGjS4~9d3:tag9:x9WGjS4~97:createdi1414088711e16:in
dialogue
with7:nfaREr46:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12290e8:endpointd6:family4:IPv47:addre ...
Oct 23 18:26:23 pbx rtpengine[4633]: [6bRH2rngPS] ...
ss14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414088727e5:flagsl3:RTP6:fillede5:statsd7:packetsi25e5:bytesi2628e6:errorsi0eeed10:local
porti12291e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414088726e5:flagsl4:RTCP6:filled10:kernelized17:no kernel
supporte5:statsd7:packetsi25e5:bytesi2208e6:errorsi0eeee5:flag ...
Oct 23 18:26:23 pbx rtpengine[4633]: [6bRH2rngPS] ...
sl11:initialized11:passthrough3:ICEeeeee6:totalsd3:RTPd7:packetsi47e5:bytesi4900e6:errorsi0ee4:RTCPd7:packetsi48e5:bytesi3872e6:errorsi0eee6:result2:oke
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] Closing call due to
timeout
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] Final packet stats:
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] --- Tag 'nfaREr4',
created 1:16 ago, in dialogue with 'x9WGjS4~9'
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] ------ Media #1, port
12268 <> 85.xx.xx.247:7076 , 22 p, 2272 b, 0 e
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] ------ Media #1, port
12269 <> 85.xx.xx.247:7077 (RTCP), 23 p, 1664 b, 0 e
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] --- Tag 'x9WGjS4~9',
created 1:16 ago, in dialogue with 'nfaREr4'
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] ------ Media #1, port
12290 <> 85.xx.xx.247:7076 , 25 p, 2628 b, 0 e
Oct 23 18:26:27 pbx rtpengine[4633]: [6bRH2rngPS] ------ Media #1, port
12291 <> 85.xx.xx.247:7077 (RTCP), 25 p, 2208 b, 0 e
And the logs for the successful calls:
rtpengine_manage("replace-origin replace-session-connection");
Oct 23 18:36:19 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35930:
offer - { "sdp": "v=0#015#012o=1000 2738 4037 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015 ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... #012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "JnnNxMkapj",
"received-from": [ "IP4",
"85. ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... 138.120.247" ], "from-tag":
"lL2Xy9ZAn", "command": "offer" }
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] Creating new call
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] Returning to SIP proxy:
d3:sdp1024:v=0#015#012o=1000 2738 4037 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12356 RTP/AVP
124 120 111 110 0 8 101#015#012c=IN IP4 79.xx.xx.153#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 sp ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ...
eex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=rtcp:12357#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12356 typ host#015#012a=candidate:GGlJTG ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ... IsZALVPUmm 2 UDP
2130706174 79.xx.xx.153 12357 typ host#015#0126:result2:oke
Oct 23 18:36:19 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35930:
offer - { "sdp": "v=0#015#012o=1000 2738 4037 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015 ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... #012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "JnnNxMkapj",
"received-from": [ "IP4",
"85. ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... 138.120.247" ], "from-tag":
"lL2Xy9ZAn", "command": "offer" }
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] Returning to SIP proxy:
d3:sdp1024:v=0#015#012o=1000 2738 4037 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12356 RTP/AVP
124 120 111 110 0 8 101#015#012c=IN IP4 79.xx.xx.153#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 sp ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ...
eex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=rtcp:12357#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12356 typ host#015#012a=candidate:GGlJTG ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ... IsZALVPUmm 2 UDP
2130706174 79.xx.xx.153 12357 typ host#015#0126:result2:oke
Oct 23 18:36:19 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35930:
offer - { "sdp": "v=0#015#012o=1000 2738 4037 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015 ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... #012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "JnnNxMkapj",
"received-from": [ "IP4",
"85. ...
Oct 23 18:36:19 pbx rtpengine[4633]: ... 138.120.247" ], "from-tag":
"lL2Xy9ZAn", "command": "offer" }
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] Returning to SIP proxy:
d3:sdp1024:v=0#015#012o=1000 2738 4037 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4ae5f0906c058b88649af65f#015#012a=ice-ufrag:bd451de7#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12356 RTP/AVP
124 120 111 110 0 8 101#015#012c=IN IP4 79.xx.xx.153#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 sp ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ...
eex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=rtcp:12357#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12356 typ host#015#012a=candidate:GGlJTG ...
Oct 23 18:36:19 pbx rtpengine[4633]: [JnnNxMkapj] ... IsZALVPUmm 2 UDP
2130706174 79.xx.xx.153 12357 typ host#015#0126:result2:oke
Oct 23 18:36:28 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35845:
answer - { "sdp": "v=0#015#012o=- 63734 35532 IN IP4
85.xx.xx.247#015#012s=zctlrun#015#012c=IN IP4 85.xx.xx.247#015#012t=0
0#015#012m=audio 33572 RTP/AVP 124 101#015#012a=rtpmap:101
TELEPHONE-EVENT/8000#015#012a=rtpmap:124 OPUS/48000/2#015#012a=fmtp:101
0-15#015#012a=fmtp:124
maxplaybackrate=16000;useinbandfec=1#015#012a=ice-ufrag:F4BB5A#015#012a=ice-pwd:B98DAF9CB90133B8671D3465AE88B9BD#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ==
1 UDP 2130706431 192.168.1.3 33572 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 1 UDP 169449 ...
Oct 23 18:36:28 pbx rtpengine[4633]: ... 8815 85.xx.xx.247 33572 typ srflx
raddr 192.168.1.3 rport 33572#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ== 2
UDP 2130706430 192.168.1.3 33573 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 2 UDP 1694498814
85.xx.xx.247 33573 typ srflx raddr 192.168.1.3 rport
33573#015#012a=ptime:20#015#012a=sendrecv#015#012", "replace": [
"origin",
"session-connection" ], "call-id": "JnnNxMkapj",
"received-from": [ "IP4",
"162.243.35.55" ], "from-tag": "lL2Xy9ZAn",
"to-tag":
"CAACC2884F8BF08C0E972BCFBCD89F09", "command": "answer"
...
Oct 23 18:36:28 pbx rtpengine[4633]: ... }
Oct 23 18:36:28 pbx rtpengine[4633]: [JnnNxMkapj] Returning to SIP proxy:
d3:sdp898:v=0#015#012o=- 63734 35532 IN IP4
79.xx.xx.153#015#012s=zctlrun#015#012c=IN IP4 79.xx.xx.153#015#012t=0
0#015#012m=audio 12376 RTP/AVP 124 101#015#012a=rtpmap:101
TELEPHONE-EVENT/8000#015#012a=rtpmap:124 OPUS/48000/2#015#012a=fmtp:101
0-15#015#012a=fmtp:124
maxplaybackrate=16000;useinbandfec=1#015#012a=ice-ufrag:F4BB5A#015#012a=ice-pwd:B98DAF9CB90133B8671D3465AE88B9BD#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ==
1 UDP 2130706431 192.168.1.3 33572 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 1 UDP 1694498815
85.xx.xx.247 33572 ...
Oct 23 18:36:28 pbx rtpengine[4633]: [JnnNxMkapj] ... typ srflx raddr
192.168.1.3 rport 33572#015#012a=candidate:z326/PkxOom7UM/yh6QLaQ== 2 UDP
2130706430 192.168.1.3 33573 typ
host#015#012a=candidate:9ZWlDYzRLqo8Q4979OwFlQ== 2 UDP 1694498814
85.xx.xx.247 33573 typ srflx raddr 192.168.1.3 rport
33573#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:12377#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12376 typ
host#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP 2130706174 79.xx.xx.153
12377 typ host#015#0126:result2:oke
Oct 23 18:36:32 pbx rtpengine[4633]: [JnnNxMkapj port 12376] Confirmed peer
address as 85.xx.xx.247:7076
Oct 23 18:36:32 pbx rtpengine[4633]: [JnnNxMkapj port 12356] Confirmed peer
address as 85.xx.xx.247:33572
Oct 23 18:36:32 pbx rtpengine[4633]: [JnnNxMkapj port 12356] Kernelizing
media stream
Oct 23 18:36:32 pbx rtpengine[4633]: [JnnNxMkapj port 12376] Kernelizing
media stream
Oct 23 18:36:32 pbx rtpengine[4633]: [JnnNxMkapj port 12357] Confirmed peer
address as 85.xx.xx.247:33573
Oct 23 18:36:33 pbx rtpengine[4633]: [JnnNxMkapj port 12377] Confirmed peer
address as 85.xx.xx.247:7077
Oct 23 18:36:49 pbx rtpengine[4633]: Got valid command from 127.0.0.1:46214:
delete - { "call-id": "JnnNxMkapj", "received-from": [
"IP4",
"85.xx.xx.247" ], "from-tag": "lL2Xy9ZAn",
"command": "delete" }
Oct 23 18:36:49 pbx rtpengine[4633]: [JnnNxMkapj] Scheduling deletion of
call branch 'lL2Xy9ZAn' in 30 seconds
Oct 23 18:36:49 pbx rtpengine[4633]: [JnnNxMkapj] Returning to SIP proxy:
d7:createdi1414089379e11:last
signali1414089388e4:tagsd9:lL2Xy9ZAnd3:tag9:lL2Xy9ZAn7:createdi1414089379e16:in
dialogue
with32:CAACC2884F8BF08C0E972BCFBCD89F096:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12376e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414089409e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi1015e
...
Oct 23 18:36:49 pbx rtpengine[4633]: [JnnNxMkapj] ...
5:bytesi133416e6:errorsi0eeed10:local
porti12377e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414089409e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no
kernel
supporte5:statsd7:packetsi7e5:bytesi916e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeee32:CAACC2884F8BF08C0E972BCFBCD89F09d3:tag32:CAACC2884F8BF08C0E972BCFBCD89F097:createdi1414089379e16:in
dialogue with9:lL2Xy9ZAn ...
Oct 23 18:36:49 pbx rtpengine[4633]: [JnnNxMkapj] ...
6:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12356e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti33572ee19:advertised
endpointd6:family4:IPv47:address13:162.243.35.554:porti33572ee11:last
packeti1414089409e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi1008e5:bytesi98393e6:errorsi0eeed10:local
porti12357e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti33573ee19:advertised
endpointd6:family4:IPv47:address13:162.243.35.554:port ...
Oct 23 18:36:49 pbx rtpengine[4633]: [JnnNxMkapj] ... i33573ee11:last
packeti1414089408e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no
kernel
supporte5:statsd7:packetsi10e5:bytesi1072e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeeee6:totalsd3:RTPd7:packetsi2023e5:bytesi231809e6:errorsi0ee4:RTCPd7:packetsi17e5:bytesi1988e6:errorsi0eee6:result2:oke
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] Call branch 'lL2Xy9ZAn'
deleted, no more branches remaining
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] Final packet stats:
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] --- Tag
'CAACC2884F8BF08C0E972BCFBCD89F09', created 1:00 ago, in dialogue with
'lL2Xy9ZAn'
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] ------ Media #1, port
12356 <> 85.xx.xx.247:33572, 1035 p, 101446 b, 0 e
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] ------ Media #1, port
12357 <> 85.xx.xx.247:33573 (RTCP), 10 p, 1072 b, 0 e
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] --- Tag 'lL2Xy9ZAn',
created 1:00 ago, in dialogue with 'CAACC2884F8BF08C0E972BCFBCD89F09'
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] ------ Media #1, port
12376 <> 85.xx.xx.247:7076 , 1031 p, 135562 b, 0 e
Oct 23 18:37:19 pbx rtpengine[4633]: [JnnNxMkapj] ------ Media #1, port
12377 <> 85.xx.xx.247:7077 (RTCP), 7 p, 916 b, 0 e
Oct 23 18:37:57 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35930:
offer - { "sdp": "v=0#015#012o=1000 997 1935 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4dcbb6c73e2764eb41a68c00#015#012a=ice-ufrag:b0b8eaf0#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012 ...
Oct 23 18:37:57 pbx rtpengine[4633]: ... a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport 7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "DZt4oR7o~2",
"received-from": [ "IP4",
"85.1 ...
Oct 23 18:37:57 pbx rtpengine[4633]: ... 38.120.247" ], "from-tag":
"yFZte-7q7", "command": "offer" }
Oct 23 18:37:57 pbx rtpengine[4633]: [DZt4oR7o~2] Creating new call
Oct 23 18:37:57 pbx rtpengine[4633]: [DZt4oR7o~2] Returning to SIP proxy:
d3:sdp1023:v=0#015#012o=1000 997 1935 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:4dcbb6c73e2764eb41a68c00#015#012a=ice-ufrag:b0b8eaf0#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12392 RTP/AVP
124 120 111 110 0 8 101#015#012c=IN IP4 79.xx.xx.153#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 spe ...
Oct 23 18:37:57 pbx rtpengine[4633]: [DZt4oR7o~2] ...
ex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.4 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 7076 typ srflx raddr 192.168.1.4 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 7077 typ srflx
raddr 192.168.1.4 rport
7077#015#012a=sendrecv#015#012a=rtcp:12393#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12392 typ host#015#012a=candidate:GGlJTGI ...
Oct 23 18:37:57 pbx rtpengine[4633]: [DZt4oR7o~2] ... sZALVPUmm 2 UDP
2130706174 79.xx.xx.153 12393 typ host#015#0126:result2:oke
Oct 23 18:38:00 pbx rtpengine[4633]: Got valid command from 127.0.0.1:42804:
answer - { "sdp": "v=0#015#012o=1104 3139 3667 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:ea415569407247b0fb0310ee#015#012a=ice-ufrag:d0a39941#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 1052 RTP/AVP 124
120 111 110 0 8 101#015#012c=IN IP4 85.xx.xx.247#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr= ...
Oct 23 18:38:00 pbx rtpengine[4633]: ... on#015#012a=rtpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 1052 typ srflx raddr 192.168.1.16 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 1053 typ srflx
raddr 192.168.1.16 rport 7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "DZt4oR7o~2",
"received-from": [ "IP4 ...
Oct 23 18:38:00 pbx rtpengine[4633]: ... ", "85.xx.xx.247" ],
"from-tag":
"yFZte-7q7", "to-tag": "U6V4a7v", "command":
"answer" }
Oct 23 18:38:00 pbx rtpengine[4633]: [DZt4oR7o~2] Returning to SIP proxy:
d3:sdp1028:v=0#015#012o=1104 3139 3667 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=ice-pwd:ea415569407247b0fb0310ee#015#012a=ice-ufrag:d0a39941#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12412 RTP/AVP
124 120 111 110 0 8 101#015#012c=IN IP4 79.xx.xx.153#015#012a=rtpmap:124
opus/48000/2#015#012a=fmtp:124 useinbandfec=1; stereo=0;
sprop-stereo=0#015#012a=rtpmap:120 SILK/16000#015#012a=rtpmap:111
speex/16000#015#012a=fmtp:111 vbr=on#015#012a=rtpmap:110 sp ...
Oct 23 18:38:00 pbx rtpengine[4633]: [DZt4oR7o~2] ...
eex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=candidate:1 1 UDP
2130706431 192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012a=candidate:2 1 UDP 1694498815
85.xx.xx.247 1052 typ srflx raddr 192.168.1.16 rport
7076#015#012a=candidate:2 2 UDP 1694498814 85.xx.xx.247 1053 typ srflx
raddr 192.168.1.16 rport
7077#015#012a=sendrecv#015#012a=rtcp:12413#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12412 typ host#015#012a=candidate:GG ...
Oct 23 18:38:00 pbx rtpengine[4633]: [DZt4oR7o~2] ... lJTGIsZALVPUmm 2 UDP
2130706174 79.xx.xx.153 12413 typ host#015#0126:result2:oke
Oct 23 18:38:03 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35930:
offer - { "sdp": "v=0#015#012o=1000 997 1936 IN IP4
192.168.1.4#015#012s=Talk#015#012c=IN IP4
192.168.1.4#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:4dcbb6c73e2764eb41a68c00#015#012a=ice-ufrag:b0b8eaf0#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpma ...
Oct 23 18:38:03 pbx rtpengine[4633]: ... p:110 speex/8000#015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431
192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4
7077 typ host#015#012a=remote-candidates:1 192.168.1.16 7076 2 192.168.1.16
7077#015#012", "replace": [ "origin",
"session-connection" ], "call-id":
"DZt4oR7o~2", "received-from": [ "IP4",
"85.xx.xx.247" ], "from-tag":
"yFZte-7q7", "to-tag": "U6V4a7v", "command":
"offer" }
Oct 23 18:38:03 pbx rtpengine[4633]: [DZt4oR7o~2] Returning to SIP proxy:
d3:sdp913:v=0#015#012o=1000 997 1936 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:4dcbb6c73e2764eb41a68c00#015#012a=ice-ufrag:b0b8eaf0#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12392 RTP/AVP
124 120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000#015 ...
Oct 23 18:38:03 pbx rtpengine[4633]: [DZt4oR7o~2] ... #012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431
192.168.1.4 7076 typ host#015#012a=candidate:1 2 UDP 2130706430 192.168.1.4
7077 typ host#015#012a=remote-candidates:1 192.168.1.16 7076 2 192.168.1.16
7077#015#012a=sendrecv#015#012a=rtcp:12393#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12392 typ
host#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP 2130706174 79.xx.xx.153
12393 typ host#015#0126:result2:oke
Oct 23 18:38:04 pbx rtpengine[4633]: Got valid command from 127.0.0.1:42804:
answer - { "sdp": "v=0#015#012o=1104 3139 3669 IN IP4
192.168.1.16#015#012s=Talk#015#012c=IN IP4
192.168.1.16#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:ea415569407247b0fb0310ee#015#012a=ice-ufrag:d0a39941#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 7076 RTP/AVP 124
120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=r ...
Oct 23 18:38:04 pbx rtpengine[4633]: ... tpmap:110
speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431
192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ host#015#012", "replace": [ "origin",
"session-connection" ], "call-id": "DZt4oR7o~2",
"received-from": [ "IP4",
"85.xx.xx.247" ], "from-tag": "yFZte-7q7",
"to-tag": "U6V4a7v", "command":
"answer" }
Oct 23 18:38:04 pbx rtpengine[4633]: [DZt4oR7o~2] Returning to SIP proxy:
d3:sdp855:v=0#015#012o=1104 3139 3669 IN IP4
79.xx.xx.153#015#012s=Talk#015#012c=IN IP4
79.xx.xx.153#015#012b=AS:1024#015#012t=0
0#015#012a=nortpproxy:yes#015#012a=ice-pwd:ea415569407247b0fb0310ee#015#012a=ice-ufrag:d0a39941#015#012a=rtcp-xr:rcvr-rtt=all:10000
stat-summary=loss,dup,jitt,TTL voip-metrics#015#012m=audio 12422 RTP/AVP
124 120 111 110 0 8 101#015#012a=rtpmap:124 opus/48000/2#015#012a=fmtp:124
useinbandfec=1; stereo=0; sprop-stereo=0#015#012a=rtpmap:120
SILK/16000#015#012a=rtpmap:111 speex/16000#015#012a=fmtp:111
vbr=on#015#012a=rtpmap:110 speex/8000 ...
Oct 23 18:38:04 pbx rtpengine[4633]: [DZt4oR7o~2] ... #015#012a=fmtp:110
vbr=on#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
0-15#015#012a=nortpproxy:yes#015#012a=candidate:1 1 UDP 2130706431
192.168.1.16 7076 typ host#015#012a=candidate:1 2 UDP 2130706430
192.168.1.16 7077 typ
host#015#012a=sendrecv#015#012a=rtcp:12423#015#012a=candidate:GGlJTGIsZALVPUmm
1 UDP 2130706175 79.xx.xx.153 12422 typ
host#015#012a=candidate:GGlJTGIsZALVPUmm 2 UDP 2130706174 79.xx.xx.153
12423 typ host#015#0126:result2:oke
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12422] Confirmed peer
address as 85.xx.xx.247:7076
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12392] Confirmed peer
address as 85.xx.xx.247:7076
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12392] Kernelizing
media stream
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12422] Kernelizing
media stream
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12423] Confirmed peer
address as 85.xx.xx.247:7077
Oct 23 18:38:08 pbx rtpengine[4633]: [DZt4oR7o~2 port 12393] Confirmed peer
address as 85.xx.xx.247:7077
Oct 23 18:38:20 pbx rtpengine[4633]: Got valid command from 127.0.0.1:35845:
delete - { "call-id": "DZt4oR7o~2", "received-from": [
"IP4",
"85.xx.xx.247" ], "from-tag": "U6V4a7v",
"command": "delete" }
Oct 23 18:38:20 pbx rtpengine[4633]: [DZt4oR7o~2] Scheduling deletion of
call branch 'U6V4a7v' in 30 seconds
Oct 23 18:38:20 pbx rtpengine[4633]: [DZt4oR7o~2] Returning to SIP proxy:
d7:createdi1414089477e11:last
signali1414089484e4:tagsd7:U6V4a7vd3:tag7:U6V4a7v7:createdi1414089477e16:in
dialogue
with9:yFZte-7q76:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti12392e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414089500e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi877e5:bytesi110156e6:errorsi0eeed
...
Oct 23 18:38:20 pbx rtpengine[4633]: [DZt4oR7o~2] ... 10:local
porti12393e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414089497e5:flagsl4:RTCP6:filled9:confirmed10:kernelized17:no
kernel
supporte5:statsd7:packetsi8e5:bytesi1500e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeee9:yFZte-7q7d3:tag9:yFZte-7q77:createdi1414089477e16:in
dialogue
with7:U6V4a7v6:mediasld5:indexi1e4:type5:audio8:protocol7:RTP/AVP7:streamsld10:local
porti1 ...
Oct 23 18:38:20 pbx rtpengine[4633]: [DZt4oR7o~2] ...
2422e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7076ee11:last
packeti1414089500e5:flagsl3:RTP6:filled9:confirmed10:kernelizede5:statsd7:packetsi970e5:bytesi121770e6:errorsi0eeed10:local
porti12423e8:endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee19:advertised
endpointd6:family4:IPv47:address14:85.xx.xx.2474:porti7077ee11:last
packeti1414089500e5:flagsl4:RTCP6:filled9:confirmed10:kernelized ...
Oct 23 18:38:20 pbx rtpengine[4633]: [DZt4oR7o~2] ... 17:no kernel
supporte5:statsd7:packetsi12e5:bytesi1936e6:errorsi0eeee5:flagsl11:initialized11:passthrough3:ICEeeeee6:totalsd3:RTPd7:packetsi1847e5:bytesi231926e6:errorsi0ee4:RTCPd7:packetsi20e5:bytesi3436e6:errorsi0eee6:result2:oke
On Thu, Oct 23, 2014 at 7:14 PM, Richard Fuchs <rfuchs(a)sipwise.com> wrote:
On 10/23/14 13:44, Peter Villeneuve wrote:
Thanks again for your help Richard.
Here's the complete log from a call from 1000 to 1104. This time both
are linphone Android UACs sitting behind the same NAT router.
Sorry about the length but it's probably best if you can see the whole
logs. I have xxed out the public IPs to protect the innocent.
You'll also notice I have tried adding ICE=force-relay and indeed it
seems to be creating the proper relay candidates.
I don't really see anything wrong with this call and it doesn't seem to
exhibit the issues you've mentioned, as there are no error messages or
anything else strange. Both clients are ICE and you're using
ICE=force-relay, so I'm guessing that the clients have established
communications outside of rtpengine's path, which is why it closes the
call with a timeout (no packets received).
cheers
_______________________________________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
3713
days inactive
3714
days old
6 comments
2 participants
participants (2)
-
Peter Villeneuve -
Richard Fuchs