freeswitch@ip-172-31-55-240> 2018-01-16 23:05:10.896861 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:05:11.256826 [INFO] mod_pocketsphinx.c:644 PocketSphinx Reloaded
2018-01-16 23:05:11.256826 [INFO] mod_enum.c:879 ENUM Reloaded
2018-01-16 23:05:11.256826 [DEBUG] mod_spandsp.c:680 Setting tone detector debug-level to : 9
2018-01-16 23:05:11.256826 [INFO] switch_time.c:1423 Timezone reloaded 530 definitions
2018-01-16 23:05:20.896861 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:05:21.416930 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-01-16 23:05:21.416930 [NOTICE] switch_channel.c:1104 New Channel sofia/external/12158258773 [ba2692d2-fb11-11e7-9319-455b975e6257]
2018-01-16 23:05:21.416930 [DEBUG] mod_sofia.c:4819 (sofia/external/12158258773) State Change CS_NEW -> CS_INIT
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_INIT (Cur 1 Tot 1)
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:627 (sofia/external/12158258773) State INIT
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:627 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:21.416930 [DEBUG] mod_sofia.c:90 sofia/external/12158258773 SOFIA INIT
2018-01-16 23:05:21.416930 [DEBUG] sofia_glue.c:1295 sofia/external/12158258773 sending invite version: 1.6.19  64bit
Local SDP:
v=0
o=FreeSWITCH 1516125843 1516125844 IN IP4 52.90.40.222
s=FreeSWITCH
c=IN IP4 52.90.40.222
t=0 0
m=audio 18078 RTP/AVP 0 8 3 101
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

2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:40 sofia/external/12158258773 Standard INIT
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:48 (sofia/external/12158258773) State Change CS_INIT -> CS_ROUTING
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:627 (sofia/external/12158258773) State INIT going to sleep
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_ROUTING (Cur 1 Tot 1)
2018-01-16 23:05:21.416930 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [calling][0]
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:643 (sofia/external/12158258773) State ROUTING
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:643 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:21.416930 [DEBUG] mod_sofia.c:143 sofia/external/12158258773 SOFIA ROUTING
2018-01-16 23:05:21.416930 [DEBUG] switch_ivr_originate.c:67 (sofia/external/12158258773) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:643 (sofia/external/12158258773) State ROUTING going to sleep
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 1)
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:662 (sofia/external/12158258773) State CONSUME_MEDIA
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:662 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:21.416930 [DEBUG] switch_core_state_machine.c:662 (sofia/external/12158258773) State CONSUME_MEDIA going to sleep
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:701 sofia/external/12158258773 session thread sleep state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:705 sofia/external/12158258773 session thread wake state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.416930 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [calling][0]
2018-01-16 23:05:21.416930 [ALERT] switch_core_state_machine.c:701 sofia/external/12158258773 session thread sleep state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.736879 [ALERT] switch_core_state_machine.c:705 sofia/external/12158258773 session thread wake state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.736879 [ALERT] sofia.c:1274 sofia/external/12158258773 Same Callee ID "Outbound Call" <12158258773>
2018-01-16 23:05:21.736879 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [proceeding][180]
2018-01-16 23:05:21.736879 [NOTICE] sofia.c:7192 Ring-Ready sofia/external/12158258773!
2018-01-16 23:05:21.736879 [DEBUG] switch_channel.c:3346 (sofia/external/12158258773) Callstate Change DOWN -> RINGING
2018-01-16 23:05:21.736879 [ALERT] sofia.c:7192 sofia/external/12158258773 receive message [RING_EVENT]
2018-01-16 23:05:21.736879 [ALERT] switch_core_state_machine.c:701 sofia/external/12158258773 session thread sleep state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.816928 [ALERT] switch_core_state_machine.c:705 sofia/external/12158258773 session thread wake state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:447 Looking for zrtp-hash
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:402 Deciding whether to pass zrtp-hash between legs
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:404 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2018-01-16 23:05:21.816928 [ALERT] sofia.c:1274 sofia/external/12158258773 Same Callee ID "Outbound Call" <12158258773>
2018-01-16 23:05:21.816928 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [completing][200]
2018-01-16 23:05:21.816928 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=Sippy 3369124320713125429 1 IN IP4 8.34.182.111
s=iFAX
t=0 0
m=audio 21516 RTP/AVP 0 101
c=IN IP4 8.34.182.100
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20

