search

NG-Studio-Development / csipsimple

Automatically exported from code.google.com/p/csipsimple
0 stars 0 forks source link

Wrong port number when trying to unregister contact - contact rewrite #2234

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
Hello,

I'm seeing very strange behaviour of the CSipSimple client when trying to 
REGISTER to a Kamailio server, due to the contact rewrite feature, which sends 
out a second registration when the client gets a different host/port back from 
the server than was sent in the REGISTER. The behaviour cannot always be 
reproduced. I'm including a few tcpdump extracts below:

As you can see, the first one works fine. The first registration with 6761 in 
the contact port is followed by a new registration, and an expires=0 for 
contact port 6761.

17:28:00.875476 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 767)
    188.189.68.119.33608 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 739
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPj4aU1BgdeOOJCAJg-yshpTuaUsiLu13NC
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=w.6q81PNijdHGoH.YGSsRgga6afcL936
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10027 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUnk1EVJmcMKTLodR/NlauO9YcoSKhV", uri="sip:firstserved.net", response="68f5780a6a57a9f689e13fc2c909c537"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:6761;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:28:00.877513 IP (tos 0x10, ttl 64, id 45335, offset 0, flags [none], proto 
UDP (17), length 589)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.33608: SIP, length: 561
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=33608;branch=z9hG4bKPj4aU1BgdeOOJCAJg-yshpTuaUsiLu13NC
    f: "koen" <sip:koen@firstserved.net>;tag=w.6q81PNijdHGoH.YGSsRgga6afcL936
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.c6bd
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10027 REGISTER
    Contact: <sip:koen@188.189.80.44:6237;ob>;expires=4;received="sip:188.189.80.44:59045", <sip:koen@188.189.68.119:6761;ob>;expires=300;received="sip:188.189.68.119:33608"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

17:28:01.274382 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 816)
    188.189.68.119.33608 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 788
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPjmbWd0PcTPZqBEz3HMm.54.2GVKGsl0Mu
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=jtTrOzQ6KXhaoPaI0gqn0DfdMv4WXSA.
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10028 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUnk1EVJmcMKTLodR/NlauO9YcoSKhV", uri="sip:firstserved.net", response="68f5780a6a57a9f689e13fc2c909c537"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:33608;ob>
    m: <sip:koen@188.189.68.119:6761;ob>;expires=0
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:28:01.276116 IP (tos 0x10, ttl 64, id 45336, offset 0, flags [none], proto 
UDP (17), length 590)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.33608: SIP, length: 562
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=33608;branch=z9hG4bKPjmbWd0PcTPZqBEz3HMm.54.2GVKGsl0Mu
    f: "koen" <sip:koen@firstserved.net>;tag=jtTrOzQ6KXhaoPaI0gqn0DfdMv4WXSA.
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.9902
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10028 REGISTER
    Contact: <sip:koen@188.189.80.44:6237;ob>;expires=3;received="sip:188.189.80.44:59045", <sip:koen@188.189.68.119:33608;ob>;expires=300;received="sip:188.189.68.119:33608"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

Here, the unregister which should contain an expires=0 for the contact on port 
7820, instead contains an unregister for port 7823, which is of course ignored 
by the server. Additionally, an extra register request is sent out, leading to 
three registrations for this AoR.

17:32:57.097215 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 767)
    188.189.68.119.37704 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 739
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPjuQ0sUVykpqOwVIvCN1XYcw-zS0dKmax3
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10029 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUnk1EVJmcMKTLodR/NlauO9YcoSKhV", uri="sip:firstserved.net", response="68f5780a6a57a9f689e13fc2c909c537"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:7816;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:32:57.097742 IP (tos 0x10, ttl 64, id 45346, offset 0, flags [none], proto 
UDP (17), length 520)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.37704: SIP, length: 492
    SIP/2.0 401 Unauthorized
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=37704;branch=z9hG4bKPjuQ0sUVykpqOwVIvCN1XYcw-zS0dKmax3
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.b5c9
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10029 REGISTER
    WWW-Authenticate: Digest realm="firstserved.net", nonce="URUp5FEVKLiaOtGsjCvNtXJ0Zx8oT8Ix"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

17:32:57.176138 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 767)
    188.189.68.119.37704 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 739
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPjuQ0sUVykpqOwVIvCN1XYcw-zS0dKmax3
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10029 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUnk1EVJmcMKTLodR/NlauO9YcoSKhV", uri="sip:firstserved.net", response="68f5780a6a57a9f689e13fc2c909c537"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:7818;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:32:57.176457 IP (tos 0x10, ttl 64, id 45347, offset 0, flags [none], proto 
UDP (17), length 520)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.37704: SIP, length: 492
    SIP/2.0 401 Unauthorized
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=37704;branch=z9hG4bKPjuQ0sUVykpqOwVIvCN1XYcw-zS0dKmax3
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.b5c9
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10029 REGISTER
    WWW-Authenticate: Digest realm="firstserved.net", nonce="URUp5FEVKLiaOtGsjCvNtXJ0Zx8oT8Ix"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

17:32:57.456560 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 767)
    188.189.68.119.37704 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 739
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPjisuN3.NhYVJc.naknm0UU.su7Lm3Xzyi
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10030 REGISTER
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:7820;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUp5FEVKLiaOtGsjCvNtXJ0Zx8oT8Ix", uri="sip:firstserved.net", response="eb9913c6da93960af00595938bb5636a"
    l:  0

17:32:57.458635 IP (tos 0x10, ttl 64, id 45349, offset 0, flags [none], proto 
UDP (17), length 592)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.37704: SIP, length: 564
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=37704;branch=z9hG4bKPjisuN3.NhYVJc.naknm0UU.su7Lm3Xzyi
    f: "koen" <sip:koen@firstserved.net>;tag=fPvz042lfqKU6PhM2uJB170bdoa.srf2
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.a00c
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10030 REGISTER
    Contact: <sip:koen@188.189.68.119:33608;ob>;expires=4;received="sip:188.189.68.119:33608", <sip:koen@188.189.68.119:7820;ob>;expires=300;received="sip:188.189.68.119:37704"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

