per account configuration problems (ICE and STUN)

[Privus 007]

Hi,

I'm trying to set up 2 accounts (Account A uses ICE, Account B uses only STUN - no ICE), but I can't seem to get it working proeprly.

Basically, I have Account A with the following attributes in the wizard I'm experimenting with:

prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_ICE, false);

and also

account.ice_cfg_enable = 0;

account.ice_cfg_use = 0;

This seems to work OK.

However, I also have the following for Account B:

prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_ICE, true);

and also

account.ice_cfg_enable = 1;

account.ice_cfg_use = 1;

The problem seems to be that once I activate both accounts, the global setting SipConfigManager.ENABLE_ICE, true seems to override the Account A settings and it ends up using ICE anyway.

What am I doing wrong here? Is it possible to have ICE enabled only for Account B and disabled (only have STUN enabled) for Account A? In other words, shouldn't the account settings account.ice_cfg_enable = 0; and account.ice_cfg_use = 0; from wizard A disable ICE for that account? I can see in the call info window that it is negotiating ICE anyway, despite the 0s....

Thanks

[Régis Montoya]

Global setting is by definition global.

So it's expected that a save in the account B overrides the global setting.

Basically, in your case you want ICE to be enabled globally and disabled at account level.

That's what you rightly tried to do with

account.ice_cfg_enable = 0;

account.ice_cfg_use = 0;

Except that you misunderstood (due to bad doc, my bad) the "ice_cfg_use" option.

This option, is the csipsimple version of the ice_cfg_use option of pjsip that you'll find detailed here :
http://www.pjsip.org/pjsip/docs/html/structpjsua__acc__config.htm#adbe93873bd4a4f1b456d83f9019d03cf

If you want to override the ice setting, you must pass the value PJSUA_ICE_CONFIG_USE_CUSTOM, in other worlds... 1 !
So you must pass for account A :

account.ice_cfg_use = 1; // This means we want to override default ICE setting for this account.

account.ice_cfg_enable = 0; // This means we want to disable ICE for this account.

It goes the same for account B : you can force override of ice_cfg_use by using 1 and force ice usage by using 1.

If you pass 0 for ice_cfg_use, whatever the param you set in ice_cfg_enable, what will be taken into account is the global setting. This global setting is by definition global and applies to all accounts.

BTW, it's advised to force ice setting at account level only if you think/know the sip server will *never* work with ice enabled and that you don't want some global app setting choosen by user lead if ICE is enabled or not.

2013/11/17 Privus 007 <priv...@gmail.com>

--
You received this message because you are subscribed to the Google Groups "CSipSimple Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to csipsimple-de...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Priv]

OK, I've been playing around with this a bit and I have some questions since I'm getting buggy ICE behaviour between 2 CS clients configured exactly the same and using a Freeswitch server as PBX (sometimes it connects OK, other times with 1 way audio, other times I can't answer incoming call at all, others DTMF doesn't work...)

I've decided to enable DNS_SRV, ICE, STUN and STUN2 globally like so:

                prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_STUN, true);

       prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_STUN2, true);

       prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_DNS_SRV, true);

       prefs.setPreferenceBooleanValue(SipConfigManager.ENABLE_ICE, true);

1) My first question is, is it OK to enable both STUN and STUN2 at the same time? The reason I ask is that originally I had only enabled STUN2 but then CS kept bugging me with the triangle reminder about STUN and 1 way audio, which leads me to believe it wasn't accepting STUN2 as STUN, no?

2) For default ICE in the account, do I have to put in the wizard account.ice_cfg_enable = 1; and account.ice_cfg_use = 1? Same question regarding account.sip_stun_use = 1; and account.media_stun_use = 1? For an account with default settings do I enable these in the wizard or just omit them and leave the global settings above? I'm assuming 0=disable and 1=enable. I think I maybe over complicating something simple which should just work 99% of the time out of the box.

3) I see in the logs that sometimes I get "Error sending RTP: ICE check is in progress". The call shows as answered but obviously there's no audio flowing through. Is this expected behaviour? Shouldn't RTP only begin after ICE has completed negotiation? Other times I see ICE negotiation never completes and I get NAT type as Error Unknown.