2018-01-16 23:05:21.816928 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [ready][200]
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:447 Looking for zrtp-hash
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:402 Deciding whether to pass zrtp-hash between legs
2018-01-16 23:05:21.816928 [ALERT] switch_core_media.c:404 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/12158258773 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-01-16 23:05:21.816928 [DEBUG] switch_core_codec.c:111 sofia/external/12158258773 Original read codec set to PCMU:0
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:4767 sofia/external/12158258773 Set 2833 dtmf send payload to 101 recv payload to 101
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/12158258773] 172.31.55.240 port 18078 -> 8.34.182.100 port 21516 codec: 0 ms: 20
2018-01-16 23:05:21.816928 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:7179 sofia/external/12158258773 Set 2833 dtmf send payload to 101
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:7186 sofia/external/12158258773 Set 2833 dtmf receive payload to 101
2018-01-16 23:05:21.816928 [DEBUG] switch_core_media.c:7209 sofia/external/12158258773 Set rtp dtmf delay to 40
2018-01-16 23:05:21.816928 [NOTICE] sofia.c:8218 Channel [sofia/external/12158258773] has been answered
2018-01-16 23:05:21.816928 [DEBUG] switch_channel.c:3773 (sofia/external/12158258773) Callstate Change RINGING -> ACTIVE
2018-01-16 23:05:21.816928 [ALERT] sofia.c:8218 sofia/external/12158258773 receive message [ANSWER_EVENT]
2018-01-16 23:05:21.816928 [ALERT] switch_core_state_machine.c:701 sofia/external/12158258773 session thread sleep state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.856943 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/external/12158258773]
2018-01-16 23:05:21.856943 [INFO] switch_channel.c:3129 sofia/external/12158258773 Flipping CID from "" <0000000000> to "Outbound Call" <12158258773>
2018-01-16 23:05:21.856943 [DEBUG] mod_commands.c:4862 (sofia/external/12158258773) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2018-01-16 23:05:21.856943 [ALERT] switch_core_state_machine.c:705 sofia/external/12158258773 session thread wake state: CS_CONSUME_MEDIA!
2018-01-16 23:05:21.856943 [ALERT] switch_ivr_originate.c:4038 sofia/external/12158258773 receive message [AUDIO_SYNC]
2018-01-16 23:05:21.856943 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2018-01-16 23:05:21.856943 [DEBUG] switch_core_state_machine.c:650 (sofia/external/12158258773) State EXECUTE
2018-01-16 23:05:21.856943 [ALERT] switch_core_state_machine.c:650 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:21.856943 [DEBUG] mod_sofia.c:198 sofia/external/12158258773 SOFIA EXECUTE
2018-01-16 23:05:21.856943 [DEBUG] switch_core_state_machine.c:328 sofia/external/12158258773 Standard EXECUTE
2018-01-16 23:05:21.856943 [ALERT] switch_core_session.c:2587 sofia/external/12158258773 Send KeyFrame
EXECUTE sofia/external/12158258773 txfax(/usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif)
2018-01-16 23:05:21.856943 [ALERT] switch_core_session.c:2800 sofia/external/12158258773 receive message [APPLICATION_EXEC]
2018-01-16 23:05:21.856943 [DEBUG] mod_spandsp_fax.c:1448 Raw read codec activation Success L16 20000
2018-01-16 23:05:21.856943 [DEBUG] switch_core_codec.c:223 sofia/external/12158258773 Push codec L16:100
2018-01-16 23:05:21.856943 [DEBUG] mod_spandsp_fax.c:1466 Raw write codec activation Success L16
2018-01-16 23:05:21.856943 [ALERT] switch_ivr.c:217 sofia/external/12158258773 receive message [AUDIO_SYNC]
2018-01-16 23:05:21.856943 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2018-01-16 23:05:21.856943 [ALERT] switch_core_io.c:416 sofia/external/12158258773 receive message [TRANSCODING_NECESSARY]
2018-01-16 23:05:22.216925 [ALERT] switch_rtp.c:1757 Calculated Instantaneous Packet Delay Variation: audio packet 2.000000
2018-01-16 23:05:22.696862 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2018-01-16 23:05:24.096861 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [received][100]
2018-01-16 23:05:24.096861 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=Sippy 3369124320713125429 2 IN IP4 8.34.182.111
s=iFAX
t=0 0
m=image 21516 udptl t38
c=IN IP4 8.34.182.100
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxFillBitRemoval
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:2000
a=T38FaxMaxDatagram:400
a=T38FaxUdpEC:t38UDPRedundancy

2018-01-16 23:05:24.096861 [ALERT] switch_core_media.c:447 Looking for zrtp-hash
2018-01-16 23:05:24.096861 [ALERT] switch_core_media.c:402 Deciding whether to pass zrtp-hash between legs
2018-01-16 23:05:24.096861 [ALERT] switch_core_media.c:404 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2018-01-16 23:05:24.096861 [DEBUG] switch_core_media.c:4041 sofia/external/12158258773 T38 ACCEPT on request
2018-01-16 23:05:24.096861 [DEBUG] switch_core_media.c:4146 sofia/external/12158258773 T38 IS POSSIBLE on request
2018-01-16 23:05:24.116796 [WARNING] mod_spandsp_fax.c:1138 sofia/external/12158258773 already has T.38 data
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1040 T38 SDP Origin = Sippy
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1041 T38FaxVersion = 0
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1042 T38MaxBitRate = 14400
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1043 T38FaxFillBitRemoval = 1
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1044 T38FaxTranscodingMMR = 0
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1045 T38FaxTranscodingJBIG = 0
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1046 T38FaxRateManagement = 'transferredTCF'
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1047 T38FaxMaxBuffer = 2000
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1048 T38FaxMaxDatagram = 400
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1049 T38FaxUdpEC = 't38UDPRedundancy'
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1050 T38VendorInfo = ''
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1051 ip = '8.34.182.100'
2018-01-16 23:05:24.116796 [DEBUG] mod_spandsp_fax.c:1053 port = 21516
2018-01-16 23:05:24.116796 [ALERT] mod_spandsp_fax.c:1096 sofia/external/12158258773 receive message [T38_DESCRIPTION]
2018-01-16 23:05:24.116796 [DEBUG] switch_core_media.c:9750 Remote address:port [8.34.182.100:21516] has not changed.
2018-01-16 23:05:24.116796 [DEBUG] switch_core_media.c:9389 sofia/external/12158258773 image media sdp:
v=0
o=FreeSWITCH 1516125843 1516125845 IN IP4 52.90.40.222
s=FreeSWITCH
c=IN IP4 52.90.40.222
t=0 0
m=image 18078 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxFillBitRemoval
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:2000
a=T38FaxMaxDatagram:400
a=T38FaxUdpEC:t38UDPRedundancy