17:32:57.857172 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 816)
    188.189.68.119.37704 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 788
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPj8vBD5MRlHUrw3Wx39Hfd2mIl39FDSo0H
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=7WnrUrBYAlzd.FHE6JvYz84rIwIIQn.l
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10031 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUp5FEVKLiaOtGsjCvNtXJ0Zx8oT8Ix", uri="sip:firstserved.net", response="eb9913c6da93960af00595938bb5636a"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:37704;ob>
    m: <sip:koen@188.189.68.119:7823;ob>;expires=0
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:32:57.858414 IP (tos 0x10, ttl 64, id 45350, offset 0, flags [none], proto 
UDP (17), length 676)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.37704: SIP, length: 648
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=37704;branch=z9hG4bKPj8vBD5MRlHUrw3Wx39Hfd2mIl39FDSo0H
    f: "koen" <sip:koen@firstserved.net>;tag=7WnrUrBYAlzd.FHE6JvYz84rIwIIQn.l
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.eba9
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10031 REGISTER
    Contact: <sip:koen@188.189.68.119:33608;ob>;expires=4;received="sip:188.189.68.119:33608", <sip:koen@188.189.68.119:7820;ob>;expires=300;received="sip:188.189.68.119:37704", <sip:koen@188.189.68.119:37704;ob>;expires=300;received="sip:188.189.68.119:37704"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

17:33:03.936014 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 767)
    188.189.68.119.37704 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 739
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.68.119:54088;rport;branch=z9hG4bKPj.qp-4JEubUXCo9DsFWhgIiltbQqSMFrq
    Route: <sip:firstserved.net;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=batH6XJrAFqvEJpC63ttwfKPVSfTu0uc
    t: "koen" <sip:koen@firstserved.net>
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10032 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URUp5FEVKLiaOtGsjCvNtXJ0Zx8oT8Ix", uri="sip:firstserved.net", response="eb9913c6da93960af00595938bb5636a"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: <sip:koen@188.189.68.119:7831;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    l:  0

17:33:03.938132 IP (tos 0x10, ttl 64, id 45351, offset 0, flags [none], proto 
UDP (17), length 677)
    93-94-109-36.ip.firstserved.net.sip > 188.189.68.119.37704: SIP, length: 649
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.68.119:54088;rport=37704;branch=z9hG4bKPj.qp-4JEubUXCo9DsFWhgIiltbQqSMFrq
    f: "koen" <sip:koen@firstserved.net>;tag=batH6XJrAFqvEJpC63ttwfKPVSfTu0uc
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.eb28
    i: cXGHDoxWFgO6U1uKuoPM5L9c8vIlO3Ur
    CSeq: 10032 REGISTER
    Contact: <sip:koen@188.189.68.119:7820;ob>;expires=294;received="sip:188.189.68.119:37704", <sip:koen@188.189.68.119:37704;ob>;expires=294;received="sip:188.189.68.119:37704", <sip:koen@188.189.68.119:7831;ob>;expires=300;received="sip:188.189.68.119:37704"
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

Kind regards,

Denis Braet

Original issue reported on code.google.com by denis.br...@gmail.com on 8 Feb 2013 at 5:01

GoogleCodeExporter commented 9 years ago 
Hi,

MMmmm, very strange.

I would be interested by two things :
 1- Try to upgrade to latest nightly builds. There is something to prevent from brutal network loss (and so from missing un-registrations in the middle) -> http://nightlies.csipsimple.com/trunk/
 (be sure with this version that the "try to clean registration" is enabled -- it should be the case after the upgrade)

 2- Have logs from the app (see HowToCollectLogs wiki page). Here we see logs from the server, and regarding how contact are rewritten (the IP are the same and only port changes), I really suspect there is a network equipment in the middle that already makes some ip:port rewriting (something like a SIP ALG). Comparing logs from the app and logs from your server will allow to see what is sent by the app and what is received by your server and detect if there is something in the middle as I suspect. (this equipement can be hidden in a firewall, or an internet access box, so maybe there is one even if you didn't voluntarily deployed one).
And in this case => 
    a) you should not have "allow contact rewrite" enabled (as already done by your equipment on the middle)
    b) the offset of 3 in the port number is probably introduced by this equipment in the middle (maybe it has a bug when stressed by the contact rewrite stuff from pjsip).

Original comment by r3gis...@gmail.com on 8 Feb 2013 at 8:51

GoogleCodeExporter commented 9 years ago 
Hello Régis,

There is indeed some NAT'ing involved in this scenario, but not under our 
control, since the connection is made over 3G with a Belgian provider. I myself 
have no such trouble, with exactly the same CSipSimple version, to connect from 
Bouygues and SFR, two French providers. I'll ask my colleague to record a log 
on his phone on monday to cross-check what goes wrong between client and server.

I'm certain that disabling the contact-rewrite field would solve the issue - at 
least when resorting to other NAT traversal means, but since we're aiming to 
build a fully RFC3261-compliant solution that works with as many clients and 
ISP's as is possible, that's not the way to go.

Kind regards,

Denis Braet

Original comment by denis.br...@gmail.com on 8 Feb 2013 at 9:13

GoogleCodeExporter commented 9 years ago 
Ah, on va pouvoir continuer en français si tu te connectes de SRF ou Bouygues 
:)