4) Finally, after reading up some more on PJNATH, I see there's both an ICE stream transport and ICE session. Which is CS using with the ENABLE_ICE global config? Perhaps my problem lies here as the FS server expects audio in iCE transport and CS sends it in UDP? Or maybe I'm just confused...

5) Lastly, is it possible to enable different codecs and priorities per account instead of globally? If so, how?

Thanks

[Régis Montoya]

1) My first question is, is it OK to enable both STUN and STUN2 at the same time? The reason I ask is that originally I had only enabled STUN2 but then CS kept bugging me with the triangle reminder about STUN and 1 way audio, which leads me to believe it wasn't accepting STUN2 as STUN, no?

The warning has mainly an indicative purpose for mainstream users. STUN2 option was added recently to give the newly introduced feature of pjsip, but I didn't tested it yet. From the reading of pjsua docs about stun2 option it requires stun to be enabled so that iit has an effect but I could be wrong.
For reference the pjsua doc : http://www.pjsip.org/docs/latest/pjsip/docs/html/structpjsua__config.htm#a30cfc7222e18f7b670dbc1ec27da92cc

 

2) For default ICE in the account, do I have to put in the wizard account.ice_cfg_enable = 1; and account.ice_cfg_use = 1? Same question regarding account.sip_stun_use = 1; and account.media_stun_use = 1? For an account with default settings do I enable these in the wizard or just omit them and leave the global settings above? I'm assuming 0=disable and 1=enable.

Yes. It's also something that comes direclty from pjsip. Maybe having a look to pjsua docs might enlight things. When it comes to very expert settings, I try to keep same logic than pjsua so that their docs applies.

The logic they have here is that the "***_use" = 0 => means keep global settings and "***_use" = 1 => use settings specified at account level.

I would advise to set/force things at account level as soon as you don't think user should modify it.

If you think users should/could take a decision on that, you can set the global setting in wizard and leave your account use the global setting. This way, if user decide to change the setting, it will also apply to your account.

 

I think I maybe over complicating something simple which should just work 99% of the time out of the box.

3) I see in the logs that sometimes I get "Error sending RTP: ICE check is in progress". The call shows as answered but obviously there's no audio flowing through. Is this expected behaviour? Shouldn't RTP only begin after ICE has completed negotiation? Other times I see ICE negotiation never completes and I get NAT type as Error Unknown.

I'm not 100% expert in ICE, but here's what I understood so far :

ICE negotiation is about announcing several candidates (that you can see in SDP). The media stack will try to reach candidates proposed by the remote. The remote should reply to the binding. If no reply made from other side, it means the path is invalid and it's time for the media stack to try another candidate.

So, if you get this kind of error message (which I never had), I suspect the ice negociation is still ongoing (and the media stack, as you noticed, will not send RTP packet it would like to send). RTP flow could always start from very beggining (as you produce something on micro); but it has to wait for ICE neg to be completed. So, I think it's expected some RTP packet gets dropped until ice neg is completed and the logs you get appears.

 

4) Finally, after reading up some more on PJNATH, I see there's both an ICE stream transport and ICE session. Which is CS using with the ENABLE_ICE global config? Perhaps my problem lies here as the FS server expects audio in iCE transport and CS sends it in UDP? Or maybe I'm just confused...

CSipSimple uses the pjsua api.
http://www.pjsip.org/docs/latest/pjsip/docs/html/structpjsua__media__config.htm#a8c3030ecc6b84a888f49f6b3e1b204a9

pjnath is lower level api (which pjsua uses).

So, when ice is enabled it's the RFC ice media transport that is used and announced in SDP (session). (So it uses both session and media stream transport).

ICE is always transported over the same thing that RTP. This is because its purpose is to open the way to RTP packets. So there is only one place where FS should expect ICE and only one place where pjsua should send it. And it's RTP(UDP).
The only breaking thing to RFC that could happen is an endpoint using google-ice non-standard approach. It's something that was implemented in early webrtc and was very similar to ICE except authentication and call flow. But only chrome and things using libjingle produces that. If you have a csipsimple and/or FS on both side, should not happen.

