daemon/lrc: SIP calls fail due to impropery formated URI from lrc
Issue generated from Tuleap's migration script. Originally submitted by: Stepan Salenikovich (ssalenik)
Initially reported as possibly an ICE/STUN/pjsip problem; however the issue is that lrc passes the SIP uri without the hostname, eg: "sip:1234" instead of "sip:1234@hostname". Several other users have reported this issue.
This is a regression due to this fix in lrc, the purpose of which is to prevent leaking the ring ID via DNS:
https://gerrit-ring.savoirfairelinux.com/\#/c/3804/
User reported that SIP calls always immediately fail. The SIP account is registered and he has a STUN server configured. The config works with linphone and sflphone.
dring log
14:42:47.520 stuntp0x2630f2 !.STUN mapped address found/changed: 108.x.x.x:21137
14:42:47.521 16798201754592 .Comp 1: Binding discovery complete, srflx address is 108.x.x.x:21137
14:42:47.521 stuntp0x2622c3 .STUN mapped address found/changed: 108.x.x.x:39003
14:42:47.521 16798201754592 .Comp 2: Binding discovery complete, srflx address is 108.x.x.x:39003
14:42:47.523 stuntp0x262cff .STUN mapped address found/changed: 108.x.x.x:32024
14:42:47.523 16798201754592 .Comp 4: Binding discovery complete, srflx address is 108.x.x.x:32024
14:42:47.523 stuntp0x261782 .STUN mapped address found/changed: 108.x.x.x:17967
14:42:47.523 16798201754592 .Comp 3: Binding discovery complete, srflx address is 108.x.x.x:17967
[1461940967.523| 4999|ice\_transport.cpp:259 ] ICE initialization success
[1461940967.524| 4999|ice\_transport.cpp:320 ] ICE as master
14:42:47.524 16798201754592 .ICE session created, comp\_cnt=4, role is Controlling agent
14:42:47.524 16798201754592 .ICE nomination type set to regular
14:42:47.524 16798201754592 .Candidate 0 added: comp\_id=1, type=srflx, foundation=Sc0a8013d, addr=108.x.x.x:21137, base=192.168.1.61:51697, prio=0x6effffff (1862270975)
14:42:47.524 16798201754592 .Candidate 1 added: comp\_id=1, type=host, foundation=Hc0a8013d, addr=192.168.1.61:51697, base=192.168.1.61:51697, prio=0x64ffffff (1694498815)
14:42:47.524 16798201754592 .Candidate 2 added: comp\_id=2, type=srflx, foundation=Sc0a8013d, addr=108.x.x.x:39003, base=192.168.1.61:39426, prio=0x6efffffe (1862270974)
14:42:47.524 16798201754592 .Candidate 3 added: comp\_id=2, type=host, foundation=Hc0a8013d, addr=192.168.1.61:39426, base=192.168.1.61:39426, prio=0x64fffffe (1694498814)
14:42:47.524 16798201754592 .Candidate 4 added: comp\_id=3, type=srflx, foundation=Sc0a8013d, addr=108.x.x.x:17967, base=192.168.1.61:60836, prio=0x6efffffd (1862270973)
14:42:47.524 16798201754592 .Candidate 5 added: comp\_id=3, type=host, foundation=Hc0a8013d, addr=192.168.1.61:60836, base=192.168.1.61:60836, prio=0x64fffffd (1694498813)
14:42:47.524 16798201754592 .Candidate 6 added: comp\_id=4, type=srflx, foundation=Sc0a8013d, addr=108.x.x.x:32024, base=192.168.1.61:42707, prio=0x6efffffc (1862270972)
14:42:47.524 16798201754592 .Candidate 7 added: comp\_id=4, type=host, foundation=Hc0a8013d, addr=192.168.1.61:42707, base=192.168.1.61:42707, prio=0x64fffffc (1694498812)
[1461940967.524| 4999|ice\_transport.cpp:313 ] ICE [local] ufrag=787b0db8, pwd=4430533a
[1461940967.524| 4898|sipvoiplink.cpp:1357 ] STUN mapping of '192.168.1.61:5060'
[1461940967.570| 4898|sipvoiplink.cpp:1383 ] STUN server stun.ideasip.com replied '108.x.x.x:10030'
[1461940967.570| 4898|sipaccountbase.cpp:352 ] [Account d41616a7b6ffc1fe] Using public address 108.x.x.x
[1461940967.570| 4898|sipaccount.cpp:340 ] contact header: / -> sip:301
[1461940967.570| 4898|sip\_utils.cpp:87 ] Adding route proxy.sipthor.net
14:42:47.570 resolver.c !...Transmitting 45 bytes to NS 0 (127.0.0.1:53): DNS SRV query for \_sip.\_udp.proxy.sipthor.net: Success
[1461940967.571| 4898|sipvoiplink.cpp:821 ] [call:16798201754592209698] INVITE@0x2717a88 state changed to 1 (CALLING): cause=0, tsx@0x271e188 status 0 (Default status message)
[1461940967.571| 4898|sipvoiplink.cpp:1141 ] [INVITE:0x2717a88] tsx\_role=0, tsx\_state=1, ev\_type=5, tsx\_state\_type=2
[1461940967.571| 4898|call.cpp:144 ] [call:16798201754592209698] state change 0/1, cnx 0/2, code 0
[1461940967.571| 4898|call.cpp:163 ] [call:16798201754592209698] emit client call state change CONNECTING, code 0
[1461940967.571| 4898|manager.cpp:409 ] ----- Switch current call id to '16798201754592209698' -----
[1461940967.573| 4898|videomanager.cpp:80 ] Setting default device to Integrated Camera
14:42:47.603 \_sip.\_udp.prox DNS SRV resolution failed for \_sip.\_udp.proxy.sipthor.net: DNS "Name Error" (PJLIB\_UTIL\_EDNS\_NXDOMAIN)
14:42:47.604 \_sip.\_udp.prox DNS SRV resolution failed for \_sip.\_udp.proxy.sipthor.net, trying resolving A record for proxy.sipthor.net
14:42:47.604 resolver.c Transmitting 35 bytes to NS 0 (127.0.0.1:53): DNS A query for proxy.sipthor.net: Success
14:42:47.614 tsx0x271e188 Temporary failure in sending Request msg INVITE/cseq=5960 (tdta0x271b170), will try next server: Unsuitable transport selected (PJSIP\_ETPNOTSUITABLE)
14:42:47.614 tsx0x271e188 Temporary failure in sending Request msg INVITE/cseq=5960 (tdta0x271b170), will try next server: Unsuitable transport selected (PJSIP\_ETPNOTSUITABLE)
14:42:47.614 tsx0x271e188 Temporary failure in sending Request msg INVITE/cseq=5960 (tdta0x271b170), will try next server: Unsuitable transport selected (PJSIP\_ETPNOTSUITABLE)
[1461940967.755| 4898|sipvoiplink.cpp:1141 ] [INVITE:0x2717a88] tsx\_role=0, tsx\_state=3, ev\_type=5, tsx\_state\_type=3
[1461940967.765| 4898|sipvoiplink.cpp:1141 ] [INVITE:0x2717a88] tsx\_role=0, tsx\_state=1, ev\_type=5, tsx\_state\_type=2
[1461940967.765| 4898|sipvoiplink.cpp:1141 ] [INVITE:0x2717a88] tsx\_role=0, tsx\_state=4, ev\_type=5, tsx\_state\_type=3
[1461940967.907| 4898|sipvoiplink.cpp:1141 ] [INVITE:0x2717a88] tsx\_role=0, tsx\_state=3, ev\_type=5, tsx\_state\_type=3
[1461940967.938| 4898|sipvoiplink.cpp:821 ] [call:16798201754592209698] INVITE@0x2717a88 state changed to 6 (DISCONNCTD): cause=500, tsx@0x2725038 status 500 (Internal Server Error)
[1461940967.938| 4898|call.cpp:144 ] [call:16798201754592209698] state change 1/4, cnx 2/0, code 500
[1461940967.938| 4898|call.cpp:163 ] [call:16798201754592209698] emit client call state change FAILURE, code 500
[1461940967.938| 4898|manager.cpp:1770 ] [call:16798201754592209698] Failed
[1461940967.938| 4898|call\_factory.cpp:39 ] Removing call 16798201754592209698
[1461940967.938| 4898|call\_factory.cpp:43 ] Remaining 0 SIP call(s)
[1461940967.939| 5004|alsalayer.cpp:176 ] Alsa: Opening default
[1461940967.943| 5004|alsalayer.cpp:376 ] Buffer size range from 2048 to 8192
[1461940967.943| 5004|alsalayer.cpp:377 ] Period size range from 1024 to 1024
[1461940967.943| 5004|alsalayer.cpp:392 ] Was set period\_size = 1024
[1461940967.943| 5004|alsalayer.cpp:393 ] Was set buffer\_size = 2048
[1461940967.943| 5004|alsalayer.cpp:404 ] capture using format {2 channels, 48000Hz}
[1461940967.943| 5004|alsalayer.cpp:176 ] Alsa: Opening default
[1461940967.944| 5004|alsalayer.cpp:376 ] Buffer size range from 2048 to 8192
[1461940967.945| 5004|alsalayer.cpp:377 ] Period size range from 1024 to 1024
[1461940967.945| 5004|alsalayer.cpp:392 ] Was set period\_size = 1024
[1461940967.945| 5004|alsalayer.cpp:393 ] Was set buffer\_size = 2048
[1461940967.945| 5004|alsalayer.cpp:404 ] playback using format {2 channels, 48000Hz}
[1461940967.945| 5004|audiolayer.cpp:55 ] Hardware audio format available : {2 channels, 48000Hz}
[1461940967.945| 5004|manager.cpp:2301 ] Audio format changed: {1 channels, 16000Hz} -> {2 channels, 48000Hz}
14:42:48.327 16798201754592 ....Destroying ICE session 0x7f1900000ba8
14:42:48.327 16798201754592 .....ICE stream transport 0x2620c88 destroyed
14:42:48.327 ice\_session.c .....ICE session 0x7f1900000ba8 destroyed
[1461940968.327| 4898|call.cpp:144 ] [call:16798201754592209698] state change 4/5, cnx 0/0, code 0
[1461940968.327| 4898|call.cpp:163 ] [call:16798201754592209698] emit client call state change OVER, code 0
[1461940968.327| 4898|audiorecord.cpp:214 ] Stop recording /home/programms/sflphone/20160429-144247-sip\_301-ring.wav
[1461940968.327| 4898|manager.cpp:2567 ] Call is NULL
[1461940968.329| 4898|manager.cpp:2567 ] Call is NULL
[1461940972.975| 4898|manager.cpp:548 ] Could not hang up non-existant call 16798201754592209698