Ok, pour le fait que l'équipement qui fait le NAT est peut-être pas de votre 
côté.
Par contre il est tout à fait illusoire d'imaginer trouver une solution qui 
corresponde à toutes les topo réseaux.
D'ailleurs la méchanique de contact rewrite n'est pas décrite dans la RFC3261 
mais dans une autre (que je n'ai pas en tête). Il y a aussi beaucoup d'autres 
RFC qui étendent le SIP. Concernant les problématiques de NAT, il y a par 
exemple le STUN et le ICE.
Activer le STUN pourrait par exemple éviter le contact rewrite (puisque le 
port sip publique serait directement trouvé comme étant le bon). Il faut par 
contre que ce serveur stun soit dans le bon réseau (idéalement le même 
public que celui du serveur sip)

Il faut donc en général des options (qu'il faudra détecter au mieux suivant 
les besoins). C'est pour cette raison que l'approche de csipsimple c'est 
d'avoir des assistant de configuration qui viennent adapter au mieux les 
options par rapport au fournisseur de service, au modèle du téléphone, au 
pays et aux préférences de l'utilisateur.

Original comment by r3gis...@gmail.com on 8 Feb 2013 at 9:23

GoogleCodeExporter commented 9 years ago 
Bonsoir Régis,

Aucun souci de continuer en français, je te savais francophone mais avais 
débuté la conversation en anglais par souci pour de futurs lecteurs.

Tu as bien raison que de chercher la configuration qui permette de connecter 
tous les clients à travers tous les fournisseurs vers tous les serveurs SIP 
est le graal. D'autre part, mieux vaut anticiper le plus possible. Ce que 
j'aime bien à CSipSimple par rapport à d'autres softphones tel que SipDroid, 
3CXPhone ou bien d'autres, c'est qu'on peut chipoter dedans pour essayer 
différents scénarios, contrairement aux autres. Pour la plateforme Android, 
le logiciel est bien en train de devenir le logiciel de préférence. Et 
malgré le fait qu'il est possible de choisir différents profils pour chaque 
fournisseur VoIP, ça n'empêche pas le NAT'ing des fournisseurs de faire 
pierre d'achoppement. La config qui marche sur mon phone ne marche pas sur 
celui de mon collègue. Mon ambition est de configurer le serveur de telle 
façon qu'il puisse capter les conneries NAT des fournisseurs autant que 
possible, sans demander à l'utilisateur de passer en mode expert, sans compter 
ceux qui se serviraient d'un logiciel moins intelligent, tel qu'un softphone 
Windows ou même un téléphone SIP Cisco.

Je te tiens au courant de mes découvertes quant à la logique NAT de l'ISP de 
mon collègue, ça pourra probablement servir à encore une fois trouver des 
workarounds pour les bêtises d'autrui.

Bien à toi,

Denis

Original comment by denis.br...@gmail.com on 9 Feb 2013 at 12:28

GoogleCodeExporter commented 9 years ago 
Bonjour Régis,

Le fournisseur ré-écrit les ports dans le champ contact, comme tu peux voir 
dans les logs ci-dessous:

Envoyé depuis le phone:

D/libpjsip( 5279): REGISTER sip:firstserved.net SIP/2.0
D/libpjsip( 5279): v: SIP/2.0/UDP 
188.189.95.24:21320;rport;branch=z9hG4bKPjwwIZ3llqbZW9VQM2PnvpWuRbplho-zRD
D/libpjsip( 5279): Route: <sip:firstserved.net;transport=udp;lr>
D/libpjsip( 5279): Max-Forwards: 70
D/libpjsip( 5279): f: "koen" 
<sip:koen@firstserved.net>;tag=aiZi0wbDzro6vyejM821Yf9qKO6O151q
D/libpjsip( 5279): t: "koen" <sip:koen@firstserved.net>
D/libpjsip( 5279): i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
D/libpjsip( 5279): CSeq: 47767 REGISTER
D/libpjsip( 5279): User-Agent: CSipSimple_SK17i-10/r1916
D/libpjsip( 5279): m: "koen" <sip:koen@188.189.95.24:21320;ob>
D/libpjsip( 5279): Expires: 300
D/libpjsip( 5279): Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, 
NOTIFY, REFER, MESSAGE, OPTIONS
D/libpjsip( 5279): Authorization: Digest username="koen@firstserved.net", 
realm="firstserved.net", nonce="URi26FEYtby4V09I4K2et/ugnyW/fzVy", 
uri="sip:firstserved.net", response="197148f2a9d22a15b4ecf5580ee6e858"
D/libpjsip( 5279): l:  0

Reçu sur le serveur:

10:11:25.844768 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 787)
    188.189.95.24.21320 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 759
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.95.24:21320;rport;branch=z9hG4bKPjwwIZ3llqbZW9VQM2PnvpWuRbplho-zRD
    Route: <sip:firstserved.net;transport=udp;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=aiZi0wbDzro6vyejM821Yf9qKO6O151q
    t: "koen" <sip:koen@firstserved.net>
    i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
    CSeq: 47767 REGISTER
    User-Agent: CSipSimple_SK17i-10/r1916
    m: "koen" <sip:koen@188.189.95.24:32203;ob>
    Expires: 300
    Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URi26FEYtby4V09I4K2et/ugnyW/fzVy", uri="sip:firstserved.net", response="197148f2a9d22a15b4ecf5580ee6e858"
    l:  0

Cela mène évidemment à un jeu de ping-pong, vu que le serveur renvoie le 
port perçu, 32203, dans ce cas, et que le client voit un port changé, et 
répond de retour, et ainsi de suite:

10:11:25.846927 IP (tos 0x10, ttl 64, id 30087, offset 0, flags [none], proto 
UDP (17), length 473)
    93-94-109-36.ip.firstserved.net.sip > 188.189.95.24.21320: SIP, length: 445
    SIP/2.0 200 OK
    v: SIP/2.0/UDP 188.189.95.24:21320;rport=21320;branch=z9hG4bKPjwwIZ3llqbZW9VQM2PnvpWuRbplho-zRD
    f: "koen" <sip:koen@firstserved.net>;tag=aiZi0wbDzro6vyejM821Yf9qKO6O151q
    t: "koen" <sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.06fc
    i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
    CSeq: 47767 REGISTER
    Contact: <sip:koen@188.189.95.24:32203;ob>;expires=300
    Server: kamailio (3.3.3 (x86_64/linux))
    Content-Length: 0

D/libpjsip( 5279): SIP/2.0 200 OK
D/libpjsip( 5279): v: SIP/2.0/UDP 
10.48.60.11;rport=21320;branch=z9hG4bKPjwwIZ3llqbZW9VQM2PnvpWuRbplho-zRD
D/libpjsip( 5279): f: "koen" 
<sip:koen@firstserved.net>;tag=aiZi0wbDzro6vyejM821Yf9qKO6O151q
D/libpjsip( 5279): t: "koen" 
<sip:koen@firstserved.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.06fc
D/libpjsip( 5279): i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
D/libpjsip( 5279): CSeq: 47767 REGISTER
D/libpjsip( 5279): Contact: <sip:koen@188.189.95.24:32203;ob>;expires=300
D/libpjsip( 5279): Server: kamailio (3.3.3 (x86_64/linux))
D/libpjsip( 5279): Content-Length: 0

