Incoming SIP calls are dropped
Issue generated from Tuleap's migration script. Originally submitted by: Maxim Cournoyer (mcournoyer)
-
Environment:
Happens with both gnome-client and the Android client. -
Reproduce steps:
- Setup SIP account (I'm using a VoIP.ms account)
- Call the SIP account
- The call is dropped as show in the logs below (captured with the Gnome client).
-
Expected result:
The client should ring and the call be answerable. -
Actual result:
Missing all incoming SIP calls. -
Log
13:55:08.632 sip\_endpoint.c Processing incoming message: Request msg INVITE/cseq=102 (rdata0x262a9f8)
[1516128908.632|14665|sipvoiplink.cpp :646 ] username = 179835\_sfl, server = 192.175.96.70, from = 192.175.96.70
[1516128908.632|14665|sipaccount.cpp :1726 ] Matching account id in request is a fullmatch 179835\_sfl@192.175.96.70
[1516128908.633|14665|audiorecord.cpp :89 ] Generate filename for this call 20180116-135508
[1516128908.633|14665|recordable.cpp :33 ] Set recording options:
[1516128908.633|14665|ringbufferpool.cpp:115 ] Ringbuffer created with id '4105047759992942438'
[1516128908.633|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/0, cnx 0/2, code 0
[1516128908.633|14665|call.cpp :220 ] [call:4105047759992942438] emit client call state change CONNECTING, code 0
[1516128908.634|14665|audiorecord.cpp :133 ] Initialize audio record for peer : 5146299726@192.175.96.70
[1516128908.634|14665|sdp.cpp :354 ] Remote SDP Session:
v=0
o=root 849326603 849326603 IN IP4 192.175.96.70
s=voip.ms
c=IN IP4 192.175.96.70
t=0 0
m=audio 18712 RTP/AVP 0 18
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
[1516128908.634|14665|sdp.cpp :354 ] SDP: Local SDP Session:
v=0
o=pc-mcournoyer 3725117708 0 IN IP4 192.168.49.36
s=Ring Daemon
c=IN IP4 192.168.49.36
t=0 0
m=audio 25574 RTP/AVP 104 9 112 111 110 8 0 101
a=rtpmap:104 opus/48000/2
a=rtpmap:9 G722/8000
a=rtpmap:112 speex/32000
a=rtpmap:111 speex/16000
a=rtpmap:110 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtcp:25575 IN IP4 192.168.49.36
a=sendrecv
[1516128908.634|14665|sipcall.cpp :1238 ] [call:4105047759992942438] no ICE data in remote SDP
13:55:08.634 tsx0x248a5d8 ..Transaction created for Request msg INVITE/cseq=102 (rdata0x262a9f8)
13:55:08.634 tsx0x248a5d8 .Incoming Request msg INVITE/cseq=102 (rdata0x262a9f8) in state Null
13:55:08.634 tsx0x248a5d8 ..State changed from Null to Trying, event=RX\_MSG
13:55:08.634 dlg0x245aa68 ...Transaction tsx0x248a5d8 state changed to Trying
13:55:08.634 dlg0x245aa68 .UAS dialog created
13:55:08.634 dlg0x245aa68 .Module mod-invite added as dialog usage, data=0x2452768
13:55:08.634 dlg0x245aa68 ..Session count inc to 3 by mod-invite
13:55:08.634 inv0x245aa68 .UAS invite session created for dialog dlg0x245aa68
13:55:08.634 endpoint ..Response msg 100/INVITE/cseq=102 (tdta0x247ae70) created
13:55:08.634 dlg0x245aa68 ..Initial answer Response msg 100/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.634 inv0x245aa68 ..Sending Response msg 100/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.634 dlg0x245aa68 ...Sending Response msg 100/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.634 tsx0x248a5d8 ...Sending Response msg 100/INVITE/cseq=102 (tdta0x247ae70) in state Trying
13:55:08.634 tsx0x248a5d8 ....State changed from Trying to Proceeding, event=TX\_MSG
13:55:08.634 dlg0x245aa68 .....Transaction tsx0x248a5d8 state changed to Proceeding
[1516128908.634|14665|sipvoiplink.cpp :821 ] [call:4105047759992942438] INVITE@0x2452768 state changed to 2 (INCOMING): cause=0, tsx@0x248a5d8 status 100 (Trying)
[1516128908.634|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/0, cnx 2/1, code 0
[1516128908.634|14665|call.cpp :220 ] [call:4105047759992942438] emit client call state change INACTIVE, code 0
13:55:08.634 inv0x245aa68 ..Sending Response msg 180/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.634 dlg0x245aa68 ...Sending Response msg 180/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.634 tsx0x248a5d8 ...Sending Response msg 180/INVITE/cseq=102 (tdta0x247ae70) in state Proceeding
13:55:08.635 tsx0x248a5d8 ....State changed from Proceeding to Proceeding, event=TX\_MSG
13:55:08.635 dlg0x245aa68 .....Transaction tsx0x248a5d8 state changed to Proceeding
[1516128908.635|14665|sipvoiplink.cpp :821 ] [call:4105047759992942438] INVITE@0x2452768 state changed to 3 (EARLY): cause=0, tsx@0x248a5d8 status 180 (Ringing)
[1516128908.635|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/0, cnx 1/3, code 0
[1516128908.635|14665|call.cpp :220 ] [call:4105047759992942438] emit client call state change INCOMING, code 0
[1516128908.635|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/0, cnx 3/3, code 0
[1516128908.635|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/0, cnx 3/3, code 0
13:55:08.912 sip\_endpoint.c .Request msg INVITE/cseq=102 (rdata0x262a9f8) from 192.175.96.70:5060 was dropped/unhandled by any modules
13:55:08.912 tsx0x248a5d8 State changed from Proceeding to Terminated, event=TRANSPORT\_ERROR
13:55:08.912 dlg0x245aa68 Transaction tsx0x248a5d8 state changed to Terminated
[1516128908.912|14665|sipvoiplink.cpp :821 ] [call:4105047759992942438] INVITE@0x2452768 state changed to 6 (DISCONNCTD): cause=503, tsx@0x248a5d8 status 503 (Service Unavailable)
[1516128908.912|14665|call.cpp :197 ] [call:4105047759992942438] state change 0/4, cnx 3/0, code 503
[1516128908.912|14665|call.cpp :220 ] [call:4105047759992942438] emit client call state change FAILURE, code 503
[1516128908.912|14665|manager.cpp :2071 ] [call:4105047759992942438] Failed
[1516128908.912|14665|manager.cpp :1663 ] [call:4105047759992942438] Remove local audio
[1516128908.912|14665|sipcall.cpp :715 ] [call:4105047759992942438] removeCall()
[1516128908.912|14665|call\_factory.cpp :39 ] Removing call 4105047759992942438
[1516128908.912|14665|call\_factory.cpp :43 ] Remaining 0 SIP call(s)
[1516128908.912|14665|call.cpp :197 ] [call:4105047759992942438] state change 4/5, cnx 0/0, code 0
[1516128908.912|14665|call.cpp :220 ] [call:4105047759992942438] emit client call state change OVER, code 0
[1516128908.912|14665|audiorecord.cpp :220 ] Stop recording /home/mcournoyer/20180116-135508-5146299726\_192.175.96.70-ring.wav
[1516128908.912|14665|audiorecord.cpp :220 ] Stop recording /home/mcournoyer/20180116-135508-5146299726\_192.175.96.70-ring.wav
13:55:08.912 dlg0x245aa68 ..Session count dec to 1 by mod-invite
13:55:08.912 dlg0x245aa68 .Dialog destroyed
13:55:08.912 tsx0x248a5d8 Timeout timer event
13:55:08.912 tsx0x248a5d8 .State changed from Terminated to Destroyed, event=TIMER
13:55:08.912 tdta0x247ae70 ..Destroying txdata Response msg 180/INVITE/cseq=102 (tdta0x247ae70)
13:55:08.912 tsx0x248a5d8 Transaction destroyed!
[1516128908.912|14665|manager.cpp :2830 ] Call is NULL
[1516128908.913|14665|manager.cpp :2830 ] Call is NULL
[1516128908.913|14665|manager.cpp :2830 ] Call is NULL
[1516128908.939|14665|manager.cpp :2830 ] Call is NULL
[1516128908.939|14665|manager.cpp :2830 ] Call is NULL
[1516128908.940|14665|manager.cpp :2830 ] Call is NULL
[1516128908.940|14665|manager.cpp :2830 ] Call is NULL
[1516128908.940|14665|manager.cpp :2830 ] Call is NULL
[1516128908.940|14665|manager.cpp :2830 ] Call is NULL
[1516128908.941|14665|manager.cpp :2830 ] Call is NULL