2018-01-16 23:05:24.116796 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [completed][200]
2018-01-16 23:05:24.116796 [ALERT] mod_spandsp_fax.c:771 sofia/external/12158258773 receive message [UDPTL_MODE]
2018-01-16 23:05:24.116796 [DEBUG] switch_core_media.c:9750 Remote address:port [8.34.182.100:21516] has not changed.
2018-01-16 23:05:24.156842 [DEBUG] sofia.c:7084 Channel sofia/external/12158258773 entering state [ready][200]
2018-01-16 23:05:24.216870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 No signal is present
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 A signal is present
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state T
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase A_CNG to B_RX
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 4
2018-01-16 23:05:26.656857 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 0
2018-01-16 23:05:28.236801 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Type CSI - CRC OK (clean)
2018-01-16 23:05:28.236801 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
2018-01-16 23:05:28.236801 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  CSI without final frame tag
2018-01-16 23:05:28.236801 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 03 40 73 6e 6f 69 74 75 6c 6f 53 58 41 46 69 20 20 20 20 20 20 20
2018-01-16 23:05:28.236801 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Remote gave CSI as: "iFAXSolutions"
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Type DIS - CRC OK (clean)
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  DIS with final frame tag
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 80 00 ee f8 c4 80 10
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state T
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase B_TX
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DIS:
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= V.8 capabilities: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Preferred octets: 256 octets
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Ready to transmit a fax document (polling): Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Can receive fax: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..00= Recording width: 215mm +- 1%
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 10..= Recording length: Unlimited
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= Error correction mode (ECM): ECM
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= T.6 coding: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= "Field not valid" supported: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Multiple selective polling: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Polled sub-address: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= T.43 coding: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Plane interleave: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= R8x15.4lines/mm: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Inch-based resolution preferred: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= Metric-based resolution preferred: Set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Selective polling: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:317 === Negotiation Result =======================================================
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:318 Remote station id: iFAXSolutions
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:319 Local station id:  SpanDSP Fax Ident
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:320 Transfer Rate:     14400
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:322 ECM status         off
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:323 remote country:
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:324 remote vendor:
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:325 remote model:
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:327 ==============================================================================
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Trying to send file '/usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif'
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start sending document
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Choose image type bi-level (0), compression T.4 2-D (4)
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Minimum bits per row will be 0
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Starting page 1 of transfer
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image width is A4 at 8040dpm x 3850dpm
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Put document with modem (7) V.17 at 14400bps
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state T to D
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Sending ident 'SpanDSP Fax Ident'
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  TSI without final frame tag
2018-01-16 23:05:28.576863 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 03 43 74 6e 65 64 49 20 78 61 46 20 50 53 44 6e 61 70 53 20 20 20
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Receive complete in phase B_RX, state D
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state D
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to B_TX
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 4
2018-01-16 23:05:28.596934 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 No signal is present
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state D
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DCS:
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Receive fax: Set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 00..= Selected data signalling rate: V.17 14400bps
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..00= Recording width: 215mm +- 1%
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 10..= Recording length: Unlimited
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Minimum scan line time: 0ms
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  DCS with final frame tag
2018-01-16 23:05:30.296870 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 83 00 a2 78
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state D
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state D
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D to D_TCF
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to C_NON_ECM_TX
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:30.576855 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 7
2018-01-16 23:05:30.896865 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase C_NON_ECM_TX, state D_TCF
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_TX to B_RX
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 4
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 0
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
2018-01-16 23:05:33.936864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D_TCF to D_POST_TCF
2018-01-16 23:05:34.756788 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 A signal is present
2018-01-16 23:05:34.756788 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state D_POST_TCF
2018-01-16 23:05:34.756788 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state D_POST_TCF
2018-01-16 23:05:34.756788 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-flagged
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Type CFR - CRC OK (clean)
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T4-flagged (15520 remaining)
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  CFR with final frame tag
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 84
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state D_POST_TCF
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Trainability test succeeded
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D_POST_TCF to I
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase C_NON_ECM_TX
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Receive complete in phase B_RX, state I
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state I
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to C_NON_ECM_TX
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 7
2018-01-16 23:05:35.816860 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 No signal is present
2018-01-16 23:05:40.896859 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:05:50.896860 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase C_NON_ECM_TX, state I
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_TX to D_TX
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 4
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state I to II_Q
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 No more pages to send
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  EOP with final frame tag
2018-01-16 23:05:53.416805 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 2f
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state II_Q
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state II_Q
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to D_RX
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 4
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 0
2018-01-16 23:05:54.736806 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
2018-01-16 23:05:55.296859 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 A signal is present
2018-01-16 23:05:55.296859 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state II_Q
2018-01-16 23:05:55.296859 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state II_Q
2018-01-16 23:05:55.296859 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-flagged
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Type MCF - CRC OK (clean)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T4-flagged (15680 remaining)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  MCF with final frame tag
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 8c
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state II_Q
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:428 ==== Page Sent ===============================================================
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:429 Page no = 1
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 1094 pixels (1728 x 1078 pixels in the file)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 3850/m (8031/m x 3858/m in the file)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:433 Compression = T.4 2-D (4)
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 31089 bytes
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 0
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 0
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state II_Q to C
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  DCN with final frame tag
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 fb
2018-01-16 23:05:56.336861 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Success - delivered 1 pages
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Receive complete in phase D_RX, state C
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state C
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 4
2018-01-16 23:05:56.356864 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 No signal is present
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Starting final pause before disconnecting
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to E
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 1
2018-01-16 23:05:57.516854 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state C to B
2018-01-16 23:05:57.836793 [NOTICE] sofia.c:1012 Hangup sofia/external/12158258773 [CS_EXECUTE] [NORMAL_CLEARING]
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:496 ==============================================================================
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:500 Fax successfully sent.
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:513 Remote station id: iFAXSolutions
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:514 Local station id:  SpanDSP Fax Ident
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:515 Pages transferred: 1
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:517 Total fax pages:   1
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:518 Image resolution:  8040x3850
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:519 Transfer Rate:     14400
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:521 ECM status         off
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:522 remote country:
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:523 remote vendor:
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:524 remote model:
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:526 ==============================================================================
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state B to CALL_FINISHED
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase E to CALL_FINISHED
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set rx type 9
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T Set tx type 9
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T FAX exchange complete
2018-01-16 23:05:57.836793 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Call completed
2018-01-16 23:05:57.836793 [DEBUG] switch_core_codec.c:248 sofia/external/12158258773 Restore previous codec PCMU:0.
2018-01-16 23:05:57.836793 [ALERT] switch_core_session.c:2815 sofia/external/12158258773 receive message [APPLICATION_EXEC_COMPLETE]
2018-01-16 23:05:57.836793 [DEBUG] switch_core_session.c:2815 sofia/external/12158258773 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:650 (sofia/external/12158258773) State EXECUTE going to sleep
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_HANGUP (Cur 1 Tot 1)
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:850 (sofia/external/12158258773) Callstate Change ACTIVE -> HANGUP
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:852 (sofia/external/12158258773) State HANGUP
2018-01-16 23:05:57.836793 [ALERT] switch_core_state_machine.c:852 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:57.836793 [DEBUG] mod_sofia.c:438 Channel sofia/external/12158258773 hanging up, cause: NORMAL_CLEARING
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:60 sofia/external/12158258773 Standard HANGUP, cause: NORMAL_CLEARING
2018-01-16 23:05:57.836793 [DEBUG] switch_core_state_machine.c:852 (sofia/external/12158258773) State HANGUP going to sleep
2018-01-16 23:05:57.836793 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f02101344d0 Connected.
2018-01-16 23:05:57.836793 [INFO] switch_cpp.cpp:1365 [FAX] info:
'direction: outbound
is_outbound: true
uuid: ba2692d2-fb11-11e7-9319-455b975e6257
session_id: 1
sip_gateway_name: 6f98ceb1-1ad0-478c-a524-69e6808b93b9
sip_invite_domain: sip.t38fax.com
sip_profile_name: gateway
video_media_flow: sendrecv
audio_media_flow: sendrecv
channel_name: sofia/external/12158258773
sip_destination_url: sip%3A12158258773%40sip.t38fax.com%3A5080
for_fax: 1
accountcode: 52.90.40.222
sip_h_X-accountcode: 52.90.40.222
domain_uuid: 76966341-7249-4fc3-98db-c64af81bc376
domain_name: 52.90.40.222
fax_file: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
fax_enable_t38: true
fax_enable_t38_request: true
ignore_early_media: true
fax_uri: sofia/gateway/6f98ceb1-1ad0-478c-a524-69e6808b93b9/12158258773
fax_retry_attempts: 1
fax_retry_limit: 20
fax_retry_sleep: 180
fax_verbose: true
fax_use_ecm: off
api_hangup_hook: lua%20fax_retry.lua
originate_early_media: false
sip_outgoing_contact_uri: %3Csip%3Agw%2B6f98ceb1-1ad0-478c-a524-69e6808b93b9%4052.90.40.222%3A5080%3Btransport%3Dudp%3Bgw%3D6f98ceb1-1ad0-478c-a524-69e6808b93b9%3E
sip_req_uri: 12158258773%40sip.t38fax.com%3A5080
sofia_profile_name: external
recovery_profile_name: external
sip_local_network_addr: 52.90.40.222
sip_reply_host: 8.34.182.111
sip_reply_port: 5080
sip_network_ip: 8.34.182.111
sip_network_port: 5080
ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b
sip_allow: INVITE,%20ACK,%20BYE,%20CANCEL,%20INFO,%20SUBSCRIBE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS,%20UPDATE
sip_invite_route_uri: %3Csip%3A8.34.182.111%3A5080%3Btransport%3Dudp%3Blr%3Bdrr%3E,%3Csip%3A8.34.182.111%3A5060%3Btransport%3Dudp%3Blr%3Bdrr%3E
sip_invite_record_route: %3Csip%3A8.34.182.111%3A5060%3Btransport%3Dudp%3Blr%3Bdrr%3E,%3Csip%3A8.34.182.111%3A5080%3Btransport%3Dudp%3Blr%3Bdrr%3E
sip_from_user: 0000000000
sip_from_uri: 0000000000%40sip.t38fax.com
sip_from_host: sip.t38fax.com
sip_to_user: 12158258773
sip_to_port: 5080
sip_to_uri: 12158258773%40sip.t38fax.com%3A5080
sip_to_host: sip.t38fax.com
sip_contact_user: nobody
sip_contact_port: 5061
sip_contact_uri: nobody%408.34.182.111%3A5061
sip_contact_host: 8.34.182.111
rtp_audio_recv_pt: 0
rtp_use_codec_name: PCMU
rtp_use_codec_rate: 8000
rtp_use_codec_ptime: 20
rtp_use_codec_channels: 1
rtp_last_audio_codec_string: PCMU%408000h%4020i%401c
original_read_codec: PCMU
original_read_rate: 8000
write_codec: PCMU
write_rate: 8000
dtmf_type: rfc2833
local_media_ip: 172.31.55.240
local_media_port: 18078
advertised_media_ip: 52.90.40.222
rtp_use_timer_name: soft
rtp_use_pt: 0
rtp_use_ssrc: 1852424801
rtp_2833_send_payload: 101
rtp_2833_recv_payload: 101
remote_media_ip: 8.34.182.100
remote_media_port: 21516
endpoint_disposition: ANSWER
pre_transfer_caller_id_number: 0000000000
call_uuid: ba2692d2-fb11-11e7-9319-455b975e6257
current_application_data: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
current_application: txfax
switch_r_sdp: v%3D0%0D%0Ao%3DSippy%203369124320713125429%202%20IN%20IP4%208.34.182.111%0D%0As%3DiFAX%0D%0At%3D0%200%0D%0Am%3Dimage%2021516%20udptl%20t38%0D%0Ac%3DIN%20IP4%208.34.182.100%0D%0Aa%3DT38FaxVersion%3A0%0D%0Aa%3DT38MaxBitRate%3A14400%0D%0Aa%3DT38FaxFillBitRemoval%0D%0Aa%3DT38FaxRateManagement%3AtransferredTCF%0D%0Aa%3DT38FaxMaxBuffer%3A2000%0D%0Aa%3DT38FaxMaxDatagram%3A400%0D%0Aa%3DT38FaxUdpEC%3At38UDPRedundancy%0D%0A
rtp_use_codec_string: PCMU,PCMA,GSM
has_t38: true
rtp_local_sdp_str: v%3D0%0D%0Ao%3DFreeSWITCH%201516125843%201516125845%20IN%20IP4%2052.90.40.222%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%2052.90.40.222%0D%0At%3D0%200%0D%0Am%3Dimage%2018078%20udptl%20t38%0D%0Aa%3DT38FaxVersion%3A0%0D%0Aa%3DT38MaxBitRate%3A14400%0D%0Aa%3DT38FaxFillBitRemoval%0D%0Aa%3DT38FaxRateManagement%3AtransferredTCF%0D%0Aa%3DT38FaxMaxBuffer%3A2000%0D%0Aa%3DT38FaxMaxDatagram%3A400%0D%0Aa%3DT38FaxUdpEC%3At38UDPRedundancy%0D%0A
fax_v17_disabled: 0
fax_ecm_requested: 0
fax_filename: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
sip_to_tag: HZXUvmZ2t83gH
sip_from_tag: 5hztxl73e4pjapwj.i
sip_cseq: 580
sip_call_id: 91855555-75b4-1236-4ea9-12266285acf2
sip_recover_contact: %3Csip%3A8.34.182.111%3A5061%3E
sip_full_via: SIP/2.0/UDP%208.34.182.111%3A5080%3Bbranch%3Dz9hG4bK-524287-1---432f9c22e291825f%3Brport%3D5080,SIP/2.0/UDP%208.34.182.111%3A5061%3Brport%3D5061%3Bbranch%3Dz9hG4bK-wg7zipzy7vbj6qva
sip_recover_via: SIP/2.0/UDP%208.34.182.111%3A5080%3Bbranch%3Dz9hG4bK-524287-1---432f9c22e291825f%3Brport%3D5080,SIP/2.0/UDP%208.34.182.111%3A5061%3Brport%3D5061%3Bbranch%3Dz9hG4bK-wg7zipzy7vbj6qva
sip_full_from: %3Csip%3A12158258773%40sip.t38fax.com%3A5080%3E%3Btag%3D5hztxl73e4pjapwj.i
sip_full_to: %3Csip%3A0000000000%40sip.t38fax.com%3E%3Btag%3DHZXUvmZ2t83gH
fax_file_image_resolution: 8031x3858
fax_image_pixel_size: 1728x1094
fax_file_image_pixel_size: 1728x1078
fax_longest_bad_row_run: 0
fax_encoding: 4
fax_encoding_name: T.4%202-D
sip_term_status: 200
proto_specific_hangup_cause: sip%3A200
sip_term_cause: 16
sip_user_agent: Sippy
sip_hangup_disposition: recv_bye
fax_success: 1
fax_result_code: 0
fax_result_text: OK
fax_ecm_used: off
fax_local_station_id: SpanDSP%20Fax%20Ident
fax_remote_station_id: iFAXSolutions
fax_document_transferred_pages: 1
fax_document_total_pages: 1
fax_image_resolution: 8040x3850
fax_image_size: 31089
fax_bad_rows: 0
fax_transfer_rate: 14400
read_codec: PCMU
read_rate: 8000
hangup_cause: NORMAL_CLEARING
hangup_cause_q850: 16
digits_dialed: none
start_stamp: 2018-01-16%2023%3A05%3A21
profile_start_stamp: 2018-01-16%2023%3A05%3A21
answer_stamp: 2018-01-16%2023%3A05%3A21
progress_stamp: 2018-01-16%2023%3A05%3A21
end_stamp: 2018-01-16%2023%3A05%3A57
start_epoch: 1516143921
start_uepoch: 1516143921416930
profile_start_epoch: 1516143921
profile_start_uepoch: 1516143921416930
answer_epoch: 1516143921
answer_uepoch: 1516143921816928
bridge_epoch: 0
bridge_uepoch: 0
last_hold_epoch: 0
last_hold_uepoch: 0
hold_accum_seconds: 0
hold_accum_usec: 0
hold_accum_ms: 0
resurrect_epoch: 0
resurrect_uepoch: 0
progress_epoch: 1516143921
progress_uepoch: 1516143921736879
progress_media_epoch: 0
progress_media_uepoch: 0
end_epoch: 1516143957
end_uepoch: 1516143957836793
last_app: txfax
last_arg: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
caller_id: %22Outbound%20Call%22%20%3C12158258773%3E
duration: 36
billsec: 36
progresssec: 0
answersec: 0
waitsec: 0
progress_mediasec: 0
flow_billsec: 36
mduration: 36420
billmsec: 36020
progressmsec: 320
answermsec: 400
waitmsec: 0
progress_mediamsec: 0
flow_billmsec: 36420
uduration: 36419863
billusec: 36019865
progressusec: 319949
answerusec: 399998
waitusec: 0
progress_mediausec: 0
flow_billusec: 36419863
rtp_audio_in_raw_bytes: 22984
rtp_audio_in_media_bytes: 21608
rtp_audio_in_packet_count: 203
rtp_audio_in_media_packet_count: 195
rtp_audio_in_skip_packet_count: 14
rtp_audio_in_jitter_packet_count: 0
rtp_audio_in_dtmf_packet_count: 0
rtp_audio_in_cng_packet_count: 0
rtp_audio_in_flush_packet_count: 8
rtp_audio_in_largest_jb_size: 0
rtp_audio_in_jitter_min_variance: 20.09
rtp_audio_in_jitter_max_variance: 80.36
rtp_audio_in_jitter_loss_rate: 0.00
rtp_audio_in_jitter_burst_rate: 0.00
rtp_audio_in_mean_interval: 20.20
rtp_audio_in_flaw_total: 0
rtp_audio_in_quality_percentage: 100.00
rtp_audio_in_mos: 4.50
rtp_audio_out_raw_bytes: 175535
rtp_audio_out_media_bytes: 175535
rtp_audio_out_packet_count: 818
rtp_audio_out_media_packet_count: 818
rtp_audio_out_skip_packet_count: 0
rtp_audio_out_dtmf_packet_count: 0
rtp_audio_out_cng_packet_count: 0
rtp_audio_rtcp_packet_count: 0
rtp_audio_rtcp_octet_count: 0
Channel-State: CS_HANGUP
Channel-Call-State: HANGUP
Channel-State-Number: 10
Channel-Name: sofia/external/12158258773
Unique-ID: ba2692d2-fb11-11e7-9319-455b975e6257
Call-Direction: outbound
Presence-Call-Direction: outbound
Channel-HIT-Dialplan: true
Channel-Call-UUID: ba2692d2-fb11-11e7-9319-455b975e6257
Answer-State: hangup
Hangup-Cause: NORMAL_CLEARING
Channel-Read-Codec-Name: PCMU
Channel-Read-Codec-Rate: 8000
Channel-Read-Codec-Bit-Rate: 64000
Channel-Write-Codec-Name: PCMU
Channel-Write-Codec-Rate: 8000
Channel-Write-Codec-Bit-Rate: 64000
Caller-Direction: outbound
Caller-Logical-Direction: outbound
Caller-Caller-ID-Name: Outbound%20Call
Caller-Caller-ID-Number: 12158258773
Caller-Orig-Caller-ID-Number: 0000000000
Caller-Callee-ID-Number: 0000000000
Caller-Network-Addr: 8.34.182.111
Caller-ANI: 0000000000
Caller-Destination-Number: 12158258773
Caller-Unique-ID: ba2692d2-fb11-11e7-9319-455b975e6257
Caller-Source: src/switch_ivr_originate.c
Caller-Context: default
Caller-Channel-Name: sofia/external/12158258773
Caller-Profile-Index: 1
Caller-Profile-Created-Time: 1516143921416930
Caller-Channel-Created-Time: 1516143921416930
Caller-Channel-Answered-Time: 1516143921816928
Caller-Channel-Progress-Time: 1516143921736879
Caller-Channel-Progress-Media-Time: 0
Caller-Channel-Hangup-Time: 1516143957836793
Caller-Channel-Transfer-Time: 0
Caller-Channel-Resurrect-Time: 0
Caller-Channel-Bridged-Time: 0
Caller-Channel-Last-Hold: 0
Caller-Channel-Hold-Accum: 0
Caller-Screen-Bit: true
Caller-Privacy-Hide-Name: false
Caller-Privacy-Hide-Number: false
variable_direction: outbound
variable_is_outbound: true
variable_uuid: ba2692d2-fb11-11e7-9319-455b975e6257
variable_session_id: 1
variable_sip_gateway_name: 6f98ceb1-1ad0-478c-a524-69e6808b93b9
variable_sip_invite_domain: sip.t38fax.com
variable_sip_profile_name: gateway
variable_video_media_flow: sendrecv
variable_audio_media_flow: sendrecv
variable_channel_name: sofia/external/12158258773
variable_sip_destination_url: sip%3A12158258773%40sip.t38fax.com%3A5080
variable_for_fax: 1
variable_accountcode: 52.90.40.222
variable_sip_h_X-accountcode: 52.90.40.222
variable_domain_uuid: 76966341-7249-4fc3-98db-c64af81bc376
variable_domain_name: 52.90.40.222
variable_fax_file: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
variable_fax_enable_t38: true
variable_fax_enable_t38_request: true
variable_ignore_early_media: true
variable_fax_uri: sofia/gateway/6f98ceb1-1ad0-478c-a524-69e6808b93b9/12158258773
variable_fax_retry_attempts: 1
variable_fax_retry_limit: 20
variable_fax_retry_sleep: 180
variable_fax_verbose: true
variable_fax_use_ecm: off
variable_api_hangup_hook: lua%20fax_retry.lua
variable_originate_early_media: false
variable_sip_outgoing_contact_uri: %3Csip%3Agw%2B6f98ceb1-1ad0-478c-a524-69e6808b93b9%4052.90.40.222%3A5080%3Btransport%3Dudp%3Bgw%3D6f98ceb1-1ad0-478c-a524-69e6808b93b9%3E
variable_sip_req_uri: 12158258773%40sip.t38fax.com%3A5080
variable_sofia_profile_name: external
variable_recovery_profile_name: external
variable_sip_local_network_addr: 52.90.40.222
variable_sip_reply_host: 8.34.182.111
variable_sip_reply_port: 5080
variable_sip_network_ip: 8.34.182.111
variable_sip_network_port: 5080
variable_ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b
variable_sip_allow: INVITE,%20ACK,%20BYE,%20CANCEL,%20INFO,%20SUBSCRIBE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS,%20UPDATE
variable_sip_invite_route_uri: %3Csip%3A8.34.182.111%3A5080%3Btransport%3Dudp%3Blr%3Bdrr%3E,%3Csip%3A8.34.182.111%3A5060%3Btransport%3Dudp%3Blr%3Bdrr%3E
variable_sip_invite_record_route: %3Csip%3A8.34.182.111%3A5060%3Btransport%3Dudp%3Blr%3Bdrr%3E,%3Csip%3A8.34.182.111%3A5080%3Btransport%3Dudp%3Blr%3Bdrr%3E
variable_sip_from_user: 0000000000
variable_sip_from_uri: 0000000000%40sip.t38fax.com
variable_sip_from_host: sip.t38fax.com
variable_sip_to_user: 12158258773
variable_sip_to_port: 5080
variable_sip_to_uri: 12158258773%40sip.t38fax.com%3A5080
variable_sip_to_host: sip.t38fax.com
variable_sip_contact_user: nobody
variable_sip_contact_port: 5061
variable_sip_contact_uri: nobody%408.34.182.111%3A5061
variable_sip_contact_host: 8.34.182.111
variable_rtp_audio_recv_pt: 0
variable_rtp_use_codec_name: PCMU
variable_rtp_use_codec_rate: 8000
variable_rtp_use_codec_ptime: 20
variable_rtp_use_codec_channels: 1
variable_rtp_last_audio_codec_string: PCMU%408000h%4020i%401c
variable_original_read_codec: PCMU
variable_original_read_rate: 8000
variable_write_codec: PCMU
variable_write_rate: 8000
variable_dtmf_type: rfc2833
variable_local_media_ip: 172.31.55.240
variable_local_media_port: 18078
variable_advertised_media_ip: 52.90.40.222
variable_rtp_use_timer_name: soft
variable_rtp_use_pt: 0
variable_rtp_use_ssrc: 1852424801
variable_rtp_2833_send_payload: 101
variable_rtp_2833_recv_payload: 101
variable_remote_media_ip: 8.34.182.100
variable_remote_media_port: 21516
variable_endpoint_disposition: ANSWER
variable_pre_transfer_caller_id_number: 0000000000
variable_call_uuid: ba2692d2-fb11-11e7-9319-455b975e6257
variable_current_application_data: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
variable_current_application: txfax
variable_switch_r_sdp: v%3D0%0D%0Ao%3DSippy%203369124320713125429%202%20IN%20IP4%208.34.182.111%0D%0As%3DiFAX%0D%0At%3D0%200%0D%0Am%3Dimage%2021516%20udptl%20t38%0D%0Ac%3DIN%20IP4%208.34.182.100%0D%0Aa%3DT38FaxVersion%3A0%0D%0Aa%3DT38MaxBitRate%3A14400%0D%0Aa%3DT38FaxFillBitRemoval%0D%0Aa%3DT38FaxRateManagement%3AtransferredTCF%0D%0Aa%3DT38FaxMaxBuffer%3A2000%0D%0Aa%3DT38FaxMaxDatagram%3A400%0D%0Aa%3DT38FaxUdpEC%3At38UDPRedundancy%0D%0A
variable_rtp_use_codec_string: PCMU,PCMA,GSM
variable_has_t38: true
variable_rtp_local_sdp_str: v%3D0%0D%0Ao%3DFreeSWITCH%201516125843%201516125845%20IN%20IP4%2052.90.40.222%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%2052.90.40.222%0D%0At%3D0%200%0D%0Am%3Dimage%2018078%20udptl%20t38%0D%0Aa%3DT38FaxVersion%3A0%0D%0Aa%3DT38MaxBitRate%3A14400%0D%0Aa%3DT38FaxFillBitRemoval%0D%0Aa%3DT38FaxRateManagement%3AtransferredTCF%0D%0Aa%3DT38FaxMaxBuffer%3A2000%0D%0Aa%3DT38FaxMaxDatagram%3A400%0D%0Aa%3DT38FaxUdpEC%3At38UDPRedundancy%0D%0A
variable_fax_v17_disabled: 0
variable_fax_ecm_requested: 0
variable_fax_filename: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
variable_sip_to_tag: HZXUvmZ2t83gH
variable_sip_from_tag: 5hztxl73e4pjapwj.i
variable_sip_cseq: 580
variable_sip_call_id: 91855555-75b4-1236-4ea9-12266285acf2
variable_sip_recover_contact: %3Csip%3A8.34.182.111%3A5061%3E
variable_sip_full_via: SIP/2.0/UDP%208.34.182.111%3A5080%3Bbranch%3Dz9hG4bK-524287-1---432f9c22e291825f%3Brport%3D5080,SIP/2.0/UDP%208.34.182.111%3A5061%3Brport%3D5061%3Bbranch%3Dz9hG4bK-wg7zipzy7vbj6qva
variable_sip_recover_via: SIP/2.0/UDP%208.34.182.111%3A5080%3Bbranch%3Dz9hG4bK-524287-1---432f9c22e291825f%3Brport%3D5080,SIP/2.0/UDP%208.34.182.111%3A5061%3Brport%3D5061%3Bbranch%3Dz9hG4bK-wg7zipzy7vbj6qva
variable_sip_full_from: %3Csip%3A12158258773%40sip.t38fax.com%3A5080%3E%3Btag%3D5hztxl73e4pjapwj.i
variable_sip_full_to: %3Csip%3A0000000000%40sip.t38fax.com%3E%3Btag%3DHZXUvmZ2t83gH
variable_fax_file_image_resolution: 8031x3858
variable_fax_image_pixel_size: 1728x1094
variable_fax_file_image_pixel_size: 1728x1078
variable_fax_longest_bad_row_run: 0
variable_fax_encoding: 4
variable_fax_encoding_name: T.4%202-D
variable_sip_term_status: 200
variable_proto_specific_hangup_cause: sip%3A200
variable_sip_term_cause: 16
variable_sip_user_agent: Sippy
variable_sip_hangup_disposition: recv_bye
variable_fax_success: 1
variable_fax_result_code: 0
variable_fax_result_text: OK
variable_fax_ecm_used: off
variable_fax_local_station_id: SpanDSP%20Fax%20Ident
variable_fax_remote_station_id: iFAXSolutions
variable_fax_document_transferred_pages: 1
variable_fax_document_total_pages: 1
variable_fax_image_resolution: 8040x3850
variable_fax_image_size: 31089
variable_fax_bad_rows: 0
variable_fax_transfer_rate: 14400
variable_read_codec: PCMU
variable_read_rate: 8000
variable_hangup_cause: NORMAL_CLEARING
variable_hangup_cause_q850: 16
variable_digits_dialed: none
variable_start_stamp: 2018-01-16%2023%3A05%3A21
variable_profile_start_stamp: 2018-01-16%2023%3A05%3A21
variable_answer_stamp: 2018-01-16%2023%3A05%3A21
variable_progress_stamp: 2018-01-16%2023%3A05%3A21
variable_end_stamp: 2018-01-16%2023%3A05%3A57
variable_start_epoch: 1516143921
variable_start_uepoch: 1516143921416930
variable_profile_start_epoch: 1516143921
variable_profile_start_uepoch: 1516143921416930
variable_answer_epoch: 1516143921
variable_answer_uepoch: 1516143921816928
variable_bridge_epoch: 0
variable_bridge_uepoch: 0
variable_last_hold_epoch: 0
variable_last_hold_uepoch: 0
variable_hold_accum_seconds: 0
variable_hold_accum_usec: 0
variable_hold_accum_ms: 0
variable_resurrect_epoch: 0
variable_resurrect_uepoch: 0
variable_progress_epoch: 1516143921
variable_progress_uepoch: 1516143921736879
variable_progress_media_epoch: 0
variable_progress_media_uepoch: 0
variable_end_epoch: 1516143957
variable_end_uepoch: 1516143957836793
variable_last_app: txfax
variable_last_arg: /usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif
variable_caller_id: %22Outbound%20Call%22%20%3C12158258773%3E
variable_duration: 36
variable_billsec: 36
variable_progresssec: 0
variable_answersec: 0
variable_waitsec: 0
variable_progress_mediasec: 0
variable_flow_billsec: 36
variable_mduration: 36420
variable_billmsec: 36020
variable_progressmsec: 320
variable_answermsec: 400
variable_waitmsec: 0
variable_progress_mediamsec: 0
variable_flow_billmsec: 36420
variable_uduration: 36419863
variable_billusec: 36019865
variable_progressusec: 319949
variable_answerusec: 399998
variable_waitusec: 0
variable_progress_mediausec: 0
variable_flow_billusec: 36419863
variable_rtp_audio_in_raw_bytes: 22984
variable_rtp_audio_in_media_bytes: 21608
variable_rtp_audio_in_packet_count: 203
variable_rtp_audio_in_media_packet_count: 195
variable_rtp_audio_in_skip_packet_count: 14
variable_rtp_audio_in_jitter_packet_count: 0
variable_rtp_audio_in_dtmf_packet_count: 0
variable_rtp_audio_in_cng_packet_count: 0
variable_rtp_audio_in_flush_packet_count: 8
variable_rtp_audio_in_largest_jb_size: 0
variable_rtp_audio_in_jitter_min_variance: 20.09
variable_rtp_audio_in_jitter_max_variance: 80.36
variable_rtp_audio_in_jitter_loss_rate: 0.00
variable_rtp_audio_in_jitter_burst_rate: 0.00
variable_rtp_audio_in_mean_interval: 20.20
variable_rtp_audio_in_flaw_total: 0
variable_rtp_audio_in_quality_percentage: 100.00
variable_rtp_audio_in_mos: 4.50
variable_rtp_audio_out_raw_bytes: 175535
variable_rtp_audio_out_media_bytes: 175535
variable_rtp_audio_out_packet_count: 818
variable_rtp_audio_out_media_packet_count: 818
variable_rtp_audio_out_skip_packet_count: 0
variable_rtp_audio_out_dtmf_packet_count: 0
variable_rtp_audio_out_cng_packet_count: 0
variable_rtp_audio_rtcp_packet_count: 0
variable_rtp_audio_rtcp_octet_count: 0
API-Command: lua
API-Command-Argument: fax_retry.lua

