[sr-dev] STUN FINGERPRINT attribute missing?

Peter Villeneuve petervnv1 at gmail.com
Thu Oct 23 19:44:37 CEST 2014 

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 at 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 at lists.sip-router.org
> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20141023/1ca2e0ef/attachment-0001.html>

More information about the sr-dev mailing list