The best thing to do, when comes to debug audio, is to have a very close look to SDP. Everything is contained in it. Check that it's what you expect regarding your topology. Check that ip address you'd like the media to use is announced by each side in their ICE candidates in the SDP. If ICE candidates are good for the network conditions, you should have audio. I suspect that when things fails either network conditions are different or ice detected candidates are different.

 

5) Lastly, is it possible to enable different codecs and priorities per account instead of globally? If so, how?

Currently no.

However, pjsua is designed to allow that. There is a doc somewhere on their website (sorry I don't remember where exactly) that explains how to do that using the callbacks.

If I correctly remember it was not obvious to implement and involved sdp rewriting. And I was also pretty discouraged by the fact the user interface inside the app would be also very complicated for mainstream users (understanding what is the purpose of a codec is already a big step) and also error prone (users could think changing the order of codecs globally while codec list at account level would be overridden).

If you find an elegant way to implement and present to user, it's a contribution that would be very welcome :)

[Priv]

Hi Reǵis,

Thanks for your help.

Indeed I have been exploring the documentation more thoroughly and I managed to configure the accounts according to your instructions.

And it seems I have discovered a bug in the ICE implementation in the process which would explain the strange behaviour I'm seeing.

I couldn't figure out why sometimes I couldn't answer calls (pushing the green answer slider has no effect and the call keeps ringing), and a few seconds later the same call worked without problems even though nothing changed.

This was baffling me until I looked more closely at the logs. I also found out that if I disable STUN completely, ICE negotiation works very well. The problem with this approach is that it only works when both clients are on the same NATed network since their public IPs never get sent as ice candidates. Obviously that is not a real solution but it does help to point the finger at STUN and ICE not playing well in PJSIP.

Here's an excerpt below of the logs for 2 different calls (changed the public IPs to protect the innocent):

Notice how we get the error message "ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED)" even though ICE connectivity check actually was OK "Check 1: [1] 192.168.1.11:4027-->92.xx.xx.29:4013 (nominated): connectivity check SUCCESS)"?

Indeed calling between 2 CSip clients with the same app version and configuration (one of the latest nightlies) shows different results in their logs. One shows ICE negotiation success, while the other shows Failure or negotiation in progress even though there's audio flowing between the 2.

This suggests to me a bug with ICE/STUN implementation, no?

Do you have any ideas as to the origin of this issue and what to do to fix it ASAP?

Thanks

Call 1

22:04:21.541        icetp00 !Starting checklist periodic check

22:04:21.541        icetp00  .Sending connectivity check for check 1: [1] 192.168.1.11:4027-->92.xx.xx.29:4013

22:04:21.548        icetp00  ..Check 1: [1] 192.168.1.11:4027-->92.xx.xx.29:4013: state changed from Frozen to In Progress

22:04:21.558   strm0xb5f19c !Error sending RTP: ICE check is in progress (PJNATH_EICEINPROGRESS)

22:04:21.559   strm0xb5f19c  Error sending RTP: ICE check is in progress (PJNATH_EICEINPROGRESS)

22:04:21.608   strm0xb5f19c  Error sending RTP: ICE check is in progress (PJNATH_EICEINPROGRESS)

22:04:21.609   strm0xb5f19c  Error sending RTP: ICE check is in progress (PJNATH_EICEINPROGRESS)

22:04:21.610   strm0xb5f19c  Error sending RTP: ICE check is in progress (PJNATH_EICEINPROGRESS)

22:04:21.614        icetp00 !.Check 1: [1] 192.168.1.11:4027-->92.xx.xx.29:4013 (nominated): connectivity check SUCCESS

22:04:21.614        icetp00  .Candidate 4 added: comp_id=1, type=prflx, foundation=Pc0a8010b, addr=95.xx.xx.56:1032, base=192.168.1.11:4027, prio=0x7effffff (2130706431)

22:04:21.614        icetp00  .Check 1: [1] 192.168.1.11:4027-->92.xx.xx.29:4013: state changed from In Progress to Succeeded

22:04:21.614        icetp00  .Check 2: [2] 192.168.1.11:4002-->79.xx.xx.34:30450: state changed from Frozen to Waiting

22:04:21.614        icetp00  .Check 3: [2] 192.168.1.11:4002-->92.xx.xx.29:4036: state changed from Frozen to Waiting

22:04:21.614        icetp00  .Check 1 is successful  and nominated

22:04:21.614        icetp00  .Cancelling check 0: [1] 192.168.1.11:4027-->79.xx.xx.34:30446 (In Progress)

22:04:21.626        icetp00  .Check 0: [1] 192.168.1.11:4027-->79.xx.xx.34:30446: state changed from In Progress to Failed

22:04:21.635        icetp00  .Triggered check for check 1 not performed because it's completed

22:04:21.635        icetp00  ..Check 1 is successful  and nominated

22:04:21.639        icetp00 !Starting checklist periodic check

22:04:21.639        icetp00  .Sending connectivity check for check 2: [2] 192.168.1.11:4002-->79.xx.xx.34:30450

22:04:21.646        icetp00  ..Check 2: [2] 192.168.1.11:4002-->79.xx.xx.34:30450: state changed from Waiting to In Progress

22:04:21.693        icetp00  Starting checklist periodic check

22:04:21.693        icetp00  .Sending connectivity check for check 3: [2] 192.168.1.11:4002-->92.xx.xx.29:4036

22:04:21.700        icetp00  ..Check 3: [2] 192.168.1.11:4002-->92.xx.xx.29:4036: state changed from Waiting to In Progress

22:04:21.736        icetp00  Starting checklist periodic check

22:04:21.761        icetp00 !.Triggered check for check 1 not performed because it's completed

22:04:21.761        icetp00  ..Check 1 is successful  and nominated

22:04:21.831        icetp00  .Check 3: [2] 192.168.1.11:4002-->92.xx.xx.29:4036 (nominated): connectivity check SUCCESS

22:04:21.831        icetp00  .Check 3: [2] 192.168.1.11:4002-->92.xx.xx.29:4036: state changed from In Progress to Succeeded

22:04:21.831        icetp00  .Check 3 is successful  and nominated

22:04:21.831        icetp00  .Cancelling check 2: [2] 192.168.1.11:4002-->79.xx.xx.34:30450 (In Progress)

22:04:21.839        icetp00  .Check 2: [2] 192.168.1.11:4002-->79.xx.xx.34:30450: state changed from In Progress to Failed

22:04:21.839        icetp00  .ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED)