'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] Success: '1'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_result_text: 'OK'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_file: '/usr/local/freeswitch/storage/fax/52.90.40.222/9000/temp/9bff0125-376f-4c8d-a63f-b245339bbbb6.tif'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] uuid: 'ba2692d2-fb11-11e7-9319-455b975e6257'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_retry_attempts: 1
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_retry_limit: 20
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_retry_sleep: 30
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_uri: 'sofia/gateway/6f98ceb1-1ad0-478c-a524-69e6808b93b9/12158258773'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] accountcode: '52.90.40.222'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] origination_caller_id_name: 000000000000000
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] origination_caller_id_number: 000000000000000
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] fax_result_code: 0
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] mailfrom_address:
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] mailto_address:
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] hangup_cause_q850: '16'
2018-01-16 23:05:58.436913 [INFO] switch_cpp.cpp:1365 [FAX] RETRY STATS SUCCESS: GATEWAY[sofia/gateway/6f98ceb1-1ad0-478c-a524-69e6808b93b9/12158258773] VARS[fax_use_ecm=true,fax_enable_t38=true,fax_enable_t38_request=true,fax_disable_v17=false]
2018-01-16 23:05:58.436913 [WARNING] switch_utils.c:1195 Failed to delete file [in_uuid);
 --result = array['domain']['template']['name'];
 --freeswitch.consoleLog("notice", result .. "\n");
 --for i, ext in ipairs(array.fax.alloy▒M]