D/libpjsip( 5279): REGISTER sip:firstserved.net SIP/2.0
D/libpjsip( 5279): v: SIP/2.0/UDP 
188.189.95.24:21320;rport;branch=z9hG4bKPjFuM0.sVUObmjjuCY.pH.1NLRC68heOyu
D/libpjsip( 5279): Route: <sip:firstserved.net;transport=udp;lr>
D/libpjsip( 5279): Max-Forwards: 70
D/libpjsip( 5279): f: "koen" 
<sip:koen@firstserved.net>;tag=TffHd4yxpx8CjdEJANinawZ0TkgZLzYf
D/libpjsip( 5279): t: "koen" <sip:koen@firstserved.net>
D/libpjsip( 5279): i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
D/libpjsip( 5279): CSeq: 47768 REGISTER
D/libpjsip( 5279): Authorization: Digest username="koen@firstserved.net", 
realm="firstserved.net", nonce="URi26FEYtby4V09I4K2et/ugnyW/fzVy", 
uri="sip:firstserved.net", response="197148f2a9d22a15b4ecf5580ee6e858"
D/libpjsip( 5279): User-Agent: CSipSimple_SK17i-10/r1916
D/libpjsip( 5279): m: "koen" <sip:koen@188.189.95.24:21320;ob>
D/libpjsip( 5279): Expires: 0
D/libpjsip( 5279): l:  0

10:11:36.984031 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 693)
    188.189.95.24.21320 > 93-94-109-36.ip.firstserved.net.sip: SIP, length: 665
    REGISTER sip:firstserved.net SIP/2.0
    v: SIP/2.0/UDP 188.189.95.24:21320;rport;branch=z9hG4bKPjFuM0.sVUObmjjuCY.pH.1NLRC68heOyu
    Route: <sip:firstserved.net;transport=udp;lr>
    Max-Forwards: 70
    f: "koen" <sip:koen@firstserved.net>;tag=TffHd4yxpx8CjdEJANinawZ0TkgZLzYf
    t: "koen" <sip:koen@firstserved.net>
    i: zulCfTZEk9j5LS7BrK22GjaiWpHFrGO.
    CSeq: 47768 REGISTER
    Authorization: Digest username="koen@firstserved.net", realm="firstserved.net", nonce="URi26FEYtby4V09I4K2et/ugnyW/fzVy", uri="sip:firstserved.net", response="197148f2a9d22a15b4ecf5580ee6e858"
    User-Agent: CSipSimple_SK17i-10/r1916
    m: "koen" <sip:koen@188.189.95.24:32222;ob>
    Expires: 0
    l:  0

Aurais-tu une idée de comment éviter ce genre de problèmes? J'avais pensé 
essayer le SIP par TCP, étant donné que pour ce scénario, CSipSimple permet 
d'employer l'extension GRUU pour avoir un champ de contact unique, mais ça ne 
donne pas trop fort en TCP:

D/libpjsip( 5279): 10:29:43.432    pjsua_acc.c  Adding account: id=koen 
<sip:koen@firstserved.net>
D/libpjsip( 5279): 10:29:43.432    pjsua_acc.c  .Account koen 
<sip:koen@firstserved.net> added with id 1
D/libpjsip( 5279): 10:29:43.432    pjsua_acc.c  .Acc 1: setting registration..
E/libpjsip( 5279): 10:29:43.432    pjsua_acc.c  ..Unable to generate suitable 
Contact header for registration: Unsupported transport (PJSIP_EUNSUPTRANSPORT) 
[status=171060]
E/libpjsip( 5279): 10:29:43.432    pjsua_acc.c  ..Unable to create 
registration: Unsupported transport (PJSIP_EUNSUPTRANSPORT) [status=171060]

Il y a-t-il une raison de protocole pourquoi RFC5626 ne marche pas en UDP? Ou 
s'agit-il d'une implémentation qui reste à faire?

Bien à toi,

Denis

Original comment by denis.br...@gmail.com on 11 Feb 2013 at 10:05

GoogleCodeExporter commented 9 years ago 
Ok, ça confirme ma théorie :).

Pour le TCP qui ne marche pas, est-ce que l'option dans Réseaux > Transport 
TCP est bien activée? Sinon comment as-tu activé le transport TCP?

Pour l'udp et la rfc5626, en effet : 
http://www.pjsip.org/pjsip/docs/html/structpjsua__acc__config.htm#a306e464198860
6f1ef0993e398ff98e7
pas encore supporté chez pjsip.

Original comment by r3gis...@gmail.com on 11 Feb 2013 at 11:02

GoogleCodeExporter commented 9 years ago 
Bonsoir Régis,

Pour le TCP, c'était en effet l'option transport qui n'était pas activée. 
J'ai fait des tests avec l'enregistrement par TCP et TLS, et le problème des 
doubles enregistrements ne se produit plus. Malheureusement, les appels 
n'offrent l'audio que d'un côté, et je suppose qu'ici aussi, il y a un 
problème du côté du fournisseur d'accès. J'inclus les paramètres utiles 
des différents logs. C'est le client dont les logs traitent ci-dessous qui ne 
reçoit pas d'audio, l'autre côté reçoit bien son audio par contre.

Les logs CSipSimple, niveau de logging 5 ci-dessous. Je n'ai pas filtré le 
tout, au cas où ce serait un problème audio, ce qui me parait plutôt 
improbable, vu que les codecs sont compatibles - nous avons testé en G711, 
Codec2 et G729. Ce qui m'intéresse, ce sont les deux messages STUN timeout, je 
ne sais s'ils sont normaux. Par contre, pas moyen de voir dans les logs quels 
ports RTP et RTCP sont affichés par le client en réponse à l'INVITE, vu que 
les messages sont coupés à mi-chemin.

