I've installed fresh FS ver-1.2.11 (latest stable) with --enable-zrtp. The server is an Xeon 3Ghz Centos 5.3. I've set vars.xml <X-PRE-PROCESS cmd="set" data="zrtp_secure_media=true"/>. I use the default sip_profile internal.xml with ext 1001 and 1002. Both proxy/bypass are commented and false (default setup). Using default dialplan public&default.xml. The problem is that I cannot get the MITM situation even with two simple ZRTP clients. (The MITM is required for end-2-site encryption when dialing through a SIP provider). The FS detects the SDP ZRTP but not generating back to back ZRTP sessions between the endpoints. I've reinstall FS with ZRTP twice and the problem is the same. I can get end-2-end ZRTP with both proxy and bypass media modes. I've install FS with ZRTP, with the same config xml files, on a remote EC2 and all works fine with MITM. What else should I check to find out why FS does not activate the internal ZRTP module? Below is the log for call between 1001 and 1002 (with no ZRTP initiative). 2013-07-21 20:18:23.968057 [NOTICE] switch_channel.c:1030 New Channel sofia/internal/1002@domain.com [2ac8892b-16ee-419f-8369-942bee25ebeb] 2013-07-21 20:18:23.968057 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:23.968057 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:23.968057 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_NEW 2013-07-21 20:18:23.968057 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/1002@domain.com) State NEW 2013-07-21 20:18:23.988080 [DEBUG] sofia.c:7888 IP 2.3.4.5 Rejected by acl "domains". Falling back to Digest auth. 2013-07-21 20:18:23.988080 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:23.988080 [DEBUG] sofia.c:1767 detaching session 2ac8892b-16ee-419f-8369-942bee25ebeb 2013-07-21 20:18:24.108098 [DEBUG] sofia.c:1859 Re-attaching to session 2ac8892b-16ee-419f-8369-942bee25ebeb 2013-07-21 20:18:24.108098 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.108098 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.108098 [DEBUG] sofia.c:7888 IP 2.3.4.5 Rejected by acl "domains". Falling back to Digest auth. 2013-07-21 20:18:24.128130 [DEBUG] sofia.c:8874 Setting NAT mode based on nat.auto 2013-07-21 20:18:24.128130 [DEBUG] sofia.c:5720 Channel sofia/internal/1002@domain.com entering state [received][100] 2013-07-21 20:18:24.128130 [DEBUG] sofia.c:5733 Remote SDP: 2013-07-21 20:18:24.128130 [DEBUG] sofia_glue.c:4072 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 63cad5b5a616388ca2578dde581b676c4ecacb7c754fc7716f07dbf249746af5 2013-07-21 20:18:24.128130 [DEBUG] sofia.c:5947 (sofia/internal/1002@domain.com) State Change CS_NEW -> CS_INIT 2013-07-21 20:18:24.128130 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_INIT 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/1002@domain.com) State INIT 2013-07-21 20:18:24.128130 [DEBUG] mod_sofia.c:87 sofia/internal/1002@domain.com SOFIA INIT 2013-07-21 20:18:24.128130 [DEBUG] mod_sofia.c:127 (sofia/internal/1002@domain.com) State Change CS_INIT -> CS_ROUTING 2013-07-21 20:18:24.128130 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/1002@domain.com) State INIT going to sleep 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_ROUTING 2013-07-21 20:18:24.128130 [DEBUG] switch_channel.c:2111 (sofia/internal/1002@domain.com) Callstate Change DOWN -> RINGING 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/1002@domain.com) State ROUTING 2013-07-21 20:18:24.128130 [DEBUG] mod_sofia.c:150 sofia/internal/1002@domain.com SOFIA ROUTING 2013-07-21 20:18:24.128130 [DEBUG] switch_core_state_machine.c:117 sofia/internal/1002@domain.com Standard ROUTING 2013-07-21 20:18:24.128130 [INFO] mod_dialplan_xml.c:558 Processing 1002 <1002>->1001 in context default 2013-07-21 20:18:24.148132 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1002@domain.com) State Change CS_ROUTING -> CS_EXECUTE 2013-07-21 20:18:24.148132 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.148132 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/1002@domain.com) State ROUTING going to sleep 2013-07-21 20:18:24.148132 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_EXECUTE 2013-07-21 20:18:24.148132 [DEBUG] switch_core_state_machine.c:477 (sofia/internal/1002@domain.com) State EXECUTE 2013-07-21 20:18:24.148132 [DEBUG] mod_sofia.c:243 sofia/internal/1002@domain.com SOFIA EXECUTE 2013-07-21 20:18:24.148132 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1002@domain.com Standard EXECUTE 2013-07-21 20:18:24.148132 [DEBUG] switch_channel.c:1222 EXPORT (export_vars) [RFC2822_DATE]=[Sun, 21 Jul 2013 20:18:24 +0300] 2013-07-21 20:18:24.148132 [DEBUG] switch_channel.c:1222 EXPORT (export_vars) [dialed_extension]=[1001] 2013-07-21 20:18:24.148132 [INFO] switch_ivr_async.c:3692 Bound B-Leg: *1 execute_extension::dx XML features 2013-07-21 20:18:24.148132 [INFO] switch_ivr_async.c:3692 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1002.2013-07-21-20-18-24.wav 2013-07-21 20:18:24.148132 [INFO] switch_ivr_async.c:3692 Bound B-Leg: *3 execute_extension::cf XML features 2013-07-21 20:18:24.148132 [INFO] switch_ivr_async.c:3692 Bound B-Leg: *4 execute_extension::att_xfer XML features 2013-07-21 20:18:24.148132 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [ringback]=[%(2000,4000,440,480)] 2013-07-21 20:18:24.148132 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [transfer_ringback]=[local_stream://moh] 2013-07-21 20:18:24.148132 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [call_timeout]=[30] 2013-07-21 20:18:24.148132 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [hangup_after_bridge]=[true] 2013-07-21 20:18:24.148132 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [continue_on_fail]=[true] 2013-07-21 20:18:24.168166 [DEBUG] mod_dptools.c:1376 sofia/internal/1002@domain.com SET [called_party_callgroup]=[techsupport] 2013-07-21 20:18:24.168166 [DEBUG] switch_channel.c:1176 sofia/internal/1002@domain.com EXPORTING[export_vars] [RFC2822_DATE]=[Sun, 21 Jul 2013 20:18:24 +0300] to event 2013-07-21 20:18:24.168166 [DEBUG] switch_channel.c:1176 sofia/internal/1002@domain.com EXPORTING[export_vars] [dialed_extension]=[1001] to event 2013-07-21 20:18:24.168166 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables 2013-07-21 20:18:24.188169 [DEBUG] switch_channel.c:1176 sofia/internal/1002@domain.com EXPORTING[export_vars] [RFC2822_DATE]=[Sun, 21 Jul 2013 20:18:24 +0300] to event 2013-07-21 20:18:24.188169 [DEBUG] switch_channel.c:1176 sofia/internal/1002@domain.com EXPORTING[export_vars] [dialed_extension]=[1001] to event 2013-07-21 20:18:24.188169 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables 2013-07-21 20:18:24.188169 [DEBUG] switch_event.c:1617 Parsing variable [sip_invite_domain]=[domain1001.com] 2013-07-21 20:18:24.188169 [DEBUG] switch_event.c:1617 Parsing variable [presence_id]=[1001@domain1001.com] 2013-07-21 20:18:24.188169 [NOTICE] switch_channel.c:1030 New Channel sofia/internal/sip:1001@192.168.1.100:51783 [cdf668f4-5a41-4703-9a22-d40299ce6c82] 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:5189 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_NEW -> CS_INIT 2013-07-21 20:18:24.188169 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.188169 [DEBUG] sofia_glue.c:4015 Passing a-leg remote zrtp-hash (audio) to b-leg 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:5259 [zrtp_passthru] Setting a-leg inherit_codec=true 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:5262 [zrtp_passthru] Setting b-leg absolute_codec_string='SILK@8000h@20i,GSM@8000h@20i@13200b,PCMU@8000h@20i@64000b' 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_INIT 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/sip:1001@192.168.1.100:51783) State INIT 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:87 sofia/internal/sip:1001@192.168.1.100:51783 SOFIA INIT 2013-07-21 20:18:24.188169 [DEBUG] sofia_glue.c:349 Adding audio a=zrtp-hash:1.10 63cad5b5a616388ca2578dde581b676c4ecacb7c754fc7716f07dbf249746af5 2013-07-21 20:18:24.188169 [DEBUG] sofia_glue.c:2649 sip:1001@109.160.136.237:57182;transport=TCP Setting proxy route to sofia/internal/sip:1001@192.168.1.100:51783 2013-07-21 20:18:24.188169 [DEBUG] sofia_glue.c:2678 Local SDP: 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:127 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_INIT -> CS_ROUTING 2013-07-21 20:18:24.188169 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/sip:1001@192.168.1.100:51783) State INIT going to sleep 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_ROUTING 2013-07-21 20:18:24.188169 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/sip:1001@192.168.1.100:51783) State ROUTING 2013-07-21 20:18:24.188169 [DEBUG] mod_sofia.c:150 sofia/internal/sip:1001@192.168.1.100:51783 SOFIA ROUTING 2013-07-21 20:18:24.188169 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2013-07-21 20:18:24.188169 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/sip:1001@192.168.1.100:51783) State ROUTING going to sleep 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_CONSUME_MEDIA 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:489 (sofia/internal/sip:1001@192.168.1.100:51783) State CONSUME_MEDIA 2013-07-21 20:18:24.188169 [DEBUG] switch_core_state_machine.c:489 (sofia/internal/sip:1001@192.168.1.100:51783) State CONSUME_MEDIA going to sleep 2013-07-21 20:18:24.188169 [DEBUG] sofia.c:5720 Channel sofia/internal/sip:1001@192.168.1.100:51783 entering state [calling][0] 2013-07-21 20:18:24.381616 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.381616 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:24.381616 [DEBUG] sofia.c:5720 Channel sofia/internal/sip:1001@192.168.1.100:51783 entering state [proceeding][180] 2013-07-21 20:18:24.381616 [NOTICE] sofia.c:5815 Ring-Ready sofia/internal/sip:1001@192.168.1.100:51783! 2013-07-21 20:18:24.381616 [DEBUG] switch_channel.c:3175 (sofia/internal/sip:1001@192.168.1.100:51783) Callstate Change DOWN -> RINGING 2013-07-21 20:18:24.401623 [INFO] switch_ivr_originate.c:1190 Sending early media 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:4072 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 63cad5b5a616388ca2578dde581b676c4ecacb7c754fc7716f07dbf249746af5 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:4015 Passing a-leg remote zrtp-hash (audio) to b-leg 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:5181 Audio Codec Compare [SILK:96:8000:20:0]/[SILK:117:8000:20:20000] 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:3124 Set Codec sofia/internal/1002@domain.com SILK/8000 20 ms 160 samples 20000 bits 2013-07-21 20:18:24.401623 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@domain.com Original read codec set to SILK:117 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:5312 Set 2833 dtmf send/recv payload to 101 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:3383 AUDIO RTP [sofia/internal/1002@domain.com] 91.205.155.18 port 19562 -> 10.195.42.107 port 4006 codec: 96 ms: 20 2013-07-21 20:18:24.401623 [DEBUG] switch_rtp.c:1985 Starting timer [soft] 160 bytes per 20ms 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:3647 Set 2833 dtmf send payload to 101 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:3653 Set 2833 dtmf receive payload to 101 2013-07-21 20:18:24.401623 [DEBUG] sofia_glue.c:3680 sofia/internal/1002@domain.com Set rtp dtmf delay to 40 2013-07-21 20:18:24.401623 [INFO] switch_channel.c:3217 sofia/internal/1002@domain.com ZRTP not negotiated on both sides; disabling ZRTP passthru mode. 2013-07-21 20:18:24.401623 [NOTICE] sofia_glue.c:4291 Pre-Answer sofia/internal/1002@domain.com! 2013-07-21 20:18:24.401623 [DEBUG] switch_channel.c:3299 (sofia/internal/1002@domain.com) Callstate Change RINGING -> EARLY 2013-07-21 20:18:24.401623 [DEBUG] mod_sofia.c:2847 Ring SDP: 2013-07-21 20:18:24.401623 [DEBUG] switch_core_session.c:854 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.401623 [DEBUG] switch_ivr_originate.c:1247 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2013-07-21 20:18:24.401623 [DEBUG] switch_core_codec.c:219 sofia/internal/1002@domain.com Push codec L16:70 2013-07-21 20:18:24.401623 [DEBUG] switch_ivr_originate.c:1315 Play Ringback Tone [%(2000,4000,440,480)] 2013-07-21 20:18:24.401623 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:24.441618 [DEBUG] sofia.c:5720 Channel sofia/internal/1002@domain.com entering state [early][183] 2013-07-21 20:18:24.801608 [INFO] switch_rtp.c:3687 Auto Changing port from 10.195.42.107:4006 to 2.3.4.5:26681 2013-07-21 20:18:30.561547 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.561547 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.561547 [DEBUG] sofia.c:5720 Channel sofia/internal/sip:1001@192.168.1.100:51783 entering state [completing][200] 2013-07-21 20:18:30.561547 [DEBUG] sofia.c:5733 Remote SDP: 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4072 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 788348c399ae6170adaee70b74ea3d584c8db158d41c3a650faedaa8a1ce67df 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4015 Passing a-leg remote zrtp-hash (audio) to b-leg 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4025 Passing b-leg remote zrtp-hash (audio) to a-leg 2013-07-21 20:18:30.561547 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.561547 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.561547 [DEBUG] sofia.c:5720 Channel sofia/internal/sip:1001@192.168.1.100:51783 entering state [ready][200] 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4072 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 788348c399ae6170adaee70b74ea3d584c8db158d41c3a650faedaa8a1ce67df 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4015 Passing a-leg remote zrtp-hash (audio) to b-leg 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:4025 Passing b-leg remote zrtp-hash (audio) to a-leg 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:5181 Audio Codec Compare [SILK:98:8000:20:0]/[SILK:117:8000:20:20000] 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:3124 Set Codec sofia/internal/sip:1001@192.168.1.100:51783 SILK/8000 20 ms 160 samples 20000 bits 2013-07-21 20:18:30.561547 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:1001@192.168.1.100:51783 Original read codec set to SILK:117 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:5303 Set 2833 dtmf send payload to 101 2013-07-21 20:18:30.561547 [INFO] switch_channel.c:3217 sofia/internal/sip:1001@192.168.1.100:51783 ZRTP not negotiated on both sides; disabling ZRTP passthru mode. 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:3383 AUDIO RTP [sofia/internal/sip:1001@192.168.1.100:51783] 91.205.155.18 port 19240 -> 109.160.136.237 port 4006 codec: 98 ms: 20 2013-07-21 20:18:30.561547 [DEBUG] switch_rtp.c:1985 Starting timer [soft] 160 bytes per 20ms 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:3647 Set 2833 dtmf send payload to 101 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:3653 Set 2833 dtmf receive payload to 101 2013-07-21 20:18:30.561547 [DEBUG] sofia_glue.c:3680 sofia/internal/sip:1001@192.168.1.100:51783 Set rtp dtmf delay to 40 2013-07-21 20:18:30.561547 [DEBUG] switch_channel.c:3530 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.561547 [NOTICE] sofia.c:6476 Channel [sofia/internal/sip:1001@192.168.1.100:51783] has been answered 2013-07-21 20:18:30.561547 [DEBUG] switch_channel.c:3576 (sofia/internal/sip:1001@192.168.1.100:51783) Callstate Change RINGING -> ACTIVE 2013-07-21 20:18:30.581577 [DEBUG] switch_core_codec.c:244 sofia/internal/1002@domain.com Restore previous codec SILK:117. 2013-07-21 20:18:30.581577 [DEBUG] sofia_glue.c:564 Adding audio a=zrtp-hash:1.10 788348c399ae6170adaee70b74ea3d584c8db158d41c3a650faedaa8a1ce67df 2013-07-21 20:18:30.581577 [DEBUG] mod_sofia.c:864 Local SDP sofia/internal/1002@domain.com: 2013-07-21 20:18:30.581577 [DEBUG] switch_core_session.c:854 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.581577 [NOTICE] switch_ivr_originate.c:3437 Channel [sofia/internal/1002@domain.com] has been answered 2013-07-21 20:18:30.581577 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.581577 [DEBUG] switch_channel.c:3576 (sofia/internal/1002@domain.com) Callstate Change EARLY -> ACTIVE 2013-07-21 20:18:30.581577 [DEBUG] sofia.c:5720 Channel sofia/internal/1002@domain.com entering state [completed][200] 2013-07-21 20:18:30.581577 [DEBUG] switch_ivr_originate.c:3494 Originate Resulted in Success: [sofia/internal/sip:1001@192.168.1.100:51783] 2013-07-21 20:18:30.581577 [DEBUG] switch_ivr_originate.c:3494 Originate Resulted in Success: [sofia/internal/sip:1001@192.168.1.100:51783] 2013-07-21 20:18:30.581577 [DEBUG] switch_core_session.c:854 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.581577 [DEBUG] switch_core_session.c:854 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.581577 [DEBUG] switch_ivr_bridge.c:1423 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2013-07-21 20:18:30.581577 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.581577 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_EXCHANGE_MEDIA 2013-07-21 20:18:30.581577 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/sip:1001@192.168.1.100:51783) State EXCHANGE_MEDIA 2013-07-21 20:18:30.581577 [DEBUG] mod_sofia.c:686 SOFIA EXCHANGE_MEDIA 2013-07-21 20:18:30.609131 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed. 2013-07-21 20:18:30.681545 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.681545 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.681545 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:30.701558 [DEBUG] sofia.c:5720 Channel sofia/internal/1002@domain.com entering state [ready][200] 2013-07-21 20:18:30.701558 [DEBUG] switch_core_session.c:916 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:30.701558 [DEBUG] switch_core_session.c:916 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.644911 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.664923 [NOTICE] sofia.c:716 Hangup sofia/internal/1002@domain.com [CS_EXECUTE] [NORMAL_CLEARING] 2013-07-21 20:18:38.664923 [DEBUG] switch_channel.c:3130 Send signal sofia/internal/1002@domain.com [KILL] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [sofia/internal/1002@domain.com] 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:658 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:557 sofia/internal/1002@domain.com ending bridge by request from write function 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [sofia/internal/sip:1001@192.168.1.100:51783] 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:658 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.664923 [NOTICE] switch_ivr_bridge.c:721 Hangup sofia/internal/sip:1001@192.168.1.100:51783 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2013-07-21 20:18:38.664923 [DEBUG] switch_channel.c:3130 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [KILL] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/sip:1001@192.168.1.100:51783) State EXCHANGE_MEDIA going to sleep 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_HANGUP 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/sip:1001@192.168.1.100:51783) State HANGUP 2013-07-21 20:18:38.664923 [DEBUG] mod_sofia.c:498 sofia/internal/sip:1001@192.168.1.100:51783 Overriding SIP cause 480 with 200 from the other leg 2013-07-21 20:18:38.664923 [DEBUG] mod_sofia.c:504 Channel sofia/internal/sip:1001@192.168.1.100:51783 hanging up, cause: NORMAL_CLEARING 2013-07-21 20:18:38.664923 [DEBUG] mod_sofia.c:556 Sending BYE to sofia/internal/sip:1001@192.168.1.100:51783 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:1001@192.168.1.100:51783 Standard HANGUP, cause: NORMAL_CLEARING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/sip:1001@192.168.1.100:51783) State HANGUP going to sleep 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:689 (sofia/internal/sip:1001@192.168.1.100:51783) Callstate Change ACTIVE -> HANGUP 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_HANGUP -> CS_REPORTING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_REPORTING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:761 (sofia/internal/sip:1001@192.168.1.100:51783) State REPORTING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:1001@192.168.1.100:51783 Standard REPORTING, cause: NORMAL_CLEARING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:761 (sofia/internal/sip:1001@192.168.1.100:51783) State REPORTING going to sleep 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/sip:1001@192.168.1.100:51783) State Change CS_REPORTING -> CS_DESTROY 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/sip:1001@192.168.1.100:51783 [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1542 Session 45 (sofia/internal/sip:1001@192.168.1.100:51783) Locked, Waiting on external entities 2013-07-21 20:18:38.664923 [DEBUG] switch_ivr_bridge.c:1524 sofia/internal/1002@domain.com skip receive message [UNBRIDGE] (channel is hungup already) 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:2740 sofia/internal/1002@domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:477 (sofia/internal/1002@domain.com) State EXECUTE going to sleep 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_HANGUP 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1002@domain.com) State HANGUP 2013-07-21 20:18:38.664923 [DEBUG] mod_sofia.c:504 Channel sofia/internal/1002@domain.com hanging up, cause: NORMAL_CLEARING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1002@domain.com Standard HANGUP, cause: NORMAL_CLEARING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1002@domain.com) State HANGUP going to sleep 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:689 (sofia/internal/1002@domain.com) Callstate Change ACTIVE -> HANGUP 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1002@domain.com) State Change CS_HANGUP -> CS_REPORTING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1002@domain.com) Running State Change CS_REPORTING 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:761 (sofia/internal/1002@domain.com) State REPORTING 2013-07-21 20:18:38.664923 [NOTICE] switch_core_session.c:1560 Session 45 (sofia/internal/sip:1001@192.168.1.100:51783) Ended 2013-07-21 20:18:38.664923 [NOTICE] switch_core_session.c:1564 Close Channel sofia/internal/sip:1001@192.168.1.100:51783 [CS_DESTROY] 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/sip:1001@192.168.1.100:51783) Callstate Change HANGUP -> DOWN 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/sip:1001@192.168.1.100:51783) Running State Change CS_DESTROY 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/sip:1001@192.168.1.100:51783) State DESTROY 2013-07-21 20:18:38.664923 [DEBUG] mod_sofia.c:397 sofia/internal/sip:1001@192.168.1.100:51783 SOFIA DESTROY 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:1001@192.168.1.100:51783 Standard DESTROY 2013-07-21 20:18:38.664923 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/sip:1001@192.168.1.100:51783) State DESTROY going to sleep 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1002@domain.com Standard REPORTING, cause: NORMAL_CLEARING 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:761 (sofia/internal/1002@domain.com) State REPORTING going to sleep 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1002@domain.com) State Change CS_REPORTING -> CS_DESTROY 2013-07-21 20:18:38.721464 [DEBUG] switch_core_session.c:1334 Send signal sofia/internal/1002@domain.com [BREAK] 2013-07-21 20:18:38.721464 [DEBUG] switch_core_session.c:1542 Session 44 (sofia/internal/1002@domain.com) Locked, Waiting on external entities 2013-07-21 20:18:38.721464 [NOTICE] switch_core_session.c:1560 Session 44 (sofia/internal/1002@domain.com) Ended 2013-07-21 20:18:38.721464 [NOTICE] switch_core_session.c:1564 Close Channel sofia/internal/1002@domain.com [CS_DESTROY] 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/1002@domain.com) Callstate Change HANGUP -> DOWN 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/1002@domain.com) Running State Change CS_DESTROY 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/1002@domain.com) State DESTROY 2013-07-21 20:18:38.721464 [DEBUG] mod_sofia.c:397 sofia/internal/1002@domain.com SOFIA DESTROY 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1002@domain.com Standard DESTROY 2013-07-21 20:18:38.721464 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/1002@domain.com) State DESTROY going to sleep -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/FS-not-supporting-ZRTP-MITM-tp... Sent from the freeswitch-users mailing list archive at Nabble.com.