[Freeswitch-users] txfax unexpected message received
António Silva
asilva at wirelessmundi.com
Fri Nov 24 17:53:12 UTC 2017
Hi,
when sending a fax to a particular destination it fails with "Fax
processing not successful - result (13) Unexpected message received."
To other destination is working ok, i don't know what is the
particularity on this one that makes it fail...
From the logs i see:
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:
CFR with final frame tag
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:
ff 13 84
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx
final frame in state D
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30
Unexpected CFR frame in state D
I guess that is not suppose to receive confirmed to received.. because
the training is not yet done. Can i do anything from my side to make it
work?
I've tried with different resolutions but no luck.. i try with t38 but
this gw the t38 is not well implemented and also didn't work.
To send the fax i just do:
originate {fax_verbose=true}sofia/gateway/CS2K/939165135
&txfax(/root/txfax.tiff)
Attach full log.
Thanks for the help.
--
Saludos / Regards / Cumprimentos
António Silva
-------------- next part --------------
Sending the fax:
originate {fax_verbose=true}sofia/gateway/CS2K/939165135 &txfax(/root/txfax.tiff)
LOG:
2017-11-24 18:29:32.325313 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
2017-11-24 18:29:32.325313 [NOTICE] switch_channel.c:1104 New Channel sofia/publico/939165135 [bce7f5cc-f2e2-4ec6-9798-27a00b660b43]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [cm_context]=[incoming]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [cm_transfer_context]=[incoming]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [cm_channel_name]=[line/CS2K]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [cm_channel_type]=[line]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [cm_line_name]=[CS2K]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [dtmf_type]=[rfc2833]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [rtp_info_when_no_2833]=[false]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [rtp_liberal_dtmf]=[true]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [refuse_t38]=[true]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [t38_passthru]=[false]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [absolute_codec_string]=[PCMA,PCMU]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5010 sofia/publico/939165135 setting variable [codec_string]=[PCMA,PCMU]
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:5026 (sofia/publico/939165135) State Change CS_NEW -> CS_INIT
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_INIT (Cur 1 Tot 15351)
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:627 (sofia/publico/939165135) State INIT
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:93 sofia/publico/939165135 SOFIA INIT
2017-11-24 18:29:32.325313 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 10822 pass
2017-11-24 18:29:32.325313 [DEBUG] sofia_glue.c:1298 sofia/publico/939165135 sending invite version: 1.9.0 git 4c78733 2017-05-16 19:50:21Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1511533750 1511533751 IN IP4 100.10.10.10
s=FreeSWITCH
c=IN IP4 100.10.10.10
t=0 0
m=audio 10822 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:40 sofia/publico/939165135 Standard INIT
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:48 (sofia/publico/939165135) State Change CS_INIT -> CS_ROUTING
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:627 (sofia/publico/939165135) State INIT going to sleep
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_ROUTING (Cur 1 Tot 15351)
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:643 (sofia/publico/939165135) State ROUTING
2017-11-24 18:29:32.325313 [DEBUG] mod_sofia.c:154 sofia/publico/939165135 SOFIA ROUTING
2017-11-24 18:29:32.325313 [DEBUG] switch_ivr_originate.c:67 (sofia/publico/939165135) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:643 (sofia/publico/939165135) State ROUTING going to sleep
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 15351)
2017-11-24 18:29:32.325313 [DEBUG] sofia.c:7249 Channel sofia/publico/939165135 entering state [calling][0]
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:662 (sofia/publico/939165135) State CONSUME_MEDIA
2017-11-24 18:29:32.325313 [DEBUG] switch_core_state_machine.c:662 (sofia/publico/939165135) State CONSUME_MEDIA going to sleep
2017-11-24 18:29:34.205294 [DEBUG] sofia.c:7249 Channel sofia/publico/939165135 entering state [proceeding][183]
2017-11-24 18:29:34.205294 [DEBUG] sofia.c:7259 Remote SDP:
v=0
o=genband 294525952 1511544573 IN IP4 100.10.100.10
s=-
c=IN IP4 100.10.100.10
t=0 0
m=audio 41814 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20
a=maxptime:30
a=sqn: 0
a=cdsc:1 image udptl t38
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5165 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5165 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5026 Set telephone-event payload to 101 at 8000
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:3425 Set Codec sofia/publico/939165135 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-24 18:29:34.205294 [DEBUG] switch_core_codec.c:111 sofia/publico/939165135 Original read codec set to PCMA:8
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5369 Set telephone-event payload to 101 at 8000
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:5427 sofia/publico/939165135 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:8144 AUDIO RTP [sofia/publico/939165135] 100.10.10.10 port 10822 -> 100.10.100.10 port 41814 codec: 8 ms: 20
2017-11-24 18:29:34.205294 [DEBUG] switch_rtp.c:4107 Starting timer [soft] 160 bytes per 20ms
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:8447 sofia/publico/939165135 Set 2833 dtmf send payload to 101
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:8454 sofia/publico/939165135 Set 2833 dtmf receive payload to 101
2017-11-24 18:29:34.205294 [DEBUG] switch_core_media.c:8477 sofia/publico/939165135 Set rtp dtmf delay to 40
2017-11-24 18:29:34.205294 [NOTICE] sofia_media.c:92 Pre-Answer sofia/publico/939165135!
2017-11-24 18:29:34.205294 [DEBUG] switch_channel.c:3490 (sofia/publico/939165135) Callstate Change DOWN -> EARLY
2017-11-24 18:29:34.205294 [DEBUG] switch_ivr_originate.c:3695 Originate Resulted in Success: [sofia/publico/939165135]
2017-11-24 18:29:34.205294 [INFO] switch_channel.c:3139 sofia/publico/939165135 Flipping CID from "" <0000000000> to "Outbound Call" <939165135>
2017-11-24 18:29:34.205294 [DEBUG] mod_commands.c:4865 (sofia/publico/939165135) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2017-11-24 18:29:34.205294 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_EXECUTE (Cur 1 Tot 15351)
2017-11-24 18:29:34.205294 [DEBUG] switch_core_state_machine.c:650 (sofia/publico/939165135) State EXECUTE
2017-11-24 18:29:34.205294 [DEBUG] mod_sofia.c:209 sofia/publico/939165135 SOFIA EXECUTE
2017-11-24 18:29:34.205294 [DEBUG] switch_core_state_machine.c:328 sofia/publico/939165135 Standard EXECUTE
2017-11-24 18:29:34.205294 [DEBUG] switch_core_session.c:2806 EXECUTE sofia/publico/939165135 txfax(/root/txfax.tiff)
2017-11-24 18:29:34.205294 [DEBUG] mod_spandsp_fax.c:1459 Raw read codec activation Success L16 20000
2017-11-24 18:29:34.205294 [DEBUG] switch_core_codec.c:223 sofia/publico/939165135 Push codec L16:100
2017-11-24 18:29:34.205294 [DEBUG] mod_spandsp_fax.c:1477 Raw write codec activation Success L16
2017-11-24 18:29:34.265321 [DEBUG] switch_rtp.c:7266 Correct audio ip/port confirmed.
2017-11-24 18:29:34.645315 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:36.185314 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:39.165314 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:40.685313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:41.265295 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:41.265295 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:41.265295 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:41.285310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:41.505307 [DEBUG] sofia.c:7249 Channel sofia/publico/939165135 entering state [completing][200]
2017-11-24 18:29:41.505307 [DEBUG] sofia.c:7256 Duplicate SDP
v=0
o=genband 294525952 1511544573 IN IP4 100.10.100.10
s=-
c=IN IP4 100.10.100.10
t=0 0
m=audio 41814 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20
a=maxptime:30
a=sqn: 0
a=cdsc:1 image udptl t38
2017-11-24 18:29:41.525326 [DEBUG] sofia.c:7249 Channel sofia/publico/939165135 entering state [ready][200]
2017-11-24 18:29:41.525326 [NOTICE] sofia.c:8327 Channel [sofia/publico/939165135] has been answered
2017-11-24 18:29:41.525326 [DEBUG] switch_channel.c:3789 (sofia/publico/939165135) Callstate Change EARLY -> ACTIVE
2017-11-24 18:29:41.565310 [DEBUG] switch_rtp.c:7266 Correct audio ip/port confirmed.
2017-11-24 18:29:42.605320 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:43.785309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Abort (-8) in state T
2017-11-24 18:29:44.065316 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:44.085313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:44.085313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:44.085313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:44.105312 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:44.165313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:46.245310 [WARNING] sofia.c:6270 Ping succeeded euskaltel with code 200 - count 1/1/1, state UP
2017-11-24 18:29:46.625305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:47.085320 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:47.305315 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state T
2017-11-24 18:29:47.305315 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase A_CNG to B_RX
2017-11-24 18:29:47.305315 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
2017-11-24 18:29:47.305315 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
2017-11-24 18:29:47.325312 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:47.465303 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:47.885318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:47.965313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:48.165318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state T
2017-11-24 18:29:48.265308 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad HDLC CRC received
2017-11-24 18:29:48.265308 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad CRC and timer is 0
2017-11-24 18:29:48.365308 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:48.385310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:48.385310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:48.445320 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:48.465319 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state T
2017-11-24 18:29:55.345320 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state T
2017-11-24 18:29:55.605316 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state T
2017-11-24 18:29:57.025313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
2017-11-24 18:29:57.025313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: CSI without final frame tag
2017-11-24 18:29:57.025313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: ff 03 40 35 36 31 39 33 39 31 35 39 20 20 20 20 20 20 20 20 20 20 20
2017-11-24 18:29:57.025313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Remote gave CSI as: "939165135"
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: DIS with final frame tag
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: ff 13 80 00 4e 9a c4 80 d9 80 80 80 80 00 00 00 00
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state T
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase B_TX
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DIS:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= 3G mobile network: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= V.8 capabilities: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= Preferred octets: 256 octets
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..1.= Can receive fax: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..00 11..= Supported data signalling rates: V.27 ter and V.29
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= 2-D coding: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1%
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 10..= Recording length: Unlimited
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .001 ....= Receiver's minimum scan line time: 5ms at 3.85 l/mm; T7.7 = T3.85
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .1..= Error correction mode (ECM): ECM
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .1.. ....= T.6 coding: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= "Field not valid" supported: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Multiple selective polling: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Polled sub-address: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= T.43 coding: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...0 ....= Plane interleave: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...1= R8x15.4lines/mm: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 1...= Inch-based resolution preferred: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .1.. ....= Selective polling: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Sub-addressing: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Password: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= Character mode: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Digital network capability: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Duplex capability: Half only
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= JPEG coding: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...0 ....= Full colour mode: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= 12bits/pel component: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Custom illuminant: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Custom gamut range: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= North American Letter (215.9mm x 279.4mm): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...0 ....= North American Legal (215.9mm x 355.6mm): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= HKM key management: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= RSA key management: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Override: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= HFX40 cipher: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ...0 ....= Alternative cipher number 2: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..0. ....= Alternative cipher number 3: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= HFX40-I hashing: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= Extension indicator: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:317 === Negotiation Result =======================================================
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:318 Remote station id: 939165135
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:319 Local station id:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:320 Transfer Rate: 9600
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:322 ECM status on
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:323 remote country:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:324 remote vendor:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:325 remote model:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:327 ==============================================================================
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Trying to send file '/root/txfax.tiff'
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start sending document
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Choose image type bi-level (0), compression T.6 (8)
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Minimum bits per row will be 0
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Starting page 1 of transfer
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Partial document buffer contains 25 frames (256 per frame)
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image width is A4 at 8040dpm x 3850dpm
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Put document with modem (6) V.29 at 9600bps
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state T to D
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DCS:
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= 3G mobile network: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..1.= Receive fax: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..00 01..= Selected data signalling rate: V.29, 9600bps
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= 2-D coding: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..00= Recording width: 215mm +- 1%
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 10..= Recording length: Unlimited
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .111 ....= Minimum scan line time: 0ms
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .1..= Error correction mode (ECM): ECM
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= Frame size: 256 octets
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .1.. ....= T.6 coding: Set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= Extension indicator: Not set
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: DCS with final frame tag
2017-11-24 18:29:57.565305 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: ff 13 83 00 06 f8 44
2017-11-24 18:29:57.605294 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state D
2017-11-24 18:29:57.605294 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to B_TX
2017-11-24 18:29:57.605294 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
2017-11-24 18:29:57.605294 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
2017-11-24 18:29:58.765307 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state D
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state D
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D to D_TCF
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to C_NON_ECM_TX
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
2017-11-24 18:29:58.845313 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 6
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase C_NON_ECM_TX, state D_TCF
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_TX to B_RX
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
2017-11-24 18:30:00.705317 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D_TCF to D_POST_TCF
2017-11-24 18:30:04.025321 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state D_POST_TCF
2017-11-24 18:30:04.065319 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Abort (-8) in state D_POST_TCF
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Retry number 1
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase B_TX
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D_POST_TCF to D
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DCS:
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= 3G mobile network: Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..1.= Receive fax: Set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 ..00 01..= Selected data signalling rate: V.29, 9600bps
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= 2-D coding: Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..00= Recording width: 215mm +- 1%
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 10..= Recording length: Unlimited
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .111 ....= Minimum scan line time: 0ms
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 1... ....= Extension indicator: Set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... .1..= Error correction mode (ECM): ECM
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .... 0...= Frame size: 256 octets
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 .1.. ....= T.6 coding: Set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 0... ....= Extension indicator: Not set
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: DCS with final frame tag
2017-11-24 18:30:04.165296 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: ff 13 83 00 06 f8 44
2017-11-24 18:30:04.285294 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state D
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: CFR with final frame tag
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx: ff 13 84
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state D
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Unexpected CFR frame in state D
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Status changing to 'Unexpected message received'
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Flushing queued phase B_TX
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state D to C
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: DCN with final frame tag
2017-11-24 18:30:05.625309 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx: ff 13 fb
2017-11-24 18:30:05.645293 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Abort (-8) in state C
2017-11-24 18:30:05.665314 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state C
2017-11-24 18:30:05.665314 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to D_TX
2017-11-24 18:30:05.665314 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
2017-11-24 18:30:05.665314 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
2017-11-24 18:30:06.725308 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Starting final pause before disconnecting
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to E
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 1
2017-11-24 18:30:06.805318 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state C to B
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase E, state B
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:496 ==============================================================================
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:508 Fax processing not successful - result (13) Unexpected message received.
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:513 Remote station id: 939165135
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:514 Local station id:
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:515 Pages transferred: 0
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:517 Total fax pages: 1
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:518 Image resolution: 8040x3850
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:519 Transfer Rate: 9600
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:521 ECM status on
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:522 remote country:
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:523 remote vendor:
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:524 remote model:
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:526 ==============================================================================
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state B to CALL_FINISHED
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase E to CALL_FINISHED
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 9
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX FAX exchange complete
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 9
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX FAX exchange complete
2017-11-24 18:30:07.805310 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Call completed
2017-11-24 18:30:07.825300 [DEBUG] switch_core_codec.c:248 sofia/publico/939165135 Restore previous codec PCMA:8.
2017-11-24 18:30:07.825300 [NOTICE] switch_core_state_machine.c:385 sofia/publico/939165135 has executed the last dialplan instruction, hanging up.
2017-11-24 18:30:07.825300 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/publico/939165135 [CS_EXECUTE] [NORMAL_CLEARING]
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:650 (sofia/publico/939165135) State EXECUTE going to sleep
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_HANGUP (Cur 1 Tot 15351)
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:850 (sofia/publico/939165135) Callstate Change ACTIVE -> HANGUP
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:852 (sofia/publico/939165135) State HANGUP
2017-11-24 18:30:07.825300 [DEBUG] mod_sofia.c:449 Channel sofia/publico/939165135 hanging up, cause: NORMAL_CLEARING
2017-11-24 18:30:07.825300 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/publico/939165135
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:60 sofia/publico/939165135 Standard HANGUP, cause: NORMAL_CLEARING
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:852 (sofia/publico/939165135) State HANGUP going to sleep
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:619 (sofia/publico/939165135) State Change CS_HANGUP -> CS_REPORTING
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:584 (sofia/publico/939165135) Running State Change CS_REPORTING (Cur 1 Tot 15351)
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:938 (sofia/publico/939165135) State REPORTING
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:174 sofia/publico/939165135 Standard REPORTING, cause: NORMAL_CLEARING
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:938 (sofia/publico/939165135) State REPORTING going to sleep
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:610 (sofia/publico/939165135) State Change CS_REPORTING -> CS_DESTROY
2017-11-24 18:30:07.825300 [DEBUG] switch_core_session.c:1712 Session 15351 (sofia/publico/939165135) Locked, Waiting on external entities
2017-11-24 18:30:07.825300 [NOTICE] switch_core_session.c:1730 Session 15351 (sofia/publico/939165135) Ended
2017-11-24 18:30:07.825300 [NOTICE] switch_core_session.c:1734 Close Channel sofia/publico/939165135 [CS_DESTROY]
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:741 (sofia/publico/939165135) Running State Change CS_DESTROY (Cur 0 Tot 15351)
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:751 (sofia/publico/939165135) State DESTROY
2017-11-24 18:30:07.825300 [DEBUG] mod_sofia.c:354 sofia/publico/939165135 SOFIA DESTROY
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:181 sofia/publico/939165135 Standard DESTROY
2017-11-24 18:30:07.825300 [DEBUG] switch_core_state_machine.c:751 (sofia/publico/939165135) State DESTROY going to sleep
More information about the FreeSWITCH-users
mailing list