Côté tcpdump sur le serveur, ça donne le suivant pour le RTP et RTCP:

RTP du serveur vers le client:
17:10:48.542876 IP (tos 0xb8, ttl 64, id 0, offset 0, flags [DF], proto UDP 
(17), length 60)
    93-94-109-36.ip.firstserved.net.43822 > 188.189.67.183.24364: UDP, length 32

Vers port 24364 comme affiché dans les logs

RTP du client vers le serveur:
17:10:48.555294 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 60)
    188.189.67.183.65324 > 93-94-109-36.ip.firstserved.net.43822: UDP, length 32

Vers le port RTP comme affiché par le serveur. Par contre, le traffic n'est 
pas symmétrique, alors que dans l'autre leg du call, il l'est.

RTCP serveur -> client:
17:10:48.684310 IP (tos 0xb8, ttl 64, id 0, offset 0, flags [DF], proto UDP 
(17), length 120)
    93-94-109-36.ip.firstserved.net.43823 > 188.189.67.183.24365: UDP, length 92

RTCP client -> serveur:
17:10:41.015986 IP (tos 0x8, ttl 57, id 0, offset 0, flags [DF], proto UDP 
(17), length 92)
    188.189.67.183.40749 > 93-94-109-36.ip.firstserved.net.43823: UDP, length 64

Le proxy media sur le serveur démontre que les packets RTP arrivent bel et 
bien jusqu'au serveur:

Feb 11 17:10:37 sip01 rtpproxy[24349]: INFO:handle_command: new session on a 
port 43822 created, tag oMKT
GNINfNkTtswEzYYsmYDSp3zzXrU0;1
Feb 11 17:10:41 sip01 rtpproxy[24349]: INFO:handle_command: pre-filling 
callee's address with 188.189.67.
183:24364
Feb 11 17:11:49 sip01 rtpproxy[24349]: INFO:remove_session: RTP stats: 398 in 
from callee, 364 in from ca
ller, 762 relayed, 0 dropped
Feb 11 17:11:49 sip01 rtpproxy[24349]: INFO:remove_session: RTCP stats: 3 in 
from callee, 4 in from calle
r, 7 relayed, 0 dropped
Feb 11 17:11:49 sip01 rtpproxy[24349]: INFO:remove_session: session on ports 
43822/52428 is cleaned up

L'invite envoyé par le serveur:

17:10:37.868956 IP (tos 0x10, ttl 64, id 23641, offset 0, flags [DF], proto TCP 
(6), length 1201)
    93-94-109-36.ip.firstserved.net.sip > 188.189.67.183.61249: Flags [P.], cksum 0xcf9a (incorrect -> 0x9834), seq 3169:4318, ack 4307, win 390, options [nop,nop,TS val 1457494659 ecr 15978911], length 1149
E...\Y@.@...]^m$..C....Aw..zW..............
V.......INVITE sip:koen@188.189.67.183:61249;transport=TCP;ob SIP/2.0
Record-Route: 
<sip:93.94.109.36;transport=tcp;r2=on;lr=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU
0;nat=yes>
Record-Route: 
<sip:93.94.109.36:5061;transport=tls;r2=on;lr=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3
zzXrU0;nat=yes>
Via: SIP/2.0/TCP 93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
v: SIP/2.0/TLS 
192.168.1.55:38512;received=109.20.3.91;rport=38512;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
Max-Forwards: 69
f: "disple" <sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
t: <sip:koen@firstserved.net>
m: <sip:denis@109.20.3.91:38512;transport=TLS;ob>
i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
CSeq: 18021 INVITE
k: replaces, 100rel, timer, norefersub
x: 1800
Min-SE: 90
User-Agent: CSipSimple_GT-I9100-15/r1916
c: application/sdp
l:   296
P-hint: branch [1]

v=0
o=- 3569587812 3569587812 IN IP4 93.94.109.36
s=pjmedia
c=IN IP4 109.20.3.91
t=0 0
m=audio 43822 RTP/AVP 18 100 0 8 101
c=IN IP4 93.94.109.36
a=rtcp:43823
a=sendrecv
a=fmtp:18 annexb=no
a=rtpmap:100 CODEC2/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=nortpproxy:yes

La réponse à l'INVITE reçue par le serveur:

17:10:41.255162 IP (tos 0x8, ttl 57, id 16820, offset 0, flags [DF], proto TCP 
(6), length 1122)
    188.189.67.183.61249 > 93-94-109-36.ip.firstserved.net.sip: Flags [P.], cksum 0x5907 (correct), seq 5616:6686, ack 4318, win 7904, options [nop,nop,TS val 15980696 ecr 1457495565], length 1070
E..bA.@.9.0...C.]^m$.A..W..#w.......Y......
SIP/2.0 200 OK
v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
Record-Route: 
<sip:93.94.109.36;transport=tcp;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0;n
at=yes>
Record-Route: 
<sip:93.94.109.36:5061;transport=tls;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzX
rU0;nat=yes>
i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
f: "disple" <sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
t: <sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
CSeq: 18021 INVITE
m: <sip:koen@188.189.67.183:61249;transport=TCP;ob>
k: replaces, 100rel, timer, norefersub
x: 1800;refresher=uac
Require: timer
c: application/sdp
l:   273

v=0
o=- 3569587799 3569587800 IN IP4 188.189.67.183
s=pjmedia
c=IN IP4 188.189.67.183
t=0 0
m=audio 24364 RTP/AVP 18 101
c=IN IP4 188.189.67.183
a=rtcp:61229 IN IP4 188.189.67.183
a=sendrecv
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

Chose bizarre, je ne vois pas le CODEC2 dans la réponse, bien qu'il soit 
installé, et que j'arrive bien à entendre l'audio venant du client, moi.

Aurais-tu une idée de ce qui se passe? Nous avons également essayé en TLS, 
nous disant que de cette façon là, un ALG SIP ne pourrait ré-écrire quoi 
que ce soit dans les messages, vu qu'ils sont illisibles, mais sans aucun 
succès.

Bien à toi,

Denis Braet

Original comment by denis.br...@gmail.com on 11 Feb 2013 at 6:53

GoogleCodeExporter commented 9 years ago 
Les logs CSipSimple appartenant au message précédent - il était trop long 
pour poster en une fois:

--------- beginning of /dev/log/main
D/libpjsip(14784): 17:09:44.292  evsub0x2b26f4  .....Subscription state changed 
ACCEPTED --> ACTIVE
D/libpjsip(14784): 17:09:44.293   pjsua_pres.c  ......MWI subscription for koen 
<sip:koen@firstserved.net> is ACTIVE
D/libpjsip(14784): 17:09:48.506 stuntsx0x2b3cc !STUN timeout waiting for 
response
D/libpjsip(14784): 17:09:48.591 stuntsx0x2b44b  STUN timeout waiting for 
response
D/SIP UA Receiver(14784): NAT TYPE DETECTED !!!Symmetric et 0
D/libpjsip(14784): 17:09:59.177   pjsua_core.c !.RX 1149 bytes Request msg 
INVITE/cseq=18021 (rdata0x2bbe94) from tcp 93.94.109.36:5060:
D/libpjsip(14784): INVITE sip:koen@188.189.67.183:61249;transport=TCP;ob SIP/2.0
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36;transport=tcp;r2=on;lr=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU
0;nat=yes>
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36:5061;transport=tls;r2=on;lr=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3
zzXrU0;nat=yes>
D/libpjsip(14784): Via: SIP/2.0/TCP 
93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;received=109.20.3.91;rport=38512;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
D/libpjsip(14784): Max-Forwards: 69
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: <sip:koen@firstserved.net>
D/libpjsip(14784): m: <sip:denis@109.20.3.91:38512;transport=TLS;ob>
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): CSeq: 18021 INVITE
D/libpjsip(14784): k: replaces, 100rel, timer, norefersub
D/libpjsip(14784): x: 1800
D/libpjsip(14784): Min-SE: 90
D/libpjsip(14784): User-Agent: CSipSimple_GT-I9100-15/r1916
D/libpjsip(14784): c: application/sdp
D/libpjsip(14784): l:   296
D/libpjsip(14784): P-hint: branch [1]
D/libpjsip(14784): 
D/libpjsip(14784): v=0
D/libpjsip(14784): o=- 3569587812 3569587812 IN IP4 93.94.109.36
D/libpjsip(14784): 17:09:59.177   pjsua_call.c  .Incoming Request msg 
INVITE/cseq=18021 (rdata0x2bbe94)
D/libpjsip(14784): 17:09:59.178  pjsua_media.c  ..Call 0: initializing media..
D/libpjsip(14784): 17:09:59.554  pjsua_media.c  ...Note: STUN mapped RTCP port 
61229 is not adjacent to RTP port 24364
D/libpjsip(14784): 17:09:59.555  pjsua_media.c  ...RTP socket reachable at 
188.189.67.183:24364
D/libpjsip(14784): 17:09:59.555  pjsua_media.c  ...RTCP socket reachable at 
188.189.67.183:61229
D/libpjsip(14784): 17:09:59.555  pjsua_media.c  ...Media index 0 selected for 
audio call 0
D/libpjsip(14784): 17:09:59.557   pjsua_core.c  .....TX 609 bytes Response msg 
100/INVITE/cseq=18021 (tdta0x2c3448) to tcp 93.94.109.36:5060:
D/libpjsip(14784): SIP/2.0 100 Trying
D/libpjsip(14784): v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36;transport=tcp;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0;n
at=yes>
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36:5061;transport=tls;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzX
rU0;nat=yes>
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: <sip:koen@firstserved.net>
D/libpjsip(14784): CSeq: 18021 INVITE
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
D/libpjsip(14784): 17:09:59.714   pjsua_call.c  ..Answering call 0: code=180
D/libpjsip(14784): 17:09:59.719   pjsua_core.c  ......TX 700 bytes Response msg 
180/INVITE/cseq=18021 (tdta0x2c3448) to tcp 93.94.109.36:5060:
D/libpjsip(14784): SIP/2.0 180 Ringing
D/libpjsip(14784): v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36;transport=tcp;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0;n
at=yes>
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36:5061;transport=tls;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzX
rU0;nat=yes>
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): CSeq: 18021 INVITE
D/libpjsip(14784): m: <sip:koen@188.189.67.183:61249;transport=TCP;ob>
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
I/libpjsip(14784): 17:09:59.720 pjsua_jni_addo  .........Call 0 state changed 
to EARLY (180 Ringing)
I/libpjsip(14784): 17:09:59.724 pjsua_jni_addo  .........Get call secure info...
E/AudioPolicyManagerBase(  118): unknown stream type
D/libpjsip(14784): 17:10:01.871   pjsua_call.c !Answering call 0: code=200
D/libpjsip(14784): 17:10:01.871  pjsua_media.c  ...Call 0: updating media..
D/libpjsip(14784): 17:10:01.871    pjsua_aud.c  ....Audio channel update..
D/libpjsip(14784): 17:10:01.871   strm0x352d3c  .....Encoder stream started
D/libpjsip(14784): 17:10:01.871   strm0x352d3c  .....Decoder stream started
D/libpjsip(14784): 17:10:01.871  pjsua_media.c  ....Audio updated, stream #0: 
G729 (sendrecv)
E/AudioPolicyManagerBase(  118): unknown stream type
I/libpjsip(14784): 17:10:01.881 pjsua_jni_addo  ...Get call secure info...
D/libpjsip(14784): 17:10:01.881 pjsua_jni_addo  ...Get secure for media type 1
D/libpjsip(14784): 17:10:01.882    pjsua_aud.c  ...Conf connect: 2 --> 0
D/libpjsip(14784): 17:10:01.882    pjsua_aud.c  ....Set sound device: 
capture=-1, playback=-2
D/libpjsip(14784): 17:10:01.882 android_jni_de  .....Default params
D/libpjsip(14784): 17:10:01.882    pjsua_aud.c  .....Opening sound device 
PCM@8000/1/20ms
D/libpjsip(14784): 17:10:01.883 android_jni_de  ......Creating stream
I/libpjsip(14784): 17:10:01.883 android_jni_de  ......Create stream : 8000 
samples/sec, 160 samples/frame, 2 bytes/sample
I/libpjsip(14784): 17:10:01.883 android_jni_de  ......Sample format is : 2 for 
16 
E/AudioPolicyManagerBase(  118): unknown stream type
I/libpjsip(14784): 17:10:02.053 android_jni_de  ......We have the class
I/libpjsip(14784): 17:10:02.053 android_jni_de  ......We have the buffer method
I/libpjsip(14784): 17:10:02.053 android_jni_de  ......Min record buffer 6144
I/libpjsip(14784): 17:10:02.055 android_jni_de  ......We have the track class
I/libpjsip(14784): 17:10:02.055 android_jni_de  ......We have the buffer method
I/libpjsip(14784): 17:10:02.055 android_jni_de  ......Min play buffer 4096
I/libpjsip(14784): 17:10:02.055 android_jni_de  ......Min buffer 6144
I/libpjsip(14784): 17:10:02.063 android_jni_de  ......Use micro source : 7
I/libpjsip(14784): 17:10:02.065 android_jni_de  ......We have capture the 
instance done
I/libpjsip(14784): 17:10:02.067 android_jni_de  ......We have the track 
instance done
D/libpjsip(14784): 17:10:02.067 android_jni_de  ......Starting Android stream 
stream..
D/libpjsip(14784): 17:10:02.067 android_jni_de  ......Starting done
D/libpjsip(14784): 17:10:02.067 android_jni_de  ......Get stream params
D/libpjsip(14784): 17:10:02.067 android_jni_de  ......Get stream params
D/libpjsip(14784): 17:10:02.067   conference.c  ....Port 2 
(sip:denis@firstserved.net) transmitting to port 0 (Android Audio)
D/libpjsip(14784): 17:10:02.067    pjsua_aud.c  ...Conf connect: 0 --> 2
D/libpjsip(14784): 17:10:02.067   conference.c  ....Port 0 (Android Audio) 
transmitting to port 2 (sip:denis@firstserved.net)
I/libpjsip(14784): 17:10:02.079 android_jni_de !<< Enter player thread
D/libpjsip(14784): 17:10:02.082 android_jni_de  We have the class for process
D/libpjsip(14784): 17:10:02.083 android_jni_de  We have the method for 
setThreadPriority
I/libpjsip(14784): 17:10:02.083 android_jni_de !<< Enter recorder thread
D/libpjsip(14784): 17:10:02.084 android_jni_de  We have the class for process
D/libpjsip(14784): 17:10:02.085 android_jni_de  We have the method for 
setThreadPriority
D/libpjsip(14784): 17:10:02.109   Master/sound  Underflow, buf_cnt=0, will 
generate 1 frame
E/kernel  (  125): [160112.784057] [audpreproc.c:audpreproc_dsp_event] Unknown 
Event 65535
E/kernel  (  125): [160112.785156] [audio_pcm_in.c:audrec_dsp_event] Unknown 
Event id 65535
D/libpjsip(14784): 17:10:02.122   pjsua_core.c !....TX 1070 bytes Response msg 
200/INVITE/cseq=18021 (tdta0x2c3448) to tcp 93.94.109.36:5060:
D/libpjsip(14784): SIP/2.0 200 OK
D/libpjsip(14784): v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36;transport=tcp;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0;n
at=yes>
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36:5061;transport=tls;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzX
rU0;nat=yes>
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): CSeq: 18021 INVITE
D/libpjsip(14784): m: <sip:koen@188.189.67.183:61249;transport=TCP;ob>
D/libpjsip(14784): k: replaces, 100rel, timer, norefersub
D/libpjsip(14784): x: 1800;refresher=uac
D/libpjsip(14784): Require: timer
D/libpjsip(14784): c: application/sdp
D/libpjsip(14784): l:   273
D/libpjsip(14784): 
D/libpjsip(14784): v=0
D/libpjsip(14784): o=- 3569587799 3569587800 IN IP4 188.189.67.183
D/libpjsip(14784): s=pjmedia
D/libpjsip(14784): c=IN IP4 188.189.67.183
D/libpjsip(14784): t=0 0
D/libpjsip(14784): m=audi
D/libpjsip(14784): 17:10:02.126   Master/sound  Underflow, buf_cnt=0, will 
generate 1 frame
I/libpjsip(14784): 17:10:02.133 pjsua_jni_addo !.......Call 0 state changed to 
CONNECTING
I/libpjsip(14784): 17:10:02.139 pjsua_jni_addo  .......Get call secure info...
D/libpjsip(14784): 17:10:02.139 pjsua_jni_addo  .......Get secure for media 
type 1
D/libpjsip(14784): 17:10:02.150   Master/sound !Underflow, buf_cnt=0, will 
generate 1 frame
D/libpjsip(14784): 17:10:02.637   pjsua_core.c !.TX 1070 bytes Response msg 
200/INVITE/cseq=18021 (tdta0x2c3448) to tcp 93.94.109.36:5060:
D/libpjsip(14784): SIP/2.0 200 OK
D/libpjsip(14784): v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK91b3.881d8005.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjIUTDd3AKpVB.
8O3paaHE-qJfCW3SzRSH
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36;transport=tcp;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0;n
at=yes>
D/libpjsip(14784): Record-Route: 
<sip:93.94.109.36:5061;transport=tls;lr;r2=on;ftag=oMKTGNINfNkTtswEzYYsmYDSp3zzX
rU0;nat=yes>
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): CSeq: 18021 INVITE
D/libpjsip(14784): m: <sip:koen@188.189.67.183:61249;transport=TCP;ob>
D/libpjsip(14784): k: replaces, 100rel, timer, norefersub
D/libpjsip(14784): x: 1800;refresher=uac
D/libpjsip(14784): Require: timer
D/libpjsip(14784): c: application/sdp
D/libpjsip(14784): l:   273
D/libpjsip(14784): 
D/libpjsip(14784): v=0
D/libpjsip(14784): o=- 3569587799 3569587800 IN IP4 188.189.67.183
D/libpjsip(14784): s=pjmedia
D/libpjsip(14784): c=IN IP4 188.189.67.183
D/libpjsip(14784): t=0 0
D/libpjsip(14784): m=audio 2
D/libpjsip(14784): 17:10:03.056   pjsua_core.c !.RX 464 bytes Request msg 
ACK/cseq=18021 (rdata0x2bbe94) from tcp 93.94.109.36:5060:
D/libpjsip(14784): ACK sip:koen@188.189.67.183:61249;transport=TCP;ob SIP/2.0
D/libpjsip(14784): Via: SIP/2.0/TCP 93.94.109.36;branch=z9hG4bKcydzigwkX;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;received=109.20.3.91;rport=38512;branch=z9hG4bKPjZoyCzEnmqhwA
9eTkDHhAJG8H4HQtcDM8
D/libpjsip(14784): Max-Forwards: 69
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): CSeq: 18021 ACK
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
I/libpjsip(14784): 17:10:03.062 pjsua_jni_addo  ...Call 0 state changed to 
CONFIRMED
I/libpjsip(14784): 17:10:03.067 pjsua_jni_addo  ...Get call secure info...
D/libpjsip(14784): 17:10:03.067 pjsua_jni_addo  ...Get secure for media type 1
D/Timer wrap(14784): Treat 3
D/libpjsip(14784): 17:10:03.736   pjsua_core.c  .RX 464 bytes Request msg 
ACK/cseq=18021 (rdata0x2bbe94) from tcp 93.94.109.36:5060:
D/libpjsip(14784): ACK sip:koen@188.189.67.183:61249;transport=TCP;ob SIP/2.0
D/libpjsip(14784): Via: SIP/2.0/TCP 93.94.109.36;branch=z9hG4bKcydzigwkX;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;received=109.20.3.91;rport=38512;branch=z9hG4bKPjZoyCzEnmqhwA
9eTkDHhAJG8H4HQtcDM8
D/libpjsip(14784): Max-Forwards: 69
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): CSeq: 18021 ACK
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
D/libpjsip(14784): 17:10:09.737   pjsua_core.c  .RX 512 bytes Request msg 
BYE/cseq=18022 (rdata0x2bbe94) from tcp 93.94.109.36:5060:
D/libpjsip(14784): BYE sip:koen@188.189.67.183:61249;transport=TCP;ob SIP/2.0
D/libpjsip(14784): Via: SIP/2.0/TCP 
93.94.109.36;branch=z9hG4bK61b3.42e06ab3.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;received=109.20.3.91;rport=38512;branch=z9hG4bKPjol0.OuxNVdk-
xTPTMcYBq7tEebmDwz5p
D/libpjsip(14784): Max-Forwards: 69
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): CSeq: 18022 BYE
D/libpjsip(14784): User-Agent: CSipSimple_GT-I9100-15/r1916
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
D/libpjsip(14784): 17:10:09.738   pjsua_core.c  .......TX 428 bytes Response 
msg 200/BYE/cseq=18022 (tdta0x2c51a8) to tcp 93.94.109.36:5060:
D/libpjsip(14784): SIP/2.0 200 OK
D/libpjsip(14784): v: SIP/2.0/TCP 
93.94.109.36;received=93.94.109.36;branch=z9hG4bK61b3.42e06ab3.0;i=e1
D/libpjsip(14784): v: SIP/2.0/TLS 
192.168.1.55:38512;rport=38512;received=109.20.3.91;branch=z9hG4bKPjol0.OuxNVdk-
xTPTMcYBq7tEebmDwz5p
D/libpjsip(14784): i: -nGwirchXTqEobxZpt4Ot3MWAH9CMFyn
D/libpjsip(14784): f: "disple" 
<sip:denis@firstserved.net>;tag=oMKTGNINfNkTtswEzYYsmYDSp3zzXrU0
D/libpjsip(14784): t: 
<sip:koen@firstserved.net>;tag=QXzD8TsJKLzIbKBWYpNZu6K.6Ur.lqrZ
D/libpjsip(14784): CSeq: 18022 BYE
D/libpjsip(14784): l:  0
D/libpjsip(14784): 
D/libpjsip(14784): 
D/libpjsip(14784): --end msg--
I/libpjsip(14784): 17:10:09.754 pjsua_jni_addo  ......Call 0 is DISCONNECTED 
[reason=200 (Normal call clearing)]
I/libpjsip(14784): 17:10:09.793 pjsua_jni_addo  ......Get call secure info...
D/libpjsip(14784): 17:10:09.793 pjsua_jni_addo  ......Get secure for media type 
1
D/libpjsip(14784): 17:10:09.881  pjsua_media.c  ......Call 0: deinitializing 
media..
D/libpjsip(14784): 17:10:09.895  pjsua_media.c  ........Media stream call00:0 
is destroyed
D/libpjsip(14784): 17:10:10.902    pjsua_aud.c !Closing sound device after idle 
for 1 second(s)
D/libpjsip(14784): 17:10:10.902 android_jni_de  .Get stream params
D/libpjsip(14784): 17:10:10.902    pjsua_aud.c  .Closing Android Audio sound 
playback device and Android Audio sound capture device
I/libpjsip(14784): 17:10:10.902 android_jni_de  .Stopping stream
I/libpjsip(14784): 17:10:10.911 android_jni_de !>> Record thread stopped
I/libpjsip(14784): 17:10:10.915 android_jni_de !>> Play thread stopped
E/AudioPolicyManagerBase(  118): unknown stream type
D/libpjsip(14784): 17:10:11.007 android_jni_de !.Stopping Done
D/libpjsip(14784): 17:10:11.007 android_jni_de  .Destroying stream
W/libpjsip(14784): 17:10:11.007 android_jni_de  .Already stopped.... nothing to 
do here
I/libpjsip(14784): 17:10:11.007 android_jni_de  .---> Released recorder
I/libpjsip(14784): 17:10:11.007 android_jni_de  .---> Released track
I/libpjsip(14784): 17:10:11.007 android_jni_de  .Stream is destroyed

Original comment by denis.br...@gmail.com on 11 Feb 2013 at 6:55