Discussion:
[Freeswitch-users] INVITE and hangup in the middle of a call
Oleg Stolyar
2015-05-20 02:01:10 UTC
Permalink
Hi guys,

Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.

The call uses WebRTC and is originated by JsSip from Chrome. Then the user
is put into a conference but I doubt it's relevant in this case since the
INVITE and disconnect are not happening from mod_conference

I suspect it's a re-INVITE but what triggers FS to send it? I couldn't
find anything in the logs that could shed light.

send 1625 bytes to wss/[##.##.##.##]:50292 at 00:00:19.702933:
------------------------------------------------------------------------
INVITE sip:***@u40rf5qikah5.invalid;transport=ws;ob SIP/2.0
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
To: "user1" <sip:***@anonymous.invalid>;tag=v1rlqab64i
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
Contact: <sip:answer-c4e14a20-fe82-11e4-95ed-22000b358f22@
##.##.###.###:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825

v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
switch_core_session.c:1061 Send signal
sofia/leia_agent/***@anonymous.invalid [BREAK]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
sofia.c:6627 Channel sofia/leia_agent/***@anonymous.invalid entering
state [calling][0]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
sofia/leia_agent/***@anonymous.invalid [BREAK]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
sofia/leia_agent/***@anonymous.invalid [BREAK]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
sofia.c:6627 Channel sofia/leia_agent/***@anonymous.invalid entering
state [terminating][503]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [NOTICE]
sofia.c:7543 Hangup sofia/leia_agent/***@anonymous.invalid
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_channel.c:3242 Send signal
sofia/leia_agent/***@anonymous.invalid [KILL]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1396 Send signal
sofia/leia_agent/***@anonymous.invalid [BREAK]
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
mod_conference.c:5057 Channel leaving conference, cause:
NORMAL_TEMPORARY_FAILURE
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
mod_conference.c:9650 sofia/leia_agent/***@anonymous.invalid skip
receive message [UNBRIDGE] (channel is hungup already)
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_media.c:7772 sofia/leia_agent/***@anonymous.invalid skip
receive message [REFER_EVENT] (channel is hungup already)
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_codec.c:246 sofia/leia_agent/***@anonymous.invalid
Restore previous codec G722:9.
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_session.c:2901 sofia/leia_agent/***@anonymous.invalid
skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:535
(sofia/leia_agent/***@anonymous.invalid) State EXECUTE going to sleep
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:472
(sofia/leia_agent/***@anonymous.invalid) Running State Change
CS_HANGUP
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:735
(sofia/leia_agent/***@anonymous.invalid) Callstate Change ACTIVE ->
HANGUP
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
(sofia/leia_agent/***@anonymous.invalid) State HANGUP
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
mod_sofia.c:413 Channel sofia/leia_agent/***@anonymous.invalid
hanging up, cause: NORMAL_TEMPORARY_FAILURE
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:60 sofia/leia_agent/***@anonymous.invalid
Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
(sofia/leia_agent/***@anonymous.invalid) State HANGUP going to sleep
Michael Jerris
2015-05-20 03:05:11 UTC
Permalink
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is sending an INVITE to the other side in the middle of a call, the other side does not respond and FS hangs up the leg. Below is the relevant log. The user experience is that they keep talking and hearing each other up to the very end. I have a recording of that call, so can confirm.
The call uses WebRTC and is originated by JsSip from Chrome. Then the user is put into a conference but I doubt it's relevant in this case since the INVITE and disconnect are not happening from mod_conference
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256 E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host generation 0
------------------------------------------------------------------------
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG] mod_conference.c:5057 Channel leaving conference, cause: NORMAL_TEMPORARY_FAILURE
_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
***@freeswitch.org
http://www.freeswitchsolutions.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com

FreeSWITCH-users mailing list
FreeSWITCH-***@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-20 03:41:28 UTC
Permalink
Thanks Michael, I'll see if we can do that!

So, is the re-INVITE legit and the problem is that JsSip does not respond
to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then the
user is put into a conference but I doubt it's relevant in this case since
the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't
find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [NOTICE]
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:735
HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Joshua Gigg
2015-05-20 06:15:18 UTC
Permalink
The session expires?
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not respond
to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then the
user is put into a conference but I doubt it's relevant in this case since
the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't
find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:735
-> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Michael Jerris
2015-05-20 06:40:56 UTC
Permalink
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not respond
to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then the
user is put into a conference but I doubt it's relevant in this case since
the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't
find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858 [DEBUG]
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874 [DEBUG]
switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:735
-> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG]
switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-20 14:40:17 UTC
Permalink
This post might be inappropriate. Click to display it.
Oleg Stolyar
2015-05-20 22:44:36 UTC
Permalink
I looked at my logs more carefully and noticed that FS sends such
re-INVITES for many of my calls but not all. It is always sent about one
minute after the call is established, so it's probably not based on session
timer, right?

In most cases when it's sent JsSip answers with a 100 Trying. In this case
the call stays on. In some rare cases JsSip does not respond and FS
disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.


I will investigate why JsSip sometimes does not respond but I would still
like to figure out why FS is sending those re-INVITES to begin with?

I thought it could be happening if JsSip does not respond to OK with an ACK
but that's not the case. The ACK is there for these calls.

There is a variable nonce-ttl in the sip profile that defaults to 60
seconds. Perhaps it has something to do with that? This profile does not
require authentication or registration at all, though.
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
-> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Michael Jerris
2015-05-21 03:19:11 UTC
Permalink
See my previous suggestion earlier in this thread
Post by Oleg Stolyar
I looked at my logs more carefully and noticed that FS sends such
re-INVITES for many of my calls but not all. It is always sent about one
minute after the call is established, so it's probably not based on session
timer, right?
In most cases when it's sent JsSip answers with a 100 Trying. In this
case the call stays on. In some rare cases JsSip does not respond and FS
disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.
I will investigate why JsSip sometimes does not respond but I would still
like to figure out why FS is sending those re-INVITES to begin with?
I thought it could be happening if JsSip does not respond to OK with an
ACK but that's not the case. The ACK is there for these calls.
There is a variable nonce-ttl in the sip profile that defaults to 60
seconds. Perhaps it has something to do with that? This profile does not
require authentication or registration at all, though.
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS
is sending an INVITE to the other side in the middle of a call, the other
side does not respond and FS hangs up the leg. Below is the relevant log.
The user experience is that they keep talking and hearing each other up to
the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-21 14:44:07 UTC
Permalink
The suggestion about switching to SIP.JS? We are considering this but it
will take a us a while to get it done and ready for production. In the
meantime I was able to enable debugging on JsSip and it seems that we get
this error when receiving re-INVITE from FS:
rtcninja:ERROR:RTCPeerConnection setLocalDescription() | error: +0ms Failed
to set local answer sdp: Session error code: ERROR_CONTENT. Session error
description: Failed to set audio receive codecs..

It seems that FS is not including codecs info in re-INVITES. JsSip
developers are saying that all invites including re-invites should include
all the info. What do you think?
Post by Michael Jerris
See my previous suggestion earlier in this thread
Post by Oleg Stolyar
I looked at my logs more carefully and noticed that FS sends such
re-INVITES for many of my calls but not all. It is always sent about one
minute after the call is established, so it's probably not based on session
timer, right?
In most cases when it's sent JsSip answers with a 100 Trying. In this
case the call stays on. In some rare cases JsSip does not respond and FS
disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.
I will investigate why JsSip sometimes does not respond but I would still
like to figure out why FS is sending those re-INVITES to begin with?
I thought it could be happening if JsSip does not respond to OK with an
ACK but that's not the case. The ACK is there for these calls.
There is a variable nonce-ttl in the sip profile that defaults to 60
seconds. Perhaps it has something to do with that? This profile does not
require authentication or registration at all, though.
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS
is sending an INVITE to the other side in the middle of a call, the other
side does not respond and FS hangs up the leg. Below is the relevant log.
The user experience is that they keep talking and hearing each other up to
the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ
host generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Michael Jerris
2015-05-21 14:50:53 UTC
Permalink
I think its incredibly easy to switch to sip.js as its pretty close API to jssip, and looking at the invite you posted, it does have a full sdp. jssip has been mostly abandoned for many months (maybe they came back, but it has serious bitrot either way), its not worth the time to mess with something we know is broken when there is an easy alternative we know works.
rtcninja:ERROR:RTCPeerConnection setLocalDescription() | error: +0ms Failed to set local answer sdp: Session error code: ERROR_CONTENT. Session error description: Failed to set audio receive codecs..
It seems that FS is not including codecs info in re-INVITES. JsSip developers are saying that all invites including re-invites should include all the info. What do you think?
See my previous suggestion earlier in this thread
I looked at my logs more carefully and noticed that FS sends such re-INVITES for many of my calls but not all. It is always sent about one minute after the call is established, so it's probably not based on session timer, right?
In most cases when it's sent JsSip answers with a 100 Trying. In this case the call stays on. In some rare cases JsSip does not respond and FS disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.
I will investigate why JsSip sometimes does not respond but I would still like to figure out why FS is sending those re-INVITES to begin with?
I thought it could be happening if JsSip does not respond to OK with an ACK but that's not the case. The ACK is there for these calls.
There is a variable nonce-ttl in the sip profile that defaults to 60 seconds. Perhaps it has something to do with that? This profile does not require authentication or registration at all, though.
But isn't that based on the session-timeout param which defaults to 30 min? My re-invites occur much sooner than 30 min into a call. Or does session-timeout param only control sessions initiated by FS while incoming sessions use the minimum-session-expires param if it's not explicitly passed by the session initiator?
session timer
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not respond to it? Still, I am curious what is triggering the re-INVITE.
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is sending an INVITE to the other side in the middle of a call, the other side does not respond and FS hangs up the leg. Below is the relevant log. The user experience is that they keep talking and hearing each other up to the very end. I have a recording of that call, so can confirm.
The call uses WebRTC and is originated by JsSip from Chrome. Then the user is put into a conference but I doubt it's relevant in this case since the INVITE and disconnect are not happening from mod_conference
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256 E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host generation 0
------------------------------------------------------------------------
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG] mod_conference.c:5057 Channel leaving conference, cause: NORMAL_TEMPORARY_FAILURE
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-21 14:59:20 UTC
Permalink
Thanks Michael!

There are some internal reasons why it's not trivial for us to switch to
sip.js but as I said we'll be looking into that as well.
On a side note, JsSip did come back - they are actively releasing new
versions.

Also, I have a question about best practices. If a client originates a
call to FS, do you think it's better to have the client be the session
refresher or FS? Any reason one way or another?
Post by Michael Jerris
I think its incredibly easy to switch to sip.js as its pretty close API to
jssip, and looking at the invite you posted, it does have a full sdp.
jssip has been mostly abandoned for many months (maybe they came back, but
it has serious bitrot either way), its not worth the time to mess with
something we know is broken when there is an easy alternative we know works.
The suggestion about switching to SIP.JS? We are considering this but it
will take a us a while to get it done and ready for production. In the
meantime I was able to enable debugging on JsSip and it seems that we get
rtcninja:ERROR:RTCPeerConnection setLocalDescription() | error: +0ms
Failed to set local answer sdp: Session error code: ERROR_CONTENT. Session
error description: Failed to set audio receive codecs..
It seems that FS is not including codecs info in re-INVITES. JsSip
developers are saying that all invites including re-invites should include
all the info. What do you think?
Post by Michael Jerris
See my previous suggestion earlier in this thread
Post by Oleg Stolyar
I looked at my logs more carefully and noticed that FS sends such
re-INVITES for many of my calls but not all. It is always sent about one
minute after the call is established, so it's probably not based on session
timer, right?
In most cases when it's sent JsSip answers with a 100 Trying. In this
case the call stays on. In some rare cases JsSip does not respond and FS
disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.
I will investigate why JsSip sometimes does not respond but I would
still like to figure out why FS is sending those re-INVITES to begin with?
I thought it could be happening if JsSip does not respond to OK with an
ACK but that's not the case. The ACK is there for these calls.
There is a variable nonce-ttl in the sip profile that defaults to 60
seconds. Perhaps it has something to do with that? This profile does not
require authentication or registration at all, though.
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip.
I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS
is sending an INVITE to the other side in the middle of a call, the other
side does not respond and FS hangs up the leg. Below is the relevant log.
The user experience is that they keep talking and hearing each other up to
the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
SIP/2.0
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
From: <
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
Contact: <
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO,
UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ
host generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] sofia.c:6627 Channel
[calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] sofia.c:6627 Channel
[terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[NOTICE] sofia.c:7543 Hangup
[NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] mod_conference.c:9650
[UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_codec.c:246
G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535 (
to sleep
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472 (
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735 (
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737 (
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] mod_sofia.c:413 Channel
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737 (
sleep
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-21 19:19:11 UTC
Permalink
Hi Michael,

I followed your suggestion and tested the same call using sip.js. You are
right sip.js does not disconnect the call after receiving the re-invite.
However, it does send back the message below. I agree that it's a more
graceful way to handle the problem but the original problem on both JsSip
and SIP.JS is still that there is something wrong with the re-INVITE
message from FS.
By the way a side effect of this is that FS does not send any more
re-invites for this session after that first attempt.

I'll be happy to run any other tests that could help fix this. For now I
will either switch to sip.js or use JsSip's new session timer capability
which makes JsSip send regular update messages, so FS does not need to send
re-invites at all.


------------------------------------------------------------------------
recv 379 bytes from wss/[69.53.236.236]:17084 at 19:11:35.832686:
------------------------------------------------------------------------
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/WSS ##.##.##.##:5067;branch=z9hG4bK9rtFZNj1vK09D
To: <sip:***@something.com>;tag=c6tjtcraq7
From: <sip:echo-***@something.com>;tag=c29e7F87NvQNp
Call-ID: 1v8ll5j5dcqj1d2fimo1
CSeq: 75781683 INVITE
Warning: 399 sipjs "Cannot update media description"
Supported: outbound
User-Agent: SIP.js/0.7.0
Content-Length: 0
Post by Oleg Stolyar
Thanks Michael!
There are some internal reasons why it's not trivial for us to switch to
sip.js but as I said we'll be looking into that as well.
On a side note, JsSip did come back - they are actively releasing new
versions.
Also, I have a question about best practices. If a client originates a
call to FS, do you think it's better to have the client be the session
refresher or FS? Any reason one way or another?
Post by Michael Jerris
I think its incredibly easy to switch to sip.js as its pretty close API
to jssip, and looking at the invite you posted, it does have a full sdp.
jssip has been mostly abandoned for many months (maybe they came back, but
it has serious bitrot either way), its not worth the time to mess with
something we know is broken when there is an easy alternative we know works.
The suggestion about switching to SIP.JS? We are considering this but it
will take a us a while to get it done and ready for production. In the
meantime I was able to enable debugging on JsSip and it seems that we get
rtcninja:ERROR:RTCPeerConnection setLocalDescription() | error: +0ms
Failed to set local answer sdp: Session error code: ERROR_CONTENT. Session
error description: Failed to set audio receive codecs..
It seems that FS is not including codecs info in re-INVITES. JsSip
developers are saying that all invites including re-invites should include
all the info. What do you think?
Post by Michael Jerris
See my previous suggestion earlier in this thread
Post by Oleg Stolyar
I looked at my logs more carefully and noticed that FS sends such
re-INVITES for many of my calls but not all. It is always sent about one
minute after the call is established, so it's probably not based on session
timer, right?
In most cases when it's sent JsSip answers with a 100 Trying. In this
case the call stays on. In some rare cases JsSip does not respond and FS
disconnects the call with NORMAL_TEMPORARY_FAILURE we see in the log above.
I will investigate why JsSip sometimes does not respond but I would
still like to figure out why FS is sending those re-INVITES to begin with?
I thought it could be happening if JsSip does not respond to OK with an
ACK but that's not the case. The ACK is there for these calls.
There is a variable nonce-ttl in the sip profile that defaults to 60
seconds. Perhaps it has something to do with that? This profile does not
require authentication or registration at all, though.
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip.
I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where
FS is sending an INVITE to the other side in the middle of a call, the
other side does not respond and FS hangs up the leg. Below is the relevant
log. The user experience is that they keep talking and hearing each other
up to the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome.
Then the user is put into a conference but I doubt it's relevant in this
case since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
SIP/2.0
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067
;branch=z9hG4bK7Xm4tjevU45Sr
Post by Oleg Stolyar
Max-Forwards: 70
From: <
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
Contact: <
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO,
UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ
host generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] sofia.c:6627 Channel
[calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] sofia.c:6627 Channel
[terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[NOTICE] sofia.c:7543 Hangup
[NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] mod_conference.c:9650
[UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_codec.c:246
codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535 (
to sleep
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472 (
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735 (
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737 (
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] mod_sofia.c:413 Channel
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737 (
to sleep
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Steven Ayre
2015-05-25 08:51:09 UTC
Permalink
The values to actual use are negotiated during the call invite, and your
trace shows it's using 2 minutes.
Session-Expires: 120;refresher=uac
Min-SE: 120

Just as an idea because you didn't send both invite and re-invite...
perhaps the SDP body is different in the reinvite without the version
number having changed. If so it may be
https://freeswitch.org/jira/browse/FS-7040
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is
sending an INVITE to the other side in the middle of a call, the other side
does not respond and FS hangs up the leg. Below is the relevant log. The
user experience is that they keep talking and hearing each other up to the
very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
-> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-25 14:36:53 UTC
Permalink
Thanks Steven!

It may be https://freeswitch.org/jira/browse/FS-7040.

As far as the 120 sec is concerned - Below are snippets from both the
invite and the 200 OK from FS. I know that FS reads the Session-Expires
from the client because if I change it to a value less than 120, FS sends
back a "SIP/2.0 422 Session Interval Too Small". I even thought the
problem could be that the Session-Exipres format in the original INVITE is
incorrect since it does not contain ";refresher=uac" but when I added that
and made the line "Session-Expires: 300;refresher=uac" nothing changed.


INVITE sip:echo-***@anonymous.invalid SIP/2.0
Via: SIP/2.0/WSS pfcnm9rjv5en.invalid;branch=z9hG4bK8223029
Max-Forwards: 69
To: <sip:echo-***@anonymous.invalid>
From: "b3N0b2x5YXI" <sip:***@anonymous.invalid>;tag=h1059gcvb2
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
Contact: <sip:***@pfcnm9rjv5en.invalid;transport=ws;ob>
Content-Type: application/sdp
Session-Expires: 300
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: timer,ice,outbound
User-Agent: JsSIP 0.6.26
Content-Length: 2754

SIP/2.0 200 OK
Via: SIP/2.0/WSS
pfcnm9rjv5en.invalid;branch=z9hG4bK8223029;received=69.53.236.236;rport=35200
From: "b3N0b2x5YXI" <sip:***@anonymous.invalid>;tag=h1059gcvb2
To: <sip:echo-***@anonymous.invalid>;tag=SgjX0X4arHUFg
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
Contact: <sip:echo-***@50.19.255.62:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER,
REFER, NOTIFY, PUBLISH, SUBSCRIBE
Require: timer
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog,
line-seize, call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Session-Expires: 120;refresher=uac
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 809
X-Netflix: yes
;party=calling;privacy=off;screen=no
The values to actual use are negotiated during the call invite, and your
trace shows it's using 2 minutes.
Session-Expires: 120;refresher=uac
Min-SE: 120
Just as an idea because you didn't send both invite and re-invite...
perhaps the SDP body is different in the reinvite without the version
number having changed. If so it may be
https://freeswitch.org/jira/browse/FS-7040
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS
is sending an INVITE to the other side in the middle of a call, the other
side does not respond and FS hangs up the leg. Below is the relevant log.
The user experience is that they keep talking and hearing each other up to
the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host
generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Oleg Stolyar
2015-05-26 15:13:36 UTC
Permalink
Just FYI, the JsSip engineers replied to my questions with this:

The error happens because the incoming reINVITE has a=setup:active in
the SDP which is a bug in FreeSwitch (the RFC clearly states that the
Post by Oleg Stolyar
Thanks Steven!
It may be https://freeswitch.org/jira/browse/FS-7040.
As far as the 120 sec is concerned - Below are snippets from both the
invite and the 200 OK from FS. I know that FS reads the Session-Expires
from the client because if I change it to a value less than 120, FS sends
back a "SIP/2.0 422 Session Interval Too Small". I even thought the
problem could be that the Session-Exipres format in the original INVITE is
incorrect since it does not contain ";refresher=uac" but when I added that
and made the line "Session-Expires: 300;refresher=uac" nothing changed.
Via: SIP/2.0/WSS pfcnm9rjv5en.invalid;branch=z9hG4bK8223029
Max-Forwards: 69
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
Content-Type: application/sdp
Session-Expires: 300
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: timer,ice,outbound
User-Agent: JsSIP 0.6.26
Content-Length: 2754
SIP/2.0 200 OK
Via: SIP/2.0/WSS
pfcnm9rjv5en.invalid;branch=z9hG4bK8223029;received=69.53.236.236;rport=35200
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER,
REFER, NOTIFY, PUBLISH, SUBSCRIBE
Require: timer
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog,
line-seize, call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Session-Expires: 120;refresher=uac
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 809
X-Netflix: yes
;party=calling;privacy=off;screen=no
The values to actual use are negotiated during the call invite, and your
trace shows it's using 2 minutes.
Session-Expires: 120;refresher=uac
Min-SE: 120
Just as an idea because you didn't send both invite and re-invite...
perhaps the SDP body is different in the reinvite without the version
number having changed. If so it may be
https://freeswitch.org/jira/browse/FS-7040
Post by Oleg Stolyar
But isn't that based on the session-timeout param which defaults to 30
min? My re-invites occur much sooner than 30 min into a call. Or does
session-timeout param only control sessions initiated by FS while incoming
sessions use the minimum-session-expires param if it's not explicitly
passed by the session initiator?
Post by Michael Jerris
session timer
Post by Oleg Stolyar
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not
respond to it? Still, I am curious what is triggering the re-INVITE.
Post by Michael Jerris
I think the sip.js guys fixed this issue when they forked jssip. I'd
suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS
is sending an INVITE to the other side in the middle of a call, the other
side does not respond and FS hangs up the leg. Below is the relevant log.
The user experience is that they keep talking and hearing each other up to
the very end. I have a recording of that call, so can confirm.
Post by Oleg Stolyar
The call uses WebRTC and is originated by JsSip from Chrome. Then
the user is put into a conference but I doubt it's relevant in this case
since the INVITE and disconnect are not happening from mod_conference
Post by Oleg Stolyar
I suspect it's a re-INVITE but what triggers FS to send it? I
couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Post by Oleg Stolyar
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
;tag=KQecUSr12rSQp
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
##.##.###.###:5080;transport=udp>
Post by Oleg Stolyar
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Post by Oleg Stolyar
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256
E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
Post by Oleg Stolyar
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ
host generation 0
------------------------------------------------------------------------
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:19.376858
entering state [calling][0]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1061 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
entering state [terminating][503]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_channel.c:3242 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.616874
[DEBUG] switch_core_session.c:1396 Send signal
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
skip receive message [UNBRIDGE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_media.c:7772
[REFER_EVENT] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
Restore previous codec G722:9.
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_session.c:2901
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:535
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:472
CS_HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:735
ACTIVE -> HANGUP
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
hanging up, cause: NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:60
NORMAL_TEMPORARY_FAILURE
Post by Oleg Stolyar
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900
[DEBUG] switch_core_state_machine.c:737
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Michael Jerris
2015-05-26 16:07:53 UTC
Permalink
Please file a jira for us on that. Even better with a pull request to fix it.
Post by Oleg Stolyar
The error happens because the incoming reINVITE has a=setup:active in
the SDP which is a bug in FreeSwitch (the RFC clearly states that the
Thanks Steven!
It may be https://freeswitch.org/jira/browse/FS-7040 <https://freeswitch.org/jira/browse/FS-7040>.
As far as the 120 sec is concerned - Below are snippets from both the invite and the 200 OK from FS. I know that FS reads the Session-Expires from the client because if I change it to a value less than 120, FS sends back a "SIP/2.0 422 Session Interval Too Small". I even thought the problem could be that the Session-Exipres format in the original INVITE is incorrect since it does not contain ";refresher=uac" but when I added that and made the line "Session-Expires: 300;refresher=uac" nothing changed.
Via: SIP/2.0/WSS pfcnm9rjv5en.invalid;branch=z9hG4bK8223029
Max-Forwards: 69
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
Content-Type: application/sdp
Session-Expires: 300
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: timer,ice,outbound
User-Agent: JsSIP 0.6.26
Content-Length: 2754
SIP/2.0 200 OK
Via: SIP/2.0/WSS pfcnm9rjv5en.invalid;branch=z9hG4bK8223029;received=69.53.236.236;rport=35200
Call-ID: r65e48gp171p21rkppcu
CSeq: 6621 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Require: timer
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Session-Expires: 120;refresher=uac
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 809
X-Netflix: yes
The values to actual use are negotiated during the call invite, and your trace shows it's using 2 minutes.
Session-Expires: 120;refresher=uac
Min-SE: 120
Just as an idea because you didn't send both invite and re-invite... perhaps the SDP body is different in the reinvite without the version number having changed. If so it may be https://freeswitch.org/jira/browse/FS-7040 <https://freeswitch.org/jira/browse/FS-7040>
But isn't that based on the session-timeout param which defaults to 30 min? My re-invites occur much sooner than 30 min into a call. Or does session-timeout param only control sessions initiated by FS while incoming sessions use the minimum-session-expires param if it's not explicitly passed by the session initiator?
session timer
Thanks Michael, I'll see if we can do that!
So, is the re-INVITE legit and the problem is that JsSip does not respond to it? Still, I am curious what is triggering the re-INVITE.
I think the sip.js guys fixed this issue when they forked jssip. I'd suggest using that.
Post by Oleg Stolyar
Hi guys,
Several weeks ago I started getting an occasional problem where FS is sending an INVITE to the other side in the middle of a call, the other side does not respond and FS hangs up the leg. Below is the relevant log. The user experience is that they keep talking and hearing each other up to the very end. I have a recording of that call, so can confirm.
The call uses WebRTC and is originated by JsSip from Chrome. Then the user is put into a conference but I doubt it's relevant in this case since the INVITE and disconnect are not happening from mod_conference
I suspect it's a re-INVITE but what triggers FS to send it? I couldn't find anything in the logs that could shed light.
------------------------------------------------------------------------
Via: SIP/2.0/WSS 10.97.158.232:5067;branch=z9hG4bK7Xm4tjevU45Sr
Max-Forwards: 70
Call-ID: g8980rbrbk2t45oj5mru
CSeq: 75703945 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.5.15b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Session-Expires: 120;refresher=uac
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 825
v=0
o=FreeSWITCH 1432057287 1432057288 IN IP4 ##.##.##.##
s=FreeSWITCH
c=IN IP4 ##.##.##.##
t=0 0
a=msid-semantic: WMS uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
m=audio 22670 RTP/SAVPF 9 126 106
a=rtpmap:9 G722/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256 E4:E2:DD:6C:60:61:69:9D:FD:21:64:79:66:C0:14:58:DD:67:CE:29:35:35:58:65:2E:91:70:85:4C:6C:47:69
a=rtcp-mux
a=rtcp:22670 IN IP4 ##.##.##.##
a=ssrc:1029894069 cname:VL2jTPmLiyFVIEaq
a=ssrc:1029894069 msid:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW a0
a=ssrc:1029894069 mslabel:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hW
a=ssrc:1029894069 label:uZEfxiWc2Dm3Mj8pRAdC8BQDwtTzC6hWa0
a=ice-ufrag:5dS3Fzx1Thrmdy9Z
a=ice-pwd:a19UHlvPK1BjvBzrFilbII2s
a=candidate:3876535948 1 udp 659136 107.20.175.160 22670 typ host generation 0
------------------------------------------------------------------------
fc1927a8-2257-400f-b4cb-67aff7297170 2015-05-20 00:00:22.636900 [DEBUG] mod_conference.c:5057 Channel leaving conference, cause: NORMAL_TEMPORARY_FAILURE
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites
http://www.freeswitch.org <http://www.freeswitch.org/>
http://confluence.freeswitch.org <http://confluence.freeswitch.org/>
http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users>
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users>
http://www.freeswitch.org <http://www.freeswitch.org/>
_________________________________________________________________________
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
Loading...