Closed GoogleCodeExporter closed 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
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
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
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
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
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
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
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
Original issue reported on code.google.com by
denis.br...@gmail.com
on 8 Feb 2013 at 5:01