Re: All audio is lost after exactly 5 minutes

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

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@xxxxxxxxx> wrote:
Hi Marko,

PJSIP uses ChannelBind to refresh the permission. Check your log if it's sent. The code that invokes this is here:

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@xxxxxxxxx> 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@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org



_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org


_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
[Index of Archives]     [Asterisk Users]     [Asterisk App Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [Linux API]
  Powered by Linux