Hi all,
The call looses all audio after exactly 5 minutes. I tracked down the
issue, and saw that
TURN server(we use Coturn implementation of STUN/TURN to enable ICE) has a
timer for 300s after which if peer does not
update allocation(create permission) for specific ip/port, will discard all
incoming packets, which is exactly what is happening to us.
Peers just cant hear each other, while signalling is working ok(we can hold
or disconnect at any time and it will work).
I believe this is happening only if RTCP is enabled(in order to have two
components in sdp). From what I can see in the logs, valid list of the
ip/port combination after
ice negotiation is not the same as the one that is updating permissions on
TURN server. CreatePermission STUN message is also not called after 5
minutes and for all ip/address combination.
If createPermission is not called, permissions are not refreshed and media
will be discarded.
Have anybody encountered this bug before? Do you maybe know some workaround
for this that we can use?
Below you can find logs excerpts:
MO = Mobile Originator(Caller), MT = Mobile Terminator(Callee)
As you can see createPermission is called only once on MO(when starting a
call), and twice on MT(when starting and after almost 5 minutes).
Can we manually invoke this somehow? We are having this problem mainly on
Android platform.
Logs:
MO Invite SDP
a=candidate:Sc0a80178 1 UDP 1694498815 xxx.24.19.70 60486 typ srflx raddr
192.168.1.120 rport 60486
a=candidate:Hc0a80178 1 UDP 2130706431 192.168.1.120 60486 typ host
a=candidate:Rc63a711d 1 UDP 16777215 yyy.58.113.29 59665 typ relay raddr
xxx.24.19.70 rport 41286
a=candidate:Sc0a80178 2 UDP 1694498814 xxx.24.19.70 60278 typ srflx raddr
192.168.1.120 rport 60278
a=candidate:Hc0a80178 2 UDP 2130706430 192.168.1.120 60278 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
MT INVITE SDP
a=candidate:Sa3da20f 1 UDP 1694498815 109.245.36.15 41219 typ srflx raddr
10.61.162.15 rport 41219
a=candidate:Ha3da20f 1 UDP 2130706431 10.61.162.15 41219 typ host
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
a=candidate:Ha3da20f 2 UDP 2130706430 10.61.162.15 46089 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 56595 typ relay raddr
109.245.36.15 rport 47560
MO UPDATE MESSAGE SDP
a=candidate:Pc0a80178 1 UDP 1862270975 xxx.24.19.70 8666 typ prflx raddr
192.168.1.120 rport 60486
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
a=remote-candidates:1 zzz.239.27.222 52165 2 109.245.36.15 46089
MT UPDATE MESSAGE SDP
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
MO Valid list after ice negoatiation
14:29:27.546 icetp00 .Valid list
14:29:27.546 icetp00 . 0: [1]
xxx.24.19.70:8666-->zzz.239.27.222:52165 (nominated, state=Succeeded)
14:29:27.546 icetp00 . 1: [2] yyy.58.113.29:50582-->
109.245.36.15:46089 (nominated, state=Succeeded)
MT Valid list after ice negoatiation
14:29:27.169 icetp00 ...Valid list
14:29:27.169 icetp00 ... 0: [1]
zzz.239.27.222:52165-->yyy.58.113.29:59665 (nominated, state=Succeeded)
14:29:27.169 icetp00 ... 1: [2]
109.245.36.15:46089-->yyy.58.113.29:50582
(nominated, state=Succeeded)
Creating permissions:
MO
createPermission
14:29:26.989
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d21223877f610cb1e9b
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=zzz.239.27.222:52165
...
14:29:26.989 udprel0xb8da08 .......TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d213ea1a9a710cb1e9c
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:56595
....
MT
createPermission
14:29:26.259 udprel0xc49938 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f693cab06d3078af769
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
14:29:26.259 udprel0xc42064 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f690accf29f078af76a
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:50582
....
14:34:10.078 udprel0xc49938 .TX 128 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=108, magic=2112a442, tsx_id=00007f6921c61c94078af793
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
Best regards,
Marko Selakovic
Hi Marko,
PJSIP uses ChannelBind to refresh the permission. Check your log if it's
sent. The code that invokes this is here:
https://trac.pjsip.org/repos/browser/pjproject/trunk/pjnath/src/pjnath/turn_session.c#L2038
And this is according to the RFC (
https://tools.ietf.org/html/rfc5766#section-2.3)
"The client can install or refresh a permission using either a
CreatePermission request or a ChannelBind request."
Regards,
Ming
On Tue, Apr 3, 2018 at 10:55 PM, selak Dev selakdev@gmail.com wrote:
Hi all,
The call looses all audio after exactly 5 minutes. I tracked down the
issue, and saw that
TURN server(we use Coturn implementation of STUN/TURN to enable ICE) has a
timer for 300s after which if peer does not
update allocation(create permission) for specific ip/port, will discard
all incoming packets, which is exactly what is happening to us.
Peers just cant hear each other, while signalling is working ok(we can
hold or disconnect at any time and it will work).
I believe this is happening only if RTCP is enabled(in order to have two
components in sdp). From what I can see in the logs, valid list of the
ip/port combination after
ice negotiation is not the same as the one that is updating permissions on
TURN server. CreatePermission STUN message is also not called after 5
minutes and for all ip/address combination.
If createPermission is not called, permissions are not refreshed and media
will be discarded.
Have anybody encountered this bug before? Do you maybe know some
workaround for this that we can use?
Below you can find logs excerpts:
MO = Mobile Originator(Caller), MT = Mobile Terminator(Callee)
As you can see createPermission is called only once on MO(when starting a
call), and twice on MT(when starting and after almost 5 minutes).
Can we manually invoke this somehow? We are having this problem mainly on
Android platform.
Logs:
MO Invite SDP
a=candidate:Sc0a80178 1 UDP 1694498815 xxx.24.19.70 60486 typ srflx raddr
192.168.1.120 rport 60486
a=candidate:Hc0a80178 1 UDP 2130706431 192.168.1.120 60486 typ host
a=candidate:Rc63a711d 1 UDP 16777215 yyy.58.113.29 59665 typ relay raddr
xxx.24.19.70 rport 41286
a=candidate:Sc0a80178 2 UDP 1694498814 xxx.24.19.70 60278 typ srflx raddr
192.168.1.120 rport 60278
a=candidate:Hc0a80178 2 UDP 2130706430 192.168.1.120 60278 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
MT INVITE SDP
a=candidate:Sa3da20f 1 UDP 1694498815 109.245.36.15 41219 typ srflx raddr
10.61.162.15 rport 41219
a=candidate:Ha3da20f 1 UDP 2130706431 10.61.162.15 41219 typ host
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
a=candidate:Ha3da20f 2 UDP 2130706430 10.61.162.15 46089 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 56595 typ relay raddr
109.245.36.15 rport 47560
MO UPDATE MESSAGE SDP
a=candidate:Pc0a80178 1 UDP 1862270975 xxx.24.19.70 8666 typ prflx raddr
192.168.1.120 rport 60486
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
a=remote-candidates:1 zzz.239.27.222 52165 2 109.245.36.15 46089
MT UPDATE MESSAGE SDP
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
MO Valid list after ice negoatiation
14:29:27.546 icetp00 .Valid list
14:29:27.546 icetp00 . 0: [1] xxx.24.19.70:8666-->zzz.239.27.222:52165
(nominated, state=Succeeded)
14:29:27.546 icetp00 . 1: [2] yyy.58.113.29:50582-->109.245.
36.15:46089 (nominated, state=Succeeded)
MT Valid list after ice negoatiation
14:29:27.169 icetp00 ...Valid list
14:29:27.169 icetp00 ... 0: [1] zzz.239.27.222:52165-->yyy.58.113.29:59665
(nominated, state=Succeeded)
14:29:27.169 icetp00 ... 1: [2] 109.245.36.15:46089-->yyy.58.113.29:50582
(nominated, state=Succeeded)
Creating permissions:
MO
createPermission
14:29:26.989
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d21223877f610cb1e9b
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=zzz.239.27.222:52165
...
14:29:26.989 udprel0xb8da08 .......TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d213ea1a9a710cb1e9c
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:56595
....
MT
createPermission
14:29:26.259 udprel0xc49938 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f693cab06d3078af769
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
14:29:26.259 udprel0xc42064 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f690accf29f078af76a
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:50582
....
14:34:10.078 udprel0xc49938 .TX 128 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=108, magic=2112a442, tsx_id=00007f6921c61c94078af793
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
Best regards,
Marko Selakovic
Visit our blog: http://blog.pjsip.org
pjsip mailing list
pjsip@lists.pjsip.org
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
Hi,
I did look at the ChannelBind Request, and it is sent, but not for good
addresses.
As you can see in the logs below, it is updating only one address(it should
update two for both rtp/rtcp) from each peer.
Also address 109.245.36.15:46089 is ip address of my 3G mobile data, so I
believe it should not update that address.
What I believe is happening is that permissions are created once in
CreatePermission request(each request has 3 addresses) at the beginning of
the call and this channelBind request does not do its job well, and we
loose the audio.
I will of course take a look at the method you supplied, to see if I can
fix it myself, but any more insights or help is welcomed.
Logs:
ChannelBind Request MO
14:29:27.547 udprel0xb8da08 .TX 136 bytes STUN message to xxxx:3478:
--- begin STUN message ---
STUN ChannelBind request
Hdr: length=116, magic=2112a442, tsx_id=00007d210ce07b9910cb1ea9
Attributes:
CHANNEL-NUMBER: length=4, chnum=16384 (0x4000)
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:46089
SOFTWARE: length=16, value="pjnath-2.7.1-svn"
.....
14:34:23.949 udprel0xb8da08 .TX 136 bytes STUN message to xxxx:3478:
--- begin STUN message ---
STUN ChannelBind request
Hdr: length=116, magic=2112a442, tsx_id=00007d215234e77c10cb1ec4
Attributes:
CHANNEL-NUMBER: length=4, chnum=16384 (0x4000)
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:46089
SOFTWARE: length=16, value="pjnath-2.7.1-svn"
....
ChannelBind Request MT
14:29:27.169 udprel0xc49938 .TX 136 bytes STUN message to xxxx:3478:
--- begin STUN message ---
STUN ChannelBind request
Hdr: length=116, magic=2112a442, tsx_id=00007f697220f820078af778
Attributes:
CHANNEL-NUMBER: length=4, chnum=16384 (0x4000)
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
SOFTWARE: length=16, value="pjnath-2.7.1-svn"
.....
14:34:25.078 udprel0xc49938 .TX 136 bytes STUN message to xxxx:3478:
--- begin STUN message ---
STUN ChannelBind request
Hdr: length=116, magic=2112a442, tsx_id=00007f6911381a2f078af796
Attributes:
CHANNEL-NUMBER: length=4, chnum=16384 (0x4000)
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
.....
BR,
Marko
On Wed, Apr 4, 2018 at 2:22 AM, Ming ming@teluu.com wrote:
Hi Marko,
PJSIP uses ChannelBind to refresh the permission. Check your log if it's
sent. The code that invokes this is here:
https://trac.pjsip.org/repos/browser/pjproject/trunk/
pjnath/src/pjnath/turn_session.c#L2038
And this is according to the RFC (https://tools.ietf.org/html/
rfc5766#section-2.3)
"The client can install or refresh a permission using either a
CreatePermission request or a ChannelBind request."
Regards,
Ming
On Tue, Apr 3, 2018 at 10:55 PM, selak Dev selakdev@gmail.com wrote:
Hi all,
The call looses all audio after exactly 5 minutes. I tracked down the
issue, and saw that
TURN server(we use Coturn implementation of STUN/TURN to enable ICE) has
a timer for 300s after which if peer does not
update allocation(create permission) for specific ip/port, will discard
all incoming packets, which is exactly what is happening to us.
Peers just cant hear each other, while signalling is working ok(we can
hold or disconnect at any time and it will work).
I believe this is happening only if RTCP is enabled(in order to have two
components in sdp). From what I can see in the logs, valid list of the
ip/port combination after
ice negotiation is not the same as the one that is updating permissions
on TURN server. CreatePermission STUN message is also not called after 5
minutes and for all ip/address combination.
If createPermission is not called, permissions are not refreshed and
media will be discarded.
Have anybody encountered this bug before? Do you maybe know some
workaround for this that we can use?
Below you can find logs excerpts:
MO = Mobile Originator(Caller), MT = Mobile Terminator(Callee)
As you can see createPermission is called only once on MO(when starting a
call), and twice on MT(when starting and after almost 5 minutes).
Can we manually invoke this somehow? We are having this problem mainly on
Android platform.
Logs:
MO Invite SDP
a=candidate:Sc0a80178 1 UDP 1694498815 xxx.24.19.70 60486 typ srflx raddr
192.168.1.120 rport 60486
a=candidate:Hc0a80178 1 UDP 2130706431 192.168.1.120 60486 typ host
a=candidate:Rc63a711d 1 UDP 16777215 yyy.58.113.29 59665 typ relay raddr
xxx.24.19.70 rport 41286
a=candidate:Sc0a80178 2 UDP 1694498814 xxx.24.19.70 60278 typ srflx raddr
192.168.1.120 rport 60278
a=candidate:Hc0a80178 2 UDP 2130706430 192.168.1.120 60278 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
MT INVITE SDP
a=candidate:Sa3da20f 1 UDP 1694498815 109.245.36.15 41219 typ srflx raddr
10.61.162.15 rport 41219
a=candidate:Ha3da20f 1 UDP 2130706431 10.61.162.15 41219 typ host
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
a=candidate:Ha3da20f 2 UDP 2130706430 10.61.162.15 46089 typ host
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 56595 typ relay raddr
109.245.36.15 rport 47560
MO UPDATE MESSAGE SDP
a=candidate:Pc0a80178 1 UDP 1862270975 xxx.24.19.70 8666 typ prflx raddr
192.168.1.120 rport 60486
a=candidate:Rc63a711d 2 UDP 16777214 yyy.58.113.29 50582 typ relay raddr
xxx.24.19.70 rport 35285
a=remote-candidates:1 zzz.239.27.222 52165 2 109.245.36.15 46089
MT UPDATE MESSAGE SDP
a=candidate:R17ef1bde 1 UDP 16777215 zzz.239.27.222 52165 typ relay raddr
109.245.36.15 rport 40443
a=candidate:Sa3da20f 2 UDP 1694498814 109.245.36.15 46089 typ srflx raddr
10.61.162.15 rport 46089
MO Valid list after ice negoatiation
14:29:27.546 icetp00 .Valid list
14:29:27.546 icetp00 . 0: [1] xxx.24.19.70:8666-->zzz.239.27.222:52165
(nominated, state=Succeeded)
14:29:27.546 icetp00 . 1: [2] yyy.58.113.29:50582-->109.245.
36.15:46089 (nominated, state=Succeeded)
MT Valid list after ice negoatiation
14:29:27.169 icetp00 ...Valid list
14:29:27.169 icetp00 ... 0: [1] zzz.239.27.222:52165-->yyy.58.113.29:59665
(nominated, state=Succeeded)
14:29:27.169 icetp00 ... 1: [2] 109.245.36.15:46089-->yyy.58.113.29:50582
(nominated, state=Succeeded)
Creating permissions:
MO
createPermission
14:29:26.989
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d21223877f610cb1e9b
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:41219
XOR-PEER-ADDRESS: length=8, IPv4 addr=zzz.239.27.222:52165
...
14:29:26.989 udprel0xb8da08 .......TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007d213ea1a9a710cb1e9c
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=109.245.36.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=10.61.162.15:46089
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:56595
....
MT
createPermission
14:29:26.259 udprel0xc49938 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f693cab06d3078af769
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60486
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
14:29:26.259 udprel0xc42064 .....TX 152 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=132, magic=2112a442, tsx_id=00007f690accf29f078af76a
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=xxx.24.19.70:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=192.168.1.120:60278
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:50582
....
14:34:10.078 udprel0xc49938 .TX 128 bytes STUN message to xxxx:3478
--- begin STUN message ---
STUN CreatePermission request
Hdr: length=108, magic=2112a442, tsx_id=00007f6921c61c94078af793
Attributes:
XOR-PEER-ADDRESS: length=8, IPv4 addr=yyy.58.113.29:59665
....
Best regards,
Marko Selakovic
Visit our blog: http://blog.pjsip.org
pjsip mailing list
pjsip@lists.pjsip.org
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
Visit our blog: http://blog.pjsip.org
pjsip mailing list
pjsip@lists.pjsip.org
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org