2018-01-16 23:05:58.436913 [ERR] switch_utils.c:1211 EMAIL NOT SENT, error [No to address specified]
2018-01-16 23:05:58.436913 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f02101344d0 released.
2018-01-16 23:05:58.436913 [DEBUG] switch_core_state_machine.c:783 Hangup Command with no Session lua(fax_retry.lua):

2018-01-16 23:05:58.436913 [DEBUG] switch_core_state_machine.c:619 (sofia/external/12158258773) State Change CS_HANGUP -> CS_REPORTING
2018-01-16 23:05:58.436913 [DEBUG] switch_core_state_machine.c:584 (sofia/external/12158258773) Running State Change CS_REPORTING (Cur 1 Tot 1)
2018-01-16 23:05:58.436913 [DEBUG] switch_core_state_machine.c:938 (sofia/external/12158258773) State REPORTING
2018-01-16 23:05:58.436913 [ALERT] switch_core_state_machine.c:938 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:174 sofia/external/12158258773 Standard REPORTING, cause: NORMAL_CLEARING
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:938 (sofia/external/12158258773) State REPORTING going to sleep
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:610 (sofia/external/12158258773) State Change CS_REPORTING -> CS_DESTROY
2018-01-16 23:05:58.476923 [DEBUG] switch_core_session.c:1665 Session 1 (sofia/external/12158258773) Locked, Waiting on external entities
2018-01-16 23:05:58.476923 [NOTICE] switch_core_session.c:1683 Session 1 (sofia/external/12158258773) Ended
2018-01-16 23:05:58.476923 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/12158258773 [CS_DESTROY]
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:741 (sofia/external/12158258773) Running State Change CS_DESTROY (Cur 0 Tot 1)
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:751 (sofia/external/12158258773) State DESTROY
2018-01-16 23:05:58.476923 [ALERT] switch_core_state_machine.c:751 sofia/external/12158258773 Send KeyFrame
2018-01-16 23:05:58.476923 [DEBUG] mod_sofia.c:343 sofia/external/12158258773 SOFIA DESTROY
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:181 sofia/external/12158258773 Standard DESTROY
2018-01-16 23:05:58.476923 [DEBUG] switch_core_state_machine.c:751 (sofia/external/12158258773) State DESTROY going to sleep
2018-01-16 23:06:00.896865 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:06:10.916846 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:06:20.916880 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:06:30.916807 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection
2018-01-16 23:06:40.916861 [ALERT] mod_rtmp.c:941 RTMP Garbage Collection