22:04:21.839        icetp00  .Valid list

22:04:21.839        icetp00  . 0: [1] 95.xx.xx.56:1032-->92.xx.xx.29:4013 (nominated, state=Succeeded)

22:04:21.839        icetp00  . 1: [1] 95.xx.xx.56:1032-->92.xx.xx.29:4036 (nominated, state=Succeeded)

22:04:21.855        icetp00  .Triggered check for check 3 not performed because it's completed

22:04:21.855        icetp00  ..Check 3 is successful  and nominated

22:04:21.874        icetp00 !ICE negotiation failed after 0s:600: All ICE checklists failed (PJNATH_EICEFAILED)

22:04:21.899        icetp00 !.Triggered check for check 3 not performed because it's completed

22:04:21.899        icetp00  ..Check 3 is successful  and nominated

Call 2

22:07:40.239        icetp00  .Check 1: [1] 192.168.1.11:4000-->92.xx.xx.29:4027 (nominated): connectivity check SUCCESS

22:07:40.239        icetp00  .Candidate 4 added: comp_id=1, type=prflx, foundation=Pc0a8010b, addr=95.xx.xx.56:1032, base=192.168.1.11:4000, prio=0x7effffff (2130706431)

22:07:40.240        icetp00  .Check 1: [1] 192.168.1.11:4000-->92.xx.xx.29:4027: state changed from In Progress to Succeeded

22:07:40.240        icetp00  .Check 2: [2] 192.168.1.11:4015-->79.xx.xx.34:30474: state changed from Frozen to Waiting

22:07:40.240        icetp00  .Check 3: [2] 192.168.1.11:4015-->92.xx.xx.29:4039: state changed from Frozen to Waiting

22:07:40.240        icetp00  .Check 1 is successful  and nominated

22:07:40.240        icetp00  .Cancelling check 0: [1] 192.168.1.11:4000-->79.xx.xx.34:30470 (In Progress)

