[Freeswitch-users] R: Call drop on transfer (REFER) after SIP 302 MOVED
Piccinin Francesco
francesco.piccinin at insiel.it
Thu Mar 23 18:07:47 MSK 2017
Hi all,
we are experiencing a strange issue during call transfer (REFER) after a SIP 302 MOVED.
Please find below a brief description of our test environment.
Extensions involved:
- 8911 (original caller)
- 8910 (forwarded to 5536 through phone ui)
- 5536 (originator of call transfer)
- 5532 (destination of call transfer)
Step to reproduce the issue:
- 8911 calls 8910 which is forwarded on 5536 (call fwd is configured directly on phone gui)
- 5536 correctly answer the call from 8911
- 5536 begins a consult transfer to 5532: Hold step is ok but call drops when 5536 completes the transfer.
>From the SIP signaling point of view:
- 8910 answers to 8911 with a SIP MOVED.
- Freeswitch send an invite to 5536 as 8911.
- Call transfer from 5536 to 5532 is managed with a refer.
- When 5536 complete the transfer, Freeswitch send a bye first to 8911 (original caller) and then to 5536.
On Freeswitch dialplan we manage refer on a different context, setting "sip_redirect_context" variables.
Without MOVED involved, all call transfer are correctly managed.
It seems that we need to keep alive a-leg after the bridge and then perform the transfer.
We tried all the following settings on redirect context:
- set + export of variables: force_transfer_context + force_transfer_dialplan
- set + export park_after_bridge=true
- set continue_on_fail=true
- unset of sip_redirect_context
But all without success!
Please find below fscli log.
Thanks in advance for help.
Regards
Francesco
freeswitch at default>
freeswitch at default>
freeswitch at default>
freeswitch at default> sofia global siptrace on
+OK Global siptrace on
recv 1047 bytes from udp/[172.25.248.82]:5060 at 10:56:05.728805:
------------------------------------------------------------------------
INVITE sip:mod_sofia at 172.25.248.83:5060 SIP/2.0
Record-Route: <sip:172.25.248.82;lr;ftag=507421845>
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK961e.b1e68771.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK2041699543
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754016 INVITE
Contact: <sip:5536 at 172.22.27.137:5062>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 69
User-Agent: Yealink SIP-T21P 34.72.0.75
Allow-Events: talk,hold,conference,refer,check-sync
Content-Length: 308
v=0
o=- 20014 20016 IN IP4 172.22.27.137
s=SDP data
c=IN IP4 172.22.27.137
t=0 0
m=audio 11786 RTP/AVP 0 8 18 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
a=ptime:20
a=sendonly
------------------------------------------------------------------------
send 487 bytes to udp/[172.25.248.82]:5060 at 10:56:05.729233:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK961e.b1e68771.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK2041699543
Record-Route: <sip:172.25.248.82;lr;ftag=507421845>
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754016 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:05.713101 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:05.713101 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:05.733132 [DEBUG] sofia.c:5847 Channel sofia/internal/sip:5536 at 172.22.27.137:5062 entering state [received][100]
2017-03-22 11:56:05.733132 [DEBUG] sofia.c:5860 Remote SDP:
v=0
o=- 20014 20016 IN IP4 172.22.27.137
s=SDP data
c=IN IP4 172.22.27.137
t=0 0
m=audio 11786 RTP/AVP 0 8 18 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly
a=ptime:20
2017-03-22 11:56:05.733132 [DEBUG] switch_channel.c:1783 (sofia/internal/sip:5536 at 172.22.27.137:5062) Callstate Change ACTIVE -> HELD
2017-03-22 11:56:05.733132 [DEBUG] switch_core_session.c:1151 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:05.753091 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:05.873149 [DEBUG] switch_ivr.c:614 sofia/internal/8911 at insiel.fvgvoipcoll.it Command Execute playback(local_stream://moh)
EXECUTE sofia/internal/8911 at insiel.fvgvoipcoll.it playback(local_stream://moh)
2017-03-22 11:56:05.873149 [DEBUG] mod_local_stream.c:498 Opening Stream [moh/8000] 8000hz
2017-03-22 11:56:05.873149 [DEBUG] switch_ivr_play_say.c:1305 Codec Activated L16 at 8000hz 1 channels 20ms
2017-03-22 11:56:05.973127 [DEBUG] sofia_glue.c:5284 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2017-03-22 11:56:05.973127 [DEBUG] sofia_glue.c:3121 Already using PCMU
2017-03-22 11:56:05.973127 [DEBUG] sofia_glue.c:5444 Set 2833 dtmf send payload to 101
2017-03-22 11:56:05.973127 [DEBUG] sofia_glue.c:3421 Audio params are unchanged for sofia/internal/sip:5536 at 172.22.27.137:5062.
2017-03-22 11:56:05.973127 [DEBUG] sofia_glue.c:3431 sofia/internal/sip:5536 at 172.22.27.137:5062 Setting audio receive payload in Re-INVITE to 0
2017-03-22 11:56:05.973127 [DEBUG] sofia.c:6426 Processing updated SDP
send 994 bytes to udp/[172.25.248.82]:5060 at 10:56:05.984830:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK961e.b1e68771.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK2041699543
Record-Route: <sip:172.25.248.82;lr;ftag=507421845>
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754016 INVITE
Contact: <sip:mod_sofia at 172.25.248.83:5060>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 234
v=0
o=FreeSWITCH 1490161741 1490161743 IN IP4 172.25.248.83
s=FreeSWITCH
c=IN IP4 172.25.248.83
t=0 0
m=audio 18418 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=recvonly
a=ptime:20
------------------------------------------------------------------------
2017-03-22 11:56:05.973127 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:05.973127 [DEBUG] sofia.c:5847 Channel sofia/internal/sip:5536 at 172.22.27.137:5062 entering state [completed][200]
recv 530 bytes from udp/[172.25.248.82]:5060 at 10:56:06.036465:
------------------------------------------------------------------------
ACK sip:mod_sofia at 172.25.248.83:5060 SIP/2.0
Record-Route: <sip:172.25.248.82;lr;ftag=507421845>
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK961e.b1e68771.2
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK1912144644
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754016 ACK
Contact: <sip:5536 at 172.22.27.137:5062>
Max-Forwards: 69
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:06.033119 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:06.033119 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:06.033119 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:06.053107 [DEBUG] sofia.c:5847 Channel sofia/internal/sip:5536 at 172.22.27.137:5062 entering state [ready][200]
recv 622 bytes from udp/[172.25.248.82]:5060 at 10:56:10.086826:
------------------------------------------------------------------------
SUBSCRIBE sip:5536 at insiel.fvgvoipcoll.it:5060 SIP/2.0
Record-Route: <sip:172.25.248.82;lr;ftag=1995003817>
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bKcd5.bbf6e311.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK2046226047
From: "5536 Agente PN" <sip:5536 at insiel.fvgvoipcoll.it>;tag=1995003817
To: "5536 Agente PN" <sip:5536 at insiel.fvgvoipcoll.it>
Call-ID: 1353578327 at 172.22.27.137
CSeq: 1 SUBSCRIBE
Contact: <sip:5536 at 172.22.27.137:5062>
Accept: application/x-as-feature-event+xml
Max-Forwards: 69
User-Agent: Yealink SIP-T21P 34.72.0.75
Expires: 3630
Event: as-feature-event
Content-Length: 0
------------------------------------------------------------------------
send 747 bytes to udp/[172.25.248.82]:5060 at 10:56:10.087100:
------------------------------------------------------------------------
SIP/2.0 489 Bad Event
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bKcd5.bbf6e311.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK2046226047
From: "5536 Agente PN" <sip:5536 at insiel.fvgvoipcoll.it>;tag=1995003817
To: "5536 Agente PN" <sip:5536 at insiel.fvgvoipcoll.it>;tag=7p57cDp7DXNSF
Call-ID: 1353578327 at 172.22.27.137
CSeq: 1 SUBSCRIBE
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 583 bytes from udp/[172.25.248.82]:5060 at 10:56:10.938465:
------------------------------------------------------------------------
REFER sip:mod_sofia at 172.25.248.83:5060 SIP/2.0
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bKa61e.a30dbb65.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK1759603587
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754017 REFER
Contact: <sip:5536 at 172.22.27.137:5062>
Max-Forwards: 69
User-Agent: Yealink SIP-T21P 34.72.0.75
Refer-To: <sip:5532 at insiel.fvgvoipcoll.it>
Referred-By: <sip:5536 at 172.22.27.137:5062>
Event: refer
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:10.933089 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
send 790 bytes to udp/[172.25.248.82]:5060 at 10:56:10.953457:
------------------------------------------------------------------------
SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bKa61e.a30dbb65.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK1759603587
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754017 REFER
Contact: <sip:mod_sofia at 172.25.248.83:5060>
Expires: 60
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:10.953129 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.953129 [DEBUG] sofia.c:6924 Process REFER to [5532 at insiel.fvgvoipcoll.it]
send 959 bytes to udp/[172.25.248.82]:5060 at 10:56:10.953825:
------------------------------------------------------------------------
NOTIFY sip:5536 at 172.22.27.137:5062 SIP/2.0
Via: SIP/2.0/UDP 172.25.248.83;rport;branch=z9hG4bKDapFc3UKFFtcr
Route: <sip:172.25.248.82;lr;ftag=4USX7U3vp2j1c;did=51d.6c2982e6>
Max-Forwards: 70
From: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
To: <sip:5536 at 172.22.27.137:5062>;tag=507421845
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754017 NOTIFY
Contact: <sip:mod_sofia at 172.25.248.83:5060>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Event: refer;id=104754017
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Subscription-State: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Content-Length: 16
SIP/2.0 200 OK
------------------------------------------------------------------------
2017-03-22 11:56:10.953129 [DEBUG] switch_ivr.c:1834 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State Change CS_EXECUTE -> CS_ROUTING
2017-03-22 11:56:10.953129 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.953129 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.953129 [NOTICE] switch_ivr.c:1841 Transfer sofia/internal/8911 at insiel.fvgvoipcoll.it to XML[5532 at redir]
2017-03-22 11:56:10.973121 [DEBUG] switch_ivr_play_say.c:1708 done playing file local_stream://moh
2017-03-22 11:56:10.973121 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.973121 [DEBUG] switch_ivr_bridge.c:386 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.973121 [DEBUG] switch_ivr_bridge.c:645 BRIDGE THREAD DONE [sofia/internal/sip:5536 at 172.22.27.137:5062]
2017-03-22 11:56:10.973121 [DEBUG] switch_channel.c:1951 (sofia/internal/sip:5536 at 172.22.27.137:5062) Callstate Change HELD -> UNHELD
2017-03-22 11:56:10.973121 [DEBUG] switch_ivr_bridge.c:675 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.973121 [NOTICE] switch_ivr_bridge.c:739 Hangup sofia/internal/sip:5536 at 172.22.27.137:5062 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2017-03-22 11:56:10.973121 [DEBUG] switch_channel.c:3189 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [KILL]
2017-03-22 11:56:10.973121 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/sip:5536 at 172.22.27.137:5062) Callstate Change UNHELD -> HANGUP
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:683 (sofia/internal/sip:5536 at 172.22.27.137:5062) State HANGUP
2017-03-22 11:56:10.973121 [DEBUG] mod_sofia.c:506 Channel sofia/internal/sip:5536 at 172.22.27.137:5062 hanging up, cause: NORMAL_CLEARING
2017-03-22 11:56:10.973121 [DEBUG] mod_sofia.c:558 Sending BYE to sofia/internal/sip:5536 at 172.22.27.137:5062
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:5536 at 172.22.27.137:5062 Standard HANGUP, cause: NORMAL_CLEARING
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:683 (sofia/internal/sip:5536 at 172.22.27.137:5062) State HANGUP going to sleep
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:484 (sofia/internal/sip:5536 at 172.22.27.137:5062) State EXCHANGE_MEDIA going to sleep
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:5536 at 172.22.27.137:5062) Running State Change CS_HANGUP
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:450 (sofia/internal/sip:5536 at 172.22.27.137:5062) State Change CS_HANGUP -> CS_REPORTING
2017-03-22 11:56:10.973121 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:5536 at 172.22.27.137:5062) Running State Change CS_REPORTING
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:767 (sofia/internal/sip:5536 at 172.22.27.137:5062) State REPORTING
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:5536 at 172.22.27.137:5062 Standard REPORTING, cause: NORMAL_CLEARING
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:767 (sofia/internal/sip:5536 at 172.22.27.137:5062) State REPORTING going to sleep
2017-03-22 11:56:10.973121 [DEBUG] switch_core_state_machine.c:444 (sofia/internal/sip:5536 at 172.22.27.137:5062) State Change CS_REPORTING -> CS_DESTROY
2017-03-22 11:56:10.973121 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.973121 [DEBUG] switch_core_session.c:1559 Session 717 (sofia/internal/sip:5536 at 172.22.27.137:5062) Locked, Waiting on external entities
2017-03-22 11:56:10.993102 [DEBUG] switch_ivr_bridge.c:645 BRIDGE THREAD DONE [sofia/internal/8911 at insiel.fvgvoipcoll.it]
2017-03-22 11:56:10.993102 [DEBUG] switch_ivr_bridge.c:675 Send signal sofia/internal/sip:5536 at 172.22.27.137:5062 [BREAK]
2017-03-22 11:56:10.993102 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.993102 [DEBUG] switch_cpp.cpp:670 CoreSession::hangup
2017-03-22 11:56:10.993102 [NOTICE] switch_cpp.cpp:672 Hangup sofia/internal/8911 at insiel.fvgvoipcoll.it [CS_ROUTING] [NORMAL_CLEARING]
2017-03-22 11:56:10.993102 [DEBUG] switch_channel.c:3189 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [KILL]
2017-03-22 11:56:10.993102 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Callstate Change ACTIVE -> HANGUP
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:683 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State HANGUP
2017-03-22 11:56:10.993102 [DEBUG] mod_sofia.c:506 Channel sofia/internal/8911 at insiel.fvgvoipcoll.it hanging up, cause: NORMAL_CLEARING
2017-03-22 11:56:10.993102 [NOTICE] switch_core_session.c:1577 Session 717 (sofia/internal/sip:5536 at 172.22.27.137:5062) Ended
2017-03-22 11:56:10.993102 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/sip:5536 at 172.22.27.137:5062 [CS_DESTROY]
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:572 (sofia/internal/sip:5536 at 172.22.27.137:5062) Running State Change CS_DESTROY
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:582 (sofia/internal/sip:5536 at 172.22.27.137:5062) State DESTROY
2017-03-22 11:56:10.993102 [DEBUG] mod_sofia.c:399 sofia/internal/sip:5536 at 172.22.27.137:5062 SOFIA DESTROY
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:5536 at 172.22.27.137:5062 Standard DESTROY
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:582 (sofia/internal/sip:5536 at 172.22.27.137:5062) State DESTROY going to sleep
2017-03-22 11:56:10.993102 [DEBUG] mod_sofia.c:558 Sending BYE to sofia/internal/8911 at insiel.fvgvoipcoll.it
send 737 bytes to udp/[172.25.248.82]:5060 at 10:56:11.000090:
------------------------------------------------------------------------
BYE sip:8911 at 10.200.0.21:65399;ob SIP/2.0
Via: SIP/2.0/UDP 172.25.248.83;rport;branch=z9hG4bKeKF8DycQcrgZK
Route: <sip:172.25.248.82;lr;ftag=aT40JNloInEWtNO93asJLx1fr99asBMY;did=e2e.3240d2d1>
Max-Forwards: 70
From: <sip:8910 at insiel.fvgvoipcoll.it>;tag=0Qmt0F0e2ySpe
To: "8911 at insiel.fvgvoipcoll.it" <sip:8911 at insiel.fvgvoipcoll.it>;tag=aT40JNloInEWtNO93asJLx1fr99asBMY
Call-ID: i2cuGU.0L-OgWpqyHD9302-wfE3Nqgaq
CSeq: 104754021 BYE
Contact: <sip:8910 at 172.25.248.83:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:48 sofia/internal/8911 at insiel.fvgvoipcoll.it Standard HANGUP, cause: NORMAL_CLEARING
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:683 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State HANGUP going to sleep
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:614 Hangup Command with no Session luarun(functions/clean_pickup.lua 9e982efc-42c4-489c-9fef-012a443fbd4a):
+OK
2017-03-22 11:56:10.993102 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x17b5b20 released.
2017-03-22 11:56:10.993102 [DEBUG] switch_cpp.cpp:1051 sofia/internal/8911 at insiel.fvgvoipcoll.it destroy/unlink session from object
2017-03-22 11:56:10.993102 [DEBUG] switch_core_session.c:2822 sofia/internal/8911 at insiel.fvgvoipcoll.it skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:481 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State EXECUTE going to sleep
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Running State Change CS_HANGUP
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:450 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State Change CS_HANGUP -> CS_REPORTING
2017-03-22 11:56:10.993102 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Running State Change CS_REPORTING
2017-03-22 11:56:10.993102 [DEBUG] switch_core_state_machine.c:767 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State REPORTING
2017-03-22 11:56:10.993102 [INFO] switch_cpp.cpp:1288 @@@@@@@@@@@@@@@@@@@@@@@ clean_pickup.lua
2017-03-22 11:56:10.993102 [DEBUG] freeswitch_lua.cpp:360 DBH handle 0x1768f10 Connected.
2017-03-22 11:56:10.993102 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x1768f10 released.
recv 358 bytes from udp/[172.25.248.82]:5060 at 10:56:11.024086:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.25.248.83;rport=5060;received=172.25.248.83;branch=z9hG4bKeKF8DycQcrgZK
Call-ID: i2cuGU.0L-OgWpqyHD9302-wfE3Nqgaq
From: <sip:8910 at insiel.fvgvoipcoll.it>;tag=0Qmt0F0e2ySpe
To: "8911 at insiel.fvgvoipcoll.it" <sip:8911 at insiel.fvgvoipcoll.it>;tag=aT40JNloInEWtNO93asJLx1fr99asBMY
CSeq: 104754021 BYE
Content-Length: 0
------------------------------------------------------------------------
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:92 sofia/internal/8911 at insiel.fvgvoipcoll.it Standard REPORTING, cause: NORMAL_CLEARING
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:767 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State REPORTING going to sleep
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:444 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State Change CS_REPORTING -> CS_DESTROY
2017-03-22 11:56:11.033093 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/8911 at insiel.fvgvoipcoll.it [BREAK]
2017-03-22 11:56:11.033093 [DEBUG] switch_core_session.c:1559 Session 715 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Locked, Waiting on external entities
2017-03-22 11:56:11.033093 [NOTICE] switch_core_session.c:1577 Session 715 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Ended
2017-03-22 11:56:11.033093 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/8911 at insiel.fvgvoipcoll.it [CS_DESTROY]
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:572 (sofia/internal/8911 at insiel.fvgvoipcoll.it) Running State Change CS_DESTROY
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:582 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State DESTROY
2017-03-22 11:56:11.033093 [DEBUG] mod_sofia.c:399 sofia/internal/8911 at insiel.fvgvoipcoll.it SOFIA DESTROY
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:99 sofia/internal/8911 at insiel.fvgvoipcoll.it Standard DESTROY
2017-03-22 11:56:11.033093 [DEBUG] switch_core_state_machine.c:582 (sofia/internal/8911 at insiel.fvgvoipcoll.it) State DESTROY going to sleep
recv 397 bytes from udp/[172.25.248.82]:5060 at 10:56:11.078961:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.25.248.83;received=172.25.248.83;rport=5060;branch=z9hG4bKDapFc3UKFFtcr
From: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
To: <sip:5536 at 172.22.27.137:5062>;tag=507421845
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754017 NOTIFY
Contact: <sip:5536 at 172.22.27.137:5062>
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 0
------------------------------------------------------------------------
send 710 bytes to udp/[172.25.248.82]:5060 at 10:56:11.079572:
------------------------------------------------------------------------
BYE sip:5536 at 172.22.27.137:5062 SIP/2.0
Via: SIP/2.0/UDP 172.25.248.83;rport;branch=z9hG4bKFv80FSXt906HF
Route: <sip:172.25.248.82;lr;ftag=4USX7U3vp2j1c;did=51d.6c2982e6>
Max-Forwards: 70
From: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
To: <sip:5536 at 172.22.27.137:5062>;tag=507421845
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754018 BYE
Contact: <sip:mod_sofia at 172.25.248.83:5060>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140910T073219Z~bbe2531cb0~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
recv 476 bytes from udp/[172.25.248.82]:5060 at 10:56:11.082051:
------------------------------------------------------------------------
BYE sip:mod_sofia at 172.25.248.83:5060 SIP/2.0
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK871e.65384514.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK384278620
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754018 BYE
Contact: <sip:5536 at 172.22.27.137:5062>
Max-Forwards: 69
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 0
------------------------------------------------------------------------
recv 354 bytes from udp/[172.25.248.82]:5060 at 10:56:11.117925:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.25.248.83;received=172.25.248.83;rport=5060;branch=z9hG4bKFv80FSXt906HF
From: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
To: <sip:5536 at 172.22.27.137:5062>;tag=507421845
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754018 BYE
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 0
------------------------------------------------------------------------
send 347 bytes to udp/[172.25.248.82]:5060 at 10:56:11.118238:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.25.248.82:5060;branch=z9hG4bK871e.65384514.0
Via: SIP/2.0/UDP 172.22.27.137:5062;branch=z9hG4bK384278620
From: <sip:5536 at 172.22.27.137:5062>;tag=507421845
To: "8911" <sip:8911 at insiel.fvgvoipcoll.it>;tag=4USX7U3vp2j1c
Call-ID: f9313c57-8990-1235-e48f-005056886d47
CSeq: 104754018 BYE
Content-Length: 0
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list