========= DIAL PLAN ========= ================== ORIGINATES I TRIED ================== originate {fax_verbose=true,ignore_early_media=true}sofia/internal/RECVFAXEXT@192.168.56.101 SENDFAXEXT XML default_context mycallername +123456 originate {ignore_early_media=true,absolute_codec_string='PCMU,PCMA',fax_enable_t38=true,fax_verbose=true,fax_use_ecm=true,fax_enable_t38_request=true}sofia/internal/RECVFAXEXT@192.168.56.101 SENDFAXEXT XML default_context mycallername +123456 originate {ignore_early_media=true,absolute_codec_string='PCMU,PCMA',fax_enable_t38=true,fax_verbose=true,fax_use_ecm=false,fax_enable_t38_request=false}sofia/internal/RECVFAXEXT@192.168.56.101 SENDFAXEXT XML default_context mycallername +123456 ==================== ORIGINATE RESULT LOG ==================== +OK log level [7] freeswitch@debian> originate {fax_verbose=true,ignore_early_media=true}sofia/internal/RECVFAXEXT@192.168.56.101 SENDFAXEXT XML default_context mycallername +123456 +OK b82fdeb1-d954-4159-9778-7fde1ab67680 2017-06-13 09:41:48.481892 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-06-13 09:41:48.481892 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/RECVFAXEXT@192.168.56.101 [b82fdeb1-d954-4159-9778-7fde1ab67680] 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:4818 (sofia/internal/RECVFAXEXT@192.168.56.101) State Change CS_NEW -> CS_INIT 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/RECVFAXEXT@192.168.56.101) Running State Change CS_INIT (Cur 1 Tot 1) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/RECVFAXEXT@192.168.56.101) State INIT 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:90 sofia/internal/RECVFAXEXT@192.168.56.101 SOFIA INIT 2017-06-13 09:41:48.481892 [DEBUG] sofia_glue.c:1295 sofia/internal/RECVFAXEXT@192.168.56.101 sending invite version: 1.6.17 -34-0fc0946 64bit Local SDP: v=0 o=FreeSWITCH 1497339796 1497339797 IN IP4 192.168.56.101 s=FreeSWITCH c=IN IP4 192.168.56.101 t=0 0 m=audio 21512 RTP/AVP 0 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv 2017-06-13 09:41:48.481892 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/+123456@192.168.56.101 [79f2c010-499c-41cf-bc2e-a8fbab1e558d] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:40 sofia/internal/RECVFAXEXT@192.168.56.101 Standard INIT 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/RECVFAXEXT@192.168.56.101) State Change CS_INIT -> CS_ROUTING 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/RECVFAXEXT@192.168.56.101) State INIT going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/RECVFAXEXT@192.168.56.101) Running State Change CS_ROUTING (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/RECVFAXEXT@192.168.56.101 entering state [calling][0] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/RECVFAXEXT@192.168.56.101) State ROUTING 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:143 sofia/internal/RECVFAXEXT@192.168.56.101 SOFIA ROUTING 2017-06-13 09:41:48.481892 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/RECVFAXEXT@192.168.56.101) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/RECVFAXEXT@192.168.56.101) State ROUTING going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/RECVFAXEXT@192.168.56.101) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/RECVFAXEXT@192.168.56.101) State CONSUME_MEDIA 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/RECVFAXEXT@192.168.56.101) State CONSUME_MEDIA going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+123456@192.168.56.101) Running State Change CS_NEW (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:9834 sofia/internal/+123456@192.168.56.101 receiving invite from 192.168.56.101:5060 version: 1.6.17 -34-0fc0946 64bit 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/+123456@192.168.56.101 entering state [received][100] 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=FreeSWITCH 1497339796 1497339797 IN IP4 192.168.56.101 s=FreeSWITCH c=IN IP4 192.168.56.101 t=0 0 m=audio 21512 RTP/AVP 0 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/+123456@192.168.56.101 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2017-06-13 09:41:48.481892 [DEBUG] switch_core_codec.c:111 sofia/internal/+123456@192.168.56.101 Original read codec set to PCMU:0 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4754 sofia/internal/+123456@192.168.56.101 Set 2833 dtmf send payload to 101 recv payload to 101 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7471 (sofia/internal/+123456@192.168.56.101) State Change CS_NEW -> CS_INIT 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/+123456@192.168.56.101) State NEW 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+123456@192.168.56.101) Running State Change CS_INIT (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/+123456@192.168.56.101) State INIT 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:90 sofia/internal/+123456@192.168.56.101 SOFIA INIT 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:40 sofia/internal/+123456@192.168.56.101 Standard INIT 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/+123456@192.168.56.101) State Change CS_INIT -> CS_ROUTING 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/+123456@192.168.56.101) State INIT going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+123456@192.168.56.101) Running State Change CS_ROUTING (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_channel.c:2249 (sofia/internal/+123456@192.168.56.101) Callstate Change DOWN -> RINGING 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/+123456@192.168.56.101) State ROUTING 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:143 sofia/internal/+123456@192.168.56.101 SOFIA ROUTING 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:236 sofia/internal/+123456@192.168.56.101 Standard ROUTING 2017-06-13 09:41:48.481892 [INFO] mod_dialplan_xml.c:637 Processing mycallername <+123456>->RECVFAXEXT in context default_context Dialplan: sofia/internal/+123456@192.168.56.101 parsing [default_context->send_fax] continue=false Dialplan: sofia/internal/+123456@192.168.56.101 Regex (FAIL) [send_fax] destination_number(RECVFAXEXT) =~ /SENDFAXEXT/ break=on-false Dialplan: sofia/internal/+123456@192.168.56.101 parsing [default_context->recv_fax] continue=false Dialplan: sofia/internal/+123456@192.168.56.101 Regex (PASS) [recv_fax] destination_number(RECVFAXEXT) =~ /RECVFAXEXT/ break=on-false Dialplan: sofia/internal/+123456@192.168.56.101 Action answer() Dialplan: sofia/internal/+123456@192.168.56.101 Action log(ALERT inside recv_fax) Dialplan: sofia/internal/+123456@192.168.56.101 Action rxfax(/tmp/rx.tiff) Dialplan: sofia/internal/+123456@192.168.56.101 Action hangup() 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/+123456@192.168.56.101) State Change CS_ROUTING -> CS_EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/+123456@192.168.56.101) State ROUTING going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+123456@192.168.56.101) Running State Change CS_EXECUTE (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/+123456@192.168.56.101) State EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:198 sofia/internal/+123456@192.168.56.101 SOFIA EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:328 sofia/internal/+123456@192.168.56.101 Standard EXECUTE EXECUTE sofia/internal/+123456@192.168.56.101 answer() 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/+123456@192.168.56.101] 192.168.56.101 port 31130 -> 192.168.56.101 port 21512 codec: 0 ms: 20 2017-06-13 09:41:48.481892 [DEBUG] switch_rtp.c:4114 Not using a timer 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7166 sofia/internal/+123456@192.168.56.101 Set 2833 dtmf send payload to 101 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7173 sofia/internal/+123456@192.168.56.101 Set 2833 dtmf receive payload to 101 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7196 sofia/internal/+123456@192.168.56.101 Set rtp dtmf delay to 40 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7202 Set comfort noise payload to 13 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/+123456@192.168.56.101: v=0 o=FreeSWITCH 1497330178 1497330179 IN IP4 192.168.56.101 s=FreeSWITCH c=IN IP4 192.168.56.101 t=0 0 m=audio 31130 RTP/AVP 0 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv 2017-06-13 09:41:48.481892 [INFO] sofia.c:1279 sofia/internal/RECVFAXEXT@192.168.56.101 Update Callee ID to "RECVFAXEXT" 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/RECVFAXEXT@192.168.56.101 entering state [completing][200] 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=FreeSWITCH 1497330178 1497330179 IN IP4 192.168.56.101 s=FreeSWITCH c=IN IP4 192.168.56.101 t=0 0 m=audio 31130 RTP/AVP 0 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/RECVFAXEXT@192.168.56.101 entering state [ready][200] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/RECVFAXEXT@192.168.56.101 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2017-06-13 09:41:48.481892 [DEBUG] switch_core_codec.c:111 sofia/internal/RECVFAXEXT@192.168.56.101 Original read codec set to PCMU:0 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:4754 sofia/internal/RECVFAXEXT@192.168.56.101 Set 2833 dtmf send payload to 101 recv payload to 101 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/RECVFAXEXT@192.168.56.101] 192.168.56.101 port 21512 -> 192.168.56.101 port 31130 codec: 0 ms: 20 2017-06-13 09:41:48.481892 [DEBUG] switch_rtp.c:4114 Not using a timer 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/+123456@192.168.56.101 entering state [completed][200] 2017-06-13 09:41:48.481892 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/+123456@192.168.56.101] has been answered 2017-06-13 09:41:48.481892 [DEBUG] switch_channel.c:3772 (sofia/internal/+123456@192.168.56.101) Callstate Change RINGING -> ACTIVE 2017-06-13 09:41:48.481892 [DEBUG] sofia.c:7048 Channel sofia/internal/+123456@192.168.56.101 entering state [ready][200] EXECUTE sofia/internal/+123456@192.168.56.101 log(ALERT inside recv_fax) 2017-06-13 09:41:48.481892 [ALERT] mod_dptools.c:1724 inside recv_fax EXECUTE sofia/internal/+123456@192.168.56.101 rxfax(/tmp/rx.tiff) 2017-06-13 09:41:48.481892 [DEBUG] mod_spandsp_fax.c:1448 Raw read codec activation Success L16 20000 2017-06-13 09:41:48.481892 [DEBUG] switch_core_codec.c:223 sofia/internal/+123456@192.168.56.101 Push codec L16:100 2017-06-13 09:41:48.481892 [DEBUG] mod_spandsp_fax.c:1466 Raw write codec activation Success L16 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7166 sofia/internal/RECVFAXEXT@192.168.56.101 Set 2833 dtmf send payload to 101 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7173 sofia/internal/RECVFAXEXT@192.168.56.101 Set 2833 dtmf receive payload to 101 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7196 sofia/internal/RECVFAXEXT@192.168.56.101 Set rtp dtmf delay to 40 2017-06-13 09:41:48.481892 [DEBUG] switch_core_media.c:7202 Set comfort noise payload to 13 2017-06-13 09:41:48.481892 [NOTICE] sofia.c:8182 Channel [sofia/internal/RECVFAXEXT@192.168.56.101] has been answered 2017-06-13 09:41:48.481892 [DEBUG] switch_channel.c:3772 (sofia/internal/RECVFAXEXT@192.168.56.101) Callstate Change DOWN -> ACTIVE 2017-06-13 09:41:48.481892 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/RECVFAXEXT@192.168.56.101] 2017-06-13 09:41:48.481892 [DEBUG] switch_ivr.c:2165 (sofia/internal/RECVFAXEXT@192.168.56.101) State Change CS_CONSUME_MEDIA -> CS_ROUTING 2017-06-13 09:41:48.481892 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/RECVFAXEXT@192.168.56.101 to XML[SENDFAXEXT@default_context] 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/RECVFAXEXT@192.168.56.101) Running State Change CS_ROUTING (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/RECVFAXEXT@192.168.56.101) State ROUTING 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:143 sofia/internal/RECVFAXEXT@192.168.56.101 SOFIA ROUTING 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:236 sofia/internal/RECVFAXEXT@192.168.56.101 Standard ROUTING 2017-06-13 09:41:48.481892 [INFO] mod_dialplan_xml.c:637 Processing mycallername <+123456>->SENDFAXEXT in context default_context Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 parsing [default_context->send_fax] continue=false Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 Regex (PASS) [send_fax] destination_number(SENDFAXEXT) =~ /SENDFAXEXT/ break=on-false Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 Action answer() Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 Action log(ALERT inside sendfax destination: ${destination_number}) Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 Action txfax(/tmp/tx.tiff) Dialplan: sofia/internal/RECVFAXEXT@192.168.56.101 Action hangup() 2017-06-13 09:41:48.481892 [INFO] switch_channel.c:3129 sofia/internal/RECVFAXEXT@192.168.56.101 Flipping CID from "mycallername" <+123456> to "RECVFAXEXT" 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/RECVFAXEXT@192.168.56.101) State Change CS_ROUTING -> CS_EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/RECVFAXEXT@192.168.56.101) State ROUTING going to sleep 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/RECVFAXEXT@192.168.56.101) Running State Change CS_EXECUTE (Cur 2 Tot 2) 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/RECVFAXEXT@192.168.56.101) State EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] mod_sofia.c:198 sofia/internal/RECVFAXEXT@192.168.56.101 SOFIA EXECUTE 2017-06-13 09:41:48.481892 [DEBUG] switch_core_state_machine.c:328 sofia/internal/RECVFAXEXT@192.168.56.101 Standard EXECUTE EXECUTE sofia/internal/RECVFAXEXT@192.168.56.101 answer() EXECUTE sofia/internal/RECVFAXEXT@192.168.56.101 log(ALERT inside sendfax destination: SENDFAXEXT) 2017-06-13 09:41:48.481892 [ALERT] mod_dptools.c:1724 inside sendfax destination: SENDFAXEXT EXECUTE sofia/internal/RECVFAXEXT@192.168.56.101 txfax(/tmp/tx.tiff) 2017-06-13 09:41:48.521420 [DEBUG] mod_spandsp_fax.c:1448 Raw read codec activation Success L16 20000 2017-06-13 09:41:48.521420 [DEBUG] switch_core_codec.c:223 sofia/internal/RECVFAXEXT@192.168.56.101 Push codec L16:100 2017-06-13 09:41:48.521420 [DEBUG] mod_spandsp_fax.c:1466 Raw write codec activation Success L16