22:07:40.244        icetp00  .Check 0: [1] 192.168.1.11:4000-->79.xx.xx.34:30470: state changed from In Progress to Failed

22:07:40.274        icetp00  .Triggered check for check 1 not performed because it's completed

22:07:40.274        icetp00  ..Check 1 is successful  and nominated

22:07:40.280        icetp00  .Triggered check for check 1 not performed because it's completed

22:07:40.281        icetp00  ..Check 1 is successful  and nominated

22:07:40.281   pjsua_core.c  .RX 1636 bytes Response msg 200/INVITE/cseq=8965 (rdata0xdd3c14) from TLS 79.xx.xx.34:5071:

SIP/2.0 200 OK

Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;did=205.a1e;mpd=ii;ice_caller=add;ice_callee=add;rtpprx=yes;vsf=dm5ucG1uYlUkOSgMfDM2FkoRTGQCBQAfF0UKKw-->

Record-Route: <sip:127.0.0.1;r2=on;lr=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

Record-Route: <sip:79.xx.xx.34:5071;transport=tls;r2=on;lr=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

v: SIP/2.0/TLS 192.168.1.11:56200;received=95.xx.xx.56;rport=56200;branch=z9hG4bKPj9U906kDYZBcF4FHsF0VJs4ibd2-hHEPO;alias

f: <sip:1004@mydomain>;tag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR

t: <sip:1000@mydomain>;tag=528093C0-52951BAB00033401-3224D700

i: 39pK8XtsZtTV6ClEBKD0kIFZ7cWdnLpk

CSeq: 8965 INVITE

Content-Type: application/sdp

Content-Length: 712

Contact: <sip:ngc...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830>

v=0

o=- 3594492458 3594492459 IN IP4 79.xx.xx.34

s=pjmedia

c=IN IP4 79.xx.xx.34

t=0 0

m=audio 30470 RTP/AVP 111 101

c=IN IP4 79.xx.xx.34

a=sendrecv

a=rtpmap:111 opus/48000/2

a=fmtp:111 maxcodedaudiobandwidth=16000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=zrtp-hash:1.10 1771024f5885b9fbb1797988724afa85e3baf1ac647c8818c65ac625dfb59cb9

a=ice-ufrag:576a214f

a=ice-pwd:6f687e8a

a=candidate:H5cfa0f37 1 UDP 2130706431 92.xx.xx.29 4027 typ host

a=candidate:H5cfa0f37 2 UDP 2130706430 92.xx.xx.29 4039 typ host

a=rtcp:30474

a=candidate:52aORdqRksCtzDKU 1 UDP 2130706432 79.xx.xx.34 30470 typ host

a=candidate:52aORdqRksCtzDKU 2 UDP 2130706431 79.xx.xx.34 30474 typ host

--end msg--

22:07:40.281 mobile_reg_han  .mod_reg_tracker_on_rx_response

22:07:40.281 mobile_reg_han  .mod_reg_tracker_on_rx_response done

22:07:40.282   pjsua_core.c  ...TX 820 bytes Request msg ACK/cseq=8965 (tdta0xf29258) to TLS 79.xx.xx.34:5071:

ACK sip:ngc...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830 SIP/2.0

v: SIP/2.0/TLS 192.168.1.11:56200;rport;branch=z9hG4bKPj97os6Z6WgvyeQhh7OchtrEKWzj4Hd6zX;alias

Max-Forwards: 70

f: <sip:1004@mydomain>;tag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR

t: <sip:1000@mydomain>;tag=528093C0-52951BAB00033401-3224D700

i: 39pK8XtsZtTV6ClEBKD0kIFZ7cWdnLpk

CSeq: 8965 ACK

Route: <sip:79.xx.xx.34:5071;transport=tls;lr;r2=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

Route: <sip:127.0.0.1;lr;r2=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

Route: <sip:127.0.0.1:5062;lr;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;did=205.a1e;mpd=ii;ice_caller=add;ice_callee=add;rtpprx=yes;vsf=dm5ucG1uYlUkOSgMfDM2FkoRTGQCBQAfF0UKKw-->

l:  0

--end msg--

