2016-08-15 01:50:25.400493 [DEBUG] switch_ivr_originate.c:2100 Parsing global variables 2016-08-15 01:50:25.400493 [DEBUG] switch_event.c:1698 Parsing variable [origination_caller_id_name]=[xxx61452594] 2016-08-15 01:50:25.400493 [DEBUG] switch_event.c:1698 Parsing variable [ignore_early_media]=[true] 2016-08-15 01:50:25.400493 [NOTICE] switch_channel.c:1075 New Channel sofia/external/xxx98645055 [bf436d68-1516-41cc-a080-12866b00e68b] 2016-08-15 01:50:25.400493 [DEBUG] mod_sofia.c:4701 (sofia/external/xxx98645055) State Change CS_NEW -> CS_INIT 2016-08-15 01:50:25.400493 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_INIT 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:512 (sofia/external/xxx98645055) State INIT 2016-08-15 01:50:25.400493 [DEBUG] mod_sofia.c:87 sofia/external/xxx98645055 SOFIA INIT 2016-08-15 01:50:25.400493 [DEBUG] sofia_glue.c:1236 sofia/external/xxx98645055 sending invite version: 1.4.19 -5-1 64bit Local SDP: v=0 o=FreeSWITCH 1471167765 1471167766 IN IP4 xxx.xxx.xxx.xxx s=FreeSWITCH c=IN IP4 xxx.xxx.xxx.xxx t=0 0 m=audio 58060 RTP/AVP 0 8 3 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1141 bytes to udp/[xxx.xxx.xxx.xx]:50619 at 01:50:25.417429: ------------------------------------------------------------------------ INVITE sip:xxx98645055@xxx.xxx.xxx.xx:50619 SIP/2.0 freeswitch@internal> Via: SIP/2.0/UDP xxx.xxx.xxx.xxx:5070;rport;branch=z9hG4bKKFpBymXSD7QpF Max-Forwards: 70 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.4.19-5-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 276 X-FS-Support: update_display,send_info Remote-Party-ID: "xxx61452594" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1471167765 1471167766 IN IP4 xxx.xxx.xxx.xxx s=FreeSWITCH c=IN IP4 xxx.xxx.xxx.xxx t=0 0 m=audio 58060 RTP/AVP 0 8 3 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2016-08-15 01:50:25.400493 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:40 sofia/external/xxx98645055 Standard INIT 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:48 (sofia/external/xxx98645055) State Change CS_INIT -> CS_ROUTING 2016-08-15 01:50:25.400493 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:512 (sofia/external/xxx98645055) State INIT going to sleep 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_ROUTING 2016-08-15 01:50:25.400493 [DEBUG] sofia.c:6627 Channel sofia/external/xxx98645055 entering state [calling][0] 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:528 (sofia/external/xxx98645055) State ROUTING 2016-08-15 01:50:25.400493 [DEBUG] mod_sofia.c:123 sofia/external/xxx98645055 SOFIA ROUTING 2016-08-15 01:50:25.400493 [DEBUG] switch_ivr_originate.c:67 (sofia/external/xxx98645055) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2016-08-15 01:50:25.400493 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:528 (sofia/external/xxx98645055) State ROUTING going to sleep 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_CONSUME_MEDIA 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:547 (sofia/external/xxx98645055) State CONSUME_MEDIA 2016-08-15 01:50:25.400493 [DEBUG] switch_core_state_machine.c:547 (sofia/external/xxx98645055) State CONSUME_MEDIA going to sleep recv 331 bytes from udp/[xxx.xxx.xxx.xx]:50619 at 01:50:25.582325: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP xxx.xxx.xxx.xx:5060;branch=z9hG4bKKFpBymXSD7QpF;rport=50619;received=10.22.160.28 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 771 bytes from udp/[xxx.xxx.xxx.xx]:50619 at 01:50:29.540563: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP xxx.xxx.xxx.xx:5060;branch=z9hG4bKKFpBymXSD7QpF;rport=50619;received=10.22.160.28 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: ;tag=2421515 Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 INVITE Contact: Content-Type: application/sdp Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: INFO Allow: PRACK Allow: UPDATE Content-Length: 238 v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 ------------------------------------------------------------------------ 2016-08-15 01:50:29.540514 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:29.540514 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:29.540514 [DEBUG] sofia.c:6627 Channel sofia/external/xxx98645055 entering state [proceeding][183] 2016-08-15 01:50:29.540514 [DEBUG] sofia.c:6637 Remote SDP: v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3733 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3594 Set telephone-event payload to 101 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:2507 Set Codec sofia/external/xxx98645055 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2016-08-15 01:50:29.540514 [DEBUG] switch_core_codec.c:111 sofia/external/xxx98645055 Original read codec set to PCMA:8 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:3932 Set 2833 dtmf send payload to 101 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:5177 AUDIO RTP [sofia/external/xxx98645055] 172.22.1.10 port 58060 -> xxx.xxx.xxx.xx port 36256 codec: 8 ms: 20 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:3569 Starting timer [soft] 160 bytes per 20ms 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: START SESSION INITIALIZATION. sID=1. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: ZID=306166303733613464366363. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Loading User's profile: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: allowclear: OFF 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: autosecure: ON 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: disclose_bit: OFF 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: signal. role: Initiator 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: TTL: 4294967295 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: SAS schemes: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 B256 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 B32 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Ciphers: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 AES3 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 AES1 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: PK schemes: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 EC25 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 DH3k 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 DH2k 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 Mult 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: ATL: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 HS32 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Hashes: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 S256 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Session initialization - DONE. sID=1. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: ATTACH NEW STREAM to sID=1: 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp]: Stream ID=0 UNKNOWN switching ---> . 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Empty slot was found - initializing new stream with ID=1. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: Preparing ZRTP Hello according to the Session profile. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp main]: ATTACH NEW STREAM - DONE. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: START STREAM ID=1 mode=CLEAR state=ACTIVE. 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp]: Stream ID=1 CLEAR switching ---> . 2016-08-15 01:50:29.540514 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38308 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:5475 Set 2833 dtmf send payload to 101 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:5481 Set 2833 dtmf receive payload to 101 2016-08-15 01:50:29.540514 [DEBUG] switch_core_media.c:5503 sofia/external/xxx98645055 Set rtp dtmf delay to 40 2016-08-15 01:50:29.540514 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/xxx98645055! 2016-08-15 01:50:29.540514 [DEBUG] switch_channel.c:3419 (sofia/external/xxx98645055) Callstate Change DOWN -> EARLY 2016-08-15 01:50:29.600487 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38309 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:29.700487 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38310 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:29.900489 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38311 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:30.100490 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38312 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:30.300486 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: WARNING! HELLO have been resent 5 times without a response. Raising ZRTP_EVENT_NO_ZRTP_QUICK event. ID=1 2016-08-15 01:50:30.300486 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38313 size=144. Stream 1:CLEAR:START recv 762 bytes from udp/[xxx.xxx.xxx.xx]:50619 at 01:50:30.493757: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP xxx.xxx.xxx.xx:5060;branch=z9hG4bKKFpBymXSD7QpF;rport=50619;received=10.22.160.28 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: ;tag=2421515 Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 INVITE Contact: Content-Type: application/sdp Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: INFO Allow: PRACK Allow: UPDATE Content-Length: 238 v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 ------------------------------------------------------------------------ 2016-08-15 01:50:30.480494 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:30.480494 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:30.480494 [DEBUG] sofia.c:6627 Channel sofia/external/xxx98645055 entering state [proceeding][180] 2016-08-15 01:50:30.480494 [DEBUG] sofia.c:6634 Duplicate SDP v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3733 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3678 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3594 Set telephone-event payload to 101 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:3932 Set 2833 dtmf send payload to 101 2016-08-15 01:50:30.480494 [DEBUG] switch_core_media.c:5160 Audio params are unchanged for sofia/external/xxx98645055. 2016-08-15 01:50:30.500493 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38314 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:30.700492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38315 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:30.900498 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38316 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:31.100492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38317 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:31.300493 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38318 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:31.500493 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38319 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:31.700524 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38320 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:31.900482 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38321 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:32.100492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38322 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:32.300488 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38323 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:32.500492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38324 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:32.700489 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38325 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:32.900492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38326 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:33.100492 [DEBUG] switch_rtp.c:1352 [ zrtp utils]: Send ssrc=1503312829 seq=38327 size=144. Stream 1:CLEAR:START 2016-08-15 01:50:33.300482 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: WARNING! HELLO Max retransmissions count reached (20 retries). ID=1 2016-08-15 01:50:33.300482 [DEBUG] switch_rtp.c:1352 [ zrtp]: Stream ID=1 CLEAR switching ---> . recv 776 bytes from udp/[xxx.xxx.xxx.xx]:50619 at 01:50:33.484919: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP xxx.xxx.xxx.xx:5060;branch=z9hG4bKKFpBymXSD7QpF;rport=50619;received=10.22.160.28 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: ;tag=2421515 Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 INVITE Contact: Content-Type: application/sdp Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: INFO Allow: PRACK Allow: UPDATE Supported: 100rel Content-Length: 238 v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 ------------------------------------------------------------------------ 2016-08-15 01:50:33.480488 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:33.480488 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:33.480488 [DEBUG] sofia.c:6627 Channel sofia/external/xxx98645055 entering state [completing][200] 2016-08-15 01:50:33.480488 [DEBUG] sofia.c:6634 Duplicate SDP v=0 o=genband 323719168 1471225826 IN IP4 xxx.xxx.xxx.xx s=- c=IN IP4 xxx.xxx.xxx.xx t=0 0 m=audio 36256 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:20 send 441 bytes to udp/[xxx.xxx.xxx.xx]:50619 at 01:50:33.485920: ------------------------------------------------------------------------ ACK sip:xxx98645055@xxx.xxx.xxx.xx:50619 SIP/2.0 Via: SIP/2.0/UDP xxx.xxx.xxx.xxx:5070;rport;branch=z9hG4bKmrF4ZFeXage9a Max-Forwards: 70 From: "xxx61452594" ;tag=jve4DHXF2BZeS To: ;tag=2421515 Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 95276848 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 2016-08-15 01:50:33.480488 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:33.480488 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:33.480488 [DEBUG] sofia.c:6627 Channel sofia/external/xxx98645055 entering state [ready][200] 2016-08-15 01:50:33.480488 [NOTICE] sofia.c:7429 Channel [sofia/external/xxx98645055] has been answered 2016-08-15 01:50:33.480488 [DEBUG] switch_channel.c:3711 (sofia/external/xxx98645055) Callstate Change EARLY -> ACTIVE 2016-08-15 01:50:33.480488 [DEBUG] switch_ivr_originate.c:3577 Originate Resulted in Success: [sofia/external/xxx98645055] 2016-08-15 01:50:33.480488 [INFO] switch_channel.c:3082 sofia/external/xxx98645055 Flipping CID from "xxx61452594" <0000000000> to "Outbound Call" 2016-08-15 01:50:33.480488 [DEBUG] mod_commands.c:4469 (sofia/external/xxx98645055) State Change CS_CONSUME_MEDIA -> CS_EXECUTE 2016-08-15 01:50:33.480488 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:33.480488 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_EXECUTE 2016-08-15 01:50:33.480488 [DEBUG] switch_core_state_machine.c:535 (sofia/external/xxx98645055) State EXECUTE 2016-08-15 01:50:33.480488 [DEBUG] mod_sofia.c:178 sofia/external/xxx98645055 SOFIA EXECUTE 2016-08-15 01:50:33.480488 [DEBUG] switch_core_state_machine.c:258 sofia/external/xxx98645055 Standard EXECUTE EXECUTE sofia/external/xxx98645055 park() recv 433 bytes from udp/[xxx.xxx.xxx.xx]:50619 at 01:50:40.914762: ------------------------------------------------------------------------ BYE sip:0000000000@xxx.xxx.xxx.xx:5060;transport=udp;gw=pivotel-au SIP/2.0 Via: SIP/2.0/UDP xxx.xxx.xxx.xx:50619;branch=z9hG4bK-57069baf-23601292 From: ;tag=2421515 To: "xxx61452594" ;tag=jve4DHXF2BZeS Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 1 BYE Max-forwards: 70 Reason: Q.850; cause=16; text="Normal call clearing" Content-Length: 0 ------------------------------------------------------------------------ 2016-08-15 01:50:40.900493 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:40.920494 [NOTICE] sofia.c:952 Hangup sofia/external/xxx98645055 [CS_EXECUTE] [NORMAL_CLEARING] 2016-08-15 01:50:40.920494 [DEBUG] switch_channel.c:3242 Send signal sofia/external/xxx98645055 [KILL] 2016-08-15 01:50:40.920494 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] send 488 bytes to udp/[xxx.xxx.xxx.xx]:50619 at 01:50:40.922654: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP xxx.xxx.xxx.xx:50619;branch=z9hG4bK-57069baf-23601292;rport=50619 From: ;tag=2421515 To: "xxx61452594" ;tag=jve4DHXF2BZeS Call-ID: 79f4f2c5-dd2d-1234-9da4-4201ac16010a CSeq: 1 BYE User-Agent: FreeSWITCH-mod_sofia/1.4.19-5-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2016-08-15 01:50:40.920494 [DEBUG] switch_core_session.c:2901 sofia/external/xxx98645055 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:535 (sofia/external/xxx98645055) State EXECUTE going to sleep 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_HANGUP 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:735 (sofia/external/xxx98645055) Callstate Change ACTIVE -> HANGUP 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:737 (sofia/external/xxx98645055) State HANGUP 2016-08-15 01:50:40.920494 [DEBUG] mod_sofia.c:413 Channel sofia/external/xxx98645055 hanging up, cause: NORMAL_CLEARING 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:60 sofia/external/xxx98645055 Standard HANGUP, cause: NORMAL_CLEARING 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:737 (sofia/external/xxx98645055) State HANGUP going to sleep 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:504 (sofia/external/xxx98645055) State Change CS_HANGUP -> CS_REPORTING 2016-08-15 01:50:40.920494 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:472 (sofia/external/xxx98645055) Running State Change CS_REPORTING 2016-08-15 01:50:40.920494 [DEBUG] switch_core_state_machine.c:823 (sofia/external/xxx98645055) State REPORTING 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:104 sofia/external/xxx98645055 Standard REPORTING, cause: NORMAL_CLEARING 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:823 (sofia/external/xxx98645055) State REPORTING going to sleep 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:498 (sofia/external/xxx98645055) State Change CS_REPORTING -> CS_DESTROY 2016-08-15 01:50:40.940520 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/xxx98645055 [BREAK] 2016-08-15 01:50:40.940520 [DEBUG] switch_core_session.c:1623 Session 2 (sofia/external/xxx98645055) Locked, Waiting on external entities 2016-08-15 01:50:40.940520 [NOTICE] switch_core_session.c:1641 Session 2 (sofia/external/xxx98645055) Ended 2016-08-15 01:50:40.940520 [NOTICE] switch_core_session.c:1645 Close Channel sofia/external/xxx98645055 [CS_DESTROY] 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:626 (sofia/external/xxx98645055) Running State Change CS_DESTROY 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:636 (sofia/external/xxx98645055) State DESTROY 2016-08-15 01:50:40.940520 [DEBUG] mod_sofia.c:323 sofia/external/xxx98645055 SOFIA DESTROY 2016-08-15 01:50:40.940520 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: STOP STREAM ID=1 mode=CLEAR state=NOZRTP. 2016-08-15 01:50:40.940520 [DEBUG] switch_rtp.c:1352 [ zrtp]: Stream ID=0 UNKNOWN switching ---> . 2016-08-15 01:50:40.940520 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2016-08-15 01:50:40.940520 [DEBUG] switch_rtp.c:1352 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:111 sofia/external/xxx98645055 Standard DESTROY 2016-08-15 01:50:40.940520 [DEBUG] switch_core_state_machine.c:636 (sofia/external/xxx98645055) State DESTROY going to sleep