[pjsip] All audio is lost after exactly 5 minutes

selak Dev selakdev at gmail.com
Wed Apr 4 04:16:27 EDT 2018


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 at 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 at 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 at lists.pjsip.org
>> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>>
>>
>
> _______________________________________________
> Visit our blog: http://blog.pjsip.org
>
> pjsip mailing list
> pjsip at lists.pjsip.org
> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20180404/c383597c/attachment.html>


More information about the pjsip mailing list