22:07:40.305        icetp00 !Starting checklist periodic check

22:07:40.305        icetp00  .Sending connectivity check for check 2: [2] 192.168.1.11:4015-->79.xx.xx.34:30474

22:07:40.309        icetp00  ..Check 2: [2] 192.168.1.11:4015-->79.xx.xx.34:30474: state changed from Waiting to In Progress

22:07:40.348        icetp00  Starting checklist periodic check

22:07:40.348        icetp00  .Sending connectivity check for check 3: [2] 192.168.1.11:4015-->92.xx.xx.29:4039

22:07:40.355        icetp00  ..Check 3: [2] 192.168.1.11:4015-->92.xx.xx.29:4039: state changed from Waiting to In Progress

22:07:40.388        icetp00  Starting checklist periodic check

22:07:40.429        icetp00 !.Check 3: [2] 192.168.1.11:4015-->92.xx.xx.29:4039 (nominated): connectivity check SUCCESS

22:07:40.429        icetp00  .Check 3: [2] 192.168.1.11:4015-->92.xx.xx.29:4039: state changed from In Progress to Succeeded

22:07:40.429        icetp00  .Check 3 is successful  and nominated

22:07:40.429        icetp00  .Cancelling check 2: [2] 192.168.1.11:4015-->79.xx.xx.34:30474 (In Progress)

22:07:40.441        icetp00  .Check 2: [2] 192.168.1.11:4015-->79.xx.xx.34:30474: state changed from In Progress to Failed

22:07:40.442        icetp00  .ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED)

22:07:40.442        icetp00  .Valid list

22:07:40.442        icetp00  . 0: [1] 95.xx.xx.56:1032-->92.xx.xx.29:4027 (nominated, state=Succeeded)

22:07:40.442        icetp00  . 1: [1] 95.xx.xx.56:1032-->92.xx.xx.29:4039 (nominated, state=Succeeded)

22:07:40.462        icetp00  .Triggered check for check 3 not performed because it's completed

22:07:40.463        icetp00  ..Check 3 is successful  and nominated

22:07:40.481        icetp00 !ICE negotiation failed after 0s:599: All ICE checklists failed (PJNATH_EICEFAILED)

22:07:40.534 pjsua_jni_addo  Get secure for media type 1

22:07:40.534    pjsua_aud.c  Conf connect: 2 --> 0

22:07:40.534    pjsua_aud.c  Conf connect: 0 --> 2

22:07:40.743 zrtp_android.c !ZRTP info message: Hello received, preparing a Commit

22:07:40.760 zrtp_android.c  ZRTP info message: Commit: Generated a public DH key

22:07:40.977 zrtp_android.c  ZRTP info message: Responder: Commit received, preparing DHPart1

22:07:40.977 zrtp_android.c  ZRTP info message: DH1Part: Generated a public DH key

22:07:41.266 zrtp_android.c  ZRTP info message: Responder: DHPart2 received, preparing Confirm1

22:07:41.294 zrtp_android.c  ZRTP info message: At least one retained secrets matches - security OK

22:07:41.500     ec0xbcc8f8 !Underflow, buf_cnt=3, will generate 1 frame

22:07:41.525 zrtp_android.c !ZRTP info message: Responder: Confirm2 received, preparing Conf2Ack

22:07:41.536 zrtp_android.c  Show sas : ya6e in ctxt e7767c

22:07:41.537 zrtp_android.c  ZRTP info message: Entered secure state

22:07:41.542 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.542 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.542 pjsua_jni_addo !Get secure for media type 1

22:07:41.543 pjsua_jni_addo  ZRTP :: V 1

22:07:41.543 pjsua_jni_addo  ZRTP :: S L 4

22:07:41.543 pjsua_jni_addo  ZRTP :: C L 16

22:07:41.558 zrtp_android.c !ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.563 pjsua_jni_addo !Get secure for media type 1

22:07:41.563 pjsua_jni_addo  ZRTP :: V 1

22:07:41.563 pjsua_jni_addo  ZRTP :: S L 4

22:07:41.563 pjsua_jni_addo  ZRTP :: C L 16

22:07:41.564 zrtp_android.c !ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.568 pjsua_jni_addo !Get secure for media type 1

22:07:41.568 pjsua_jni_addo  ZRTP :: V 1

22:07:41.568 pjsua_jni_addo  ZRTP :: S L 4

22:07:41.568 pjsua_jni_addo  ZRTP :: C L 16

22:07:41.609 zrtp_android.c !ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.614 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.642 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.681 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.687 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.695 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.708 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:41.732 zrtp_android.c  ZRTP warning message: Dropping packet because SRTP authentication failed!

22:07:48.479   Master/sound !Underflow, buf_cnt=2, will generate 1 frame

22:07:59.141   pjsua_call.c !Call 2 hanging up: code=0..

22:07:59.142   pjsua_core.c  ....TX 861 bytes Request msg BYE/cseq=8966 (tdta0xcc67a8) to TLS 79.xx.xx.34:5071:

BYE sip:ngc...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830 SIP/2.0

v: SIP/2.0/TLS 192.168.1.11:56200;rport;branch=z9hG4bKPjb6thLuSioAYo2rme0.zoX54UXaAi4muj;alias

Max-Forwards: 70

f: <sip:1004@mydomain>;tag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR

t: <sip:1000@mydomain>;tag=528093C0-52951BAB00033401-3224D700

i: 39pK8XtsZtTV6ClEBKD0kIFZ7cWdnLpk

CSeq: 8966 BYE

Route: <sip:79.xx.xx.34:5071;transport=tls;lr;r2=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

Route: <sip:127.0.0.1;lr;r2=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

Route: <sip:127.0.0.1:5062;lr;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;did=205.a1e;mpd=ii;ice_caller=add;ice_callee=add;rtpprx=yes;vsf=dm5ucG1uYlUkOSgMfDM2FkoRTGQCBQAfF0UKKw-->

User-Agent:Test_ST27i-15/r2328

l:  0

[Régis Montoya]

Thanks for the details.

Interesting point.
Something I'm just thinking about : can you try with zrtp disabled?

I'm wondering if it could not be something with android timers conflicting. The timers has been changed recently in pjsip and the portage to android is far to be perfect (I'm not totally confident in the fact it will behaves well on all devices in all conditions ;) ).

2013/11/27 Priv <priv...@gmail.com>

[Priv]

I just checked with ZRTP off. Problem remains, unfortunately.

I was looking into issue 2379 since there maybe some similar issues at play. Tomas also got (PJNATH_EICEFAILED) in the logs.

I'm pretty confident the issue lies somewhere in the STUN/ICE implementation.

I've sent copy of this to the PJSIP mailing list, but unfortunately no one has replied (:

Not really sure where to go from here.

Any help/ideas are appreciated.

Thanks

[Régis Montoya]

Ok,

In order to ensure the problem is with pjsip it could be interesting to test with other apps using pjsip as stack. For example blink or microsip or pjsua in cli.
I don't know if they support ICE too, but might help to ensure the problem is pjsip or is csipsimple. I'm yet not totally sure where is the problem.
If you have your own builds, could be interesting to upgrade pjsip, maybe they did some changes meanwhile. I'll try to do that soon, but you can try before me ;). Do do so:

unapply quilt patch on pjsip folder (quilt pop -a); change the svn remote version dep; reapply all quilt patches (quilt push -a).

2013/11/28 Priv <priv...@gmail.com>

[Priv]

Thanks for the tip.

I'm not really sure blink and the others support ICE (at least in the free version of blink - there's also a paid version which likely supports ICE).

Anyway I'm going to try them out if I can find some free time.

I also noticed that there was a potential buffer overflow recently fixed in PJSIP's ICE http://trac.pjsip.org/repos/ticket/1700 and it is not applied in CSip yet.

Maybe that could be the problem?

Also, on another different topic, I noticed you updated opus to 1.0.2 recently. You are aware that opus has been at 1.0.3 for some months now, and they're testing version 1.1.rc2 right now?

I mention this because I changed the branch myself to 1.0.3 and it seems ok with CSip at first glance. Freeswitch has also added 1.0.3 to their master branch recently and there are some issues when using CS to call FS when both are on 1.0.3 (audio works but sounds pretty bad - likely needs some minor adjustments).

Thanks

[Priv]

And this could also be relevant.

http://trac.pjsip.org/repos/ticket/1695

[Régis Montoya]

Ok. Several things to upgrade :) . I add that to my todo list

2013/11/28 Priv <priv...@gmail.com>

[Priv]

Thanks. I look forward to seeing the updated version.

Meanwhile, where can I find the svn dep to update? Looking in /trunk/CSipSimple/jni/pjsip I don't see it anywhere

[Peter Villeneuve]

Hi,

Is there any estimate of when these updates will be ported into CSipSimple?
I would also like to learn how to update to latest PJSIP to see if these problems are resolved.

Could someone point me in the right direction or give me some specific instructions?
I'm not a great android developer but I'm sure I could do it if given proper instructions.

Thank you,

Peter

[Régis Montoya]

Hi Peter,

I'll start that right now.

However, for reference the short instruction on how to migrate pjsip version in csipsimple :
1) unapply patches : go in jni/pjsip folder and run "quilt pop -a"
2) Edit svn properties of jni/pjsip folder and change the svn:externals property to use the version of pjsip repo you want
3) Reapply patches : run quilt push as many time as necessary to reach last patch (and check each time that there is no conflict). (If confident in the fact there will be no conflict you can run "quilt push -a"
That's it :)

[Régis Montoya]

Oups forgot one point after point 2) -> run svn update ;)

2013/12/1 Régis Montoya <r3gi...@gmail.com>

[Priv]

Hi Regis,

Thanks for the update and for all the help you provide the community. I'm sure a lot if us appreciate your effort.

2013/11/28 Priv <priv...@gmail.com>

http://trac.pjsip.org/repos/ticket/1695

2013/11/28 Priv <priv...@gmail.com>

2013/11/27 Priv <priv...@gmail.com>

Contact: <sip:n...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830>

v=0

o=- 3594492458 3594492459 IN IP4 79.xx.xx.34

s=pjmedia

c=IN IP4 79.xx.xx.34

t=0 0

m=audio 30470 RTP/AVP 111 101

c=IN IP4 79.xx.xx.34

a=sendrecv

a=rtpmap:111 opus/48000/2

a=fmtp:111 maxcodedaudiobandwidth=16000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=zrtp-hash:1.10 1771024f5885b9fbb1797988724afa85e3baf1ac647c8818c65ac625dfb59cb9

a=ice-ufrag:576a214f

a=ice-pwd:6f687e8a

a=candidate:H5cfa0f37 1 UDP 2130706431 92.xx.xx.29 4027 typ host

a=candidate:H5cfa0f37 2 UDP 2130706430 92.xx.xx.29 4039 typ host

a=rtcp:30474

a=candidate:52aORdqRksCtzDKU 1 UDP 2130706432 79.xx.xx.34 30470 typ host

a=candidate:52aORdqRksCtzDKU 2 UDP 2130706431 79.xx.xx.34 30474 typ host

--end msg--

22:07:40.281 mobile_reg_han  .mod_reg_tracker_on_rx_response

22:07:40.281 mobile_reg_han  .mod_reg_tracker_on_rx_response done

22:07:40.282   pjsua_core.c  ...TX 820 bytes Request msg ACK/cseq=8965 (tdta0xf29258) to TLS 79.xx.xx.34:5071:

ACK sip:n...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830 SIP/2.0

BYE sip:n...@79.xx.xx.34:5060;ngcpct=7369703a3132372e302e302e313a35303830 SIP/2.0

v: SIP/2.0/TLS 192.168.1.11:56200;rport;branch=z9hG4bKPjb6thLuSioAYo2rme0.zoX54UXaAi4muj;alias

Max-Forwards: 70

f: <sip:1004@mydomain>;tag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR

t: <sip:1000@mydomain>;tag=528093C0-52951BAB00033401-3224D700

i: 39pK8XtsZtTV6ClEBKD0kIFZ7cWdnLpk

CSeq: 8966 BYE

Route: <sip:79.xx.xx.34:5071;transport=tls;lr;r2=on;ftag=TptWgy7WZjiBHrHEskTO7-5CYURWwGYR;ngcplb=yes;socket=tls:79.xx.xx.34:5071>

...