Hello I am trying to send a traditional fax through the voip gateway to Freeswitch, but it fails a lot the error message is : Fax processing not successful - result (48) Disconnected after permitted retries. the route looks like this: HP officejet 5610 all-in-one ---------RJ11--------- Wellgate 2644 ---------RJ45--------- FreeSwitch Server system: Windows XP FreeSWITCH: Version 1.0.head (git-) i donno what's the problem it is . i have tried many solutions. like disable-v17 set to true, it increase the successful rate but still not good. thank you~ here is the log: 2010-09-08 10:52:36.710250 [NOTICE] switch_channel.c:779 New Channel sofia/internal/test123_inner_fax@192.168.1.23:5566[5585d019-0b99-43c2-9202-6901f83fb348] 2010-09-08 10:52:36.725875 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_NEW 2010-09-08 10:52:36.725875 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State NEW 2010-09-08 10:52:36.819625 [DEBUG] sofia.c:4318 Channel sofia/internal/ test123_inner_fax@192.168.1.23:5566 entering state [received][100] 2010-09-08 10:52:36.819625 [DEBUG] sofia.c:4329 Remote SDP: v=0 o=2dsp_4fxs_4fxo_108 16394 0 IN IP4 192.168.1.24 s=SIP CALL i=Audio Session c=IN IP4 192.168.1.24 t=0 0 m=audio 16394 RTP/AVP 18 4 8 0 2 96 a=rtpmap:18 G729/8000/1 a=rtpmap:4 G723/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=rtpmap:2 G726-32/8000/1 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[G7221:115:32000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[G7221:107:16000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[G722:9:8000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[PCMU:0:8000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[PCMA:8:8000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[GSM:3:8000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[G7221:115:32000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[G7221:107:16000:20] 2010-09-08 10:52:36.819625 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[G722:9:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[PCMU:0:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[PCMA:8:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G723:4:8000:20]/[GSM:3:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMA:8:8000:20]/[G7221:115:32000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMA:8:8000:20]/[G7221:107:16000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMA:8:8000:20]/[PCMU:0:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:2442 Set Codec sofia/internal/test123_inner_fax@192.168.1.23:5566 PCMA/8000 20 ms 160 samples 2010-09-08 10:52:36.835250 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf send/recv payload to 96 2010-09-08 10:52:36.835250 [DEBUG] sofia.c:4476 (sofia/internal/ test123_inner_fax@192.168.1.23:5566) State Change CS_NEW -> CS_INIT 2010-09-08 10:52:36.835250 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_INIT 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State INIT 2010-09-08 10:52:36.835250 [DEBUG] mod_sofia.c:83 sofia/internal/ test123_inner_fax@192.168.1.23:5566 SOFIA INIT 2010-09-08 10:52:36.835250 [DEBUG] mod_sofia.c:119 (sofia/internal/ test123_inner_fax@192.168.1.23:5566) State Change CS_INIT -> CS_ROUTING 2010-09-08 10:52:36.835250 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State INIT going to sleep 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_ROUTING 2010-09-08 10:52:36.835250 [DEBUG] switch_channel.c:1512 (sofia/internal/ test123_inner_fax@192.168.1.23:5566) Callstate Change DOWN -> RINGING 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State ROUTING 2010-09-08 10:52:36.835250 [DEBUG] mod_sofia.c:142 sofia/internal/ test123_inner_fax@192.168.1.23:5566 SOFIA ROUTING 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:77 sofia/internal/test123_inner_fax@192.168.1.23:5566 Standard ROUTING 2010-09-08 10:52:36.835250 [INFO] mod_dialplan_xml.c:331 Processing test123_inner_fax->11111111 in context default Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Regex (FAIL) [Local_Extension] destination_number(11111111) =~ /^([0-9][0-9][0-9][0-9])$/ break=on-false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 parsing [default->czc] continue=false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Regex (FAIL) [czc] destination_number(11111111) =~ /^99999$/ break=on-false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 parsing [default->voip_inner_fax] continue=false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Regex (FAIL) [voip_inner_fax] caller_id_number(test123_inner_fax) =~ /^voip_inner_fax$/ break=on-false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 parsing [default->2296_fax_in] continue=false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Regex (PASS) [2296_fax_in] caller_id_number(test123_inner_fax) =~ /^test123_inner_fax$/ break=on-false Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Action answer() Dialplan: sofia/internal/test123_inner_fax@192.168.1.23:5566 Action lua(FaxOut_PSTN.lua ${destination_number} test123_inner_fax) 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State Change CS_ROUTING -> CS_EXECUTE 2010-09-08 10:52:36.835250 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State ROUTING going to sleep 2010-09-08 10:52:36.835250 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_EXECUTE 2010-09-08 10:52:36.850875 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State EXECUTE 2010-09-08 10:52:36.850875 [DEBUG] mod_sofia.c:235 sofia/internal/ test123_inner_fax@192.168.1.23:5566 SOFIA EXECUTE 2010-09-08 10:52:36.850875 [DEBUG] switch_core_state_machine.c:157 sofia/internal/test123_inner_fax@192.168.1.23:5566 Standard EXECUTE EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566 answer() 2010-09-08 10:52:36.944625 [DEBUG] sofia_glue.c:2682 AUDIO RTP [sofia/internal/test123_inner_fax@192.168.1.23:5566] 192.168.1.23 port 30974 -> 192.168.1.24 port 16394 codec: 8 ms: 20 2010-09-08 10:52:36.944625 [DEBUG] switch_rtp.c:1413 Starting timer [soft] 160 bytes per 20ms 2010-09-08 10:52:36.944625 [DEBUG] sofia_glue.c:2892 Set 2833 dtmf send payload to 96 2010-09-08 10:52:36.944625 [DEBUG] sofia_glue.c:2897 Set 2833 dtmf receive payload to 96 2010-09-08 10:52:36.944625 [DEBUG] mod_sofia.c:677 Local SDP sofia/internal/ test123_inner_fax@192.168.1.23:5566: v=0 o=FreeSWITCH 1283883382 1283883383 IN IP4 192.168.1.23 s=FreeSWITCH c=IN IP4 192.168.1.23 t=0 0 m=audio 30974 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2010-09-08 10:52:36.944625 [DEBUG] switch_core_session.c:658 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:52:36.944625 [DEBUG] switch_channel.c:2542 (sofia/internal/ test123_inner_fax@192.168.1.23:5566) Callstate Change RINGING -> ACTIVE 2010-09-08 10:52:36.944625 [NOTICE] mod_dptools.c:746 Channel [sofia/internal/test123_inner_fax@192.168.1.23:5566] has been answered EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566lua(FaxOut_PSTN.lua 11111111 test123_inner_fax) 2010-09-08 10:52:37.116500 [NOTICE] mod_commands.c:4080 Executing command: extra\log\Log_2.exe 5585d019-0b99-43c2-9202-6901f83fb348 test123_inner_fax fax to 11111111 2010-09-08 10:52:37.491500 [DEBUG] sofia.c:4318 Channel sofia/internal/ test123_inner_fax@192.168.1.23:5566 entering state [completed][200] 2010-09-08 10:52:37.491500 [DEBUG] sofia.c:4318 Channel sofia/internal/ test123_inner_fax@192.168.1.23:5566 entering state [ready][200] 2010-09-08 10:52:37.585250 [ALERT] switch_cpp.cpp:1177 FaxOUT_PSTN: fax from test123_inner_fax to 11111111 2010-09-08 10:52:37.585250 [ALERT] switch_cpp.cpp:1177 Fax_Receive: Fax Recieving EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566playback(silence_stream://2000) 2010-09-08 10:52:37.616500 [DEBUG] switch_ivr_play_say.c:1161 Codec Activated L16@8000hz 1 channels 20ms 2010-09-08 10:52:37.679000 [DEBUG] switch_rtp.c:2519 Correct ip/port confirmed. 2010-09-08 10:52:39.632125 [DEBUG] switch_ivr_play_say.c:1468 done playing file EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566 system(mkdir tmp\fax\5585d019-0b99-43c2-9202-6901f83fb348) 2010-09-08 10:52:39.632125 [NOTICE] mod_dptools.c:1332 Executing command: mkdir tmp\fax\5585d019-0b99-43c2-9202-6901f83fb348 EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566set(fax_v17_disabled=true) 2010-09-08 10:52:39.679000 [DEBUG] mod_dptools.c:854 sofia/internal/ test123_inner_fax@192.168.1.23:5566 SET [fax_v17_disabled]=[true] EXECUTE sofia/internal/test123_inner_fax@192.168.1.23:5566rxfax(tmp/fax/5585d019-0b99-43c2-9202-6901f83fb348/FAX-5585d019-0b99-43c2-9202-6901f83fb348.tif) 2010-09-08 10:52:39.679000 [DEBUG] mod_spandsp_fax.c:1077 Raw read codec activation Success L16 20000 2010-09-08 10:52:39.679000 [DEBUG] switch_core_codec.c:116 sofia/internal/ test123_inner_fax@192.168.1.23:5566 Push codec L16:10 2010-09-08 10:52:39.679000 [DEBUG] mod_spandsp_fax.c:1093 Raw write codec activation Success L16 2010-09-08 10:52:40.710250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 1 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Starting answer mode 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 0 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 4 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Start T2 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from state 1 to 17 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Sending ident 'TEST123 VOIP' 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: CSI without final frame tag 2010-09-08 10:52:42.741500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 03 40 50 49 4f 56 20 4f 55 55 4e 20 20 20 20 20 20 20 20 20 20 20 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 DIS: 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= 3G mobile network: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..1.= Can receive fax: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..00 11..= Supported data signalling rates: V.27 ter and V.29 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= 2-D coding: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 10..= Recording length: Unlimited 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= T.6 coding: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Polled sub-address: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= T.43 coding: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Plane interleave: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Selective polling: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Sub-addressing: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Password: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Character mode: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Digital network capability: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Duplex capability: Half only 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= JPEG coding: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Full colour mode: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Custom illuminant: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Custom gamut range: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2010-09-08 10:52:44.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 0... ....= Extension indicator: Not set 2010-09-08 10:52:44.335250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: DIS with final frame tag 2010-09-08 10:52:44.335250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 13 80 00 ce fa c4 80 95 80 80 80 18 2010-09-08 10:52:44.788375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:44.866500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:44.866500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2010-09-08 10:52:44.866500 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 4 2010-09-08 10:52:44.866500 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 0 2010-09-08 10:52:44.866500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Start T4 2010-09-08 10:52:44.882125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2010-09-08 10:52:44.944625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 T4 expired in phase T30_PHASE_B_RX, state 17 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Retry number 1 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_B_TX 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 0 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 4 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Sending ident 'TEST123 VOIP' 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: CSI without final frame tag 2010-09-08 10:52:48.319625 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 03 40 50 49 4f 56 20 4f 55 55 4e 20 20 20 20 20 20 20 20 20 20 20 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 DIS: 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= 3G mobile network: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..1.= Can receive fax: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..00 11..= Supported data signalling rates: V.27 ter and V.29 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= 2-D coding: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 10..= Recording length: Unlimited 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= T.6 coding: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Polled sub-address: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= T.43 coding: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Plane interleave: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Selective polling: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Sub-addressing: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Password: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Character mode: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Digital network capability: Not set 2010-09-08 10:52:49.897750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Duplex capability: Half only 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= JPEG coding: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Full colour mode: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Custom illuminant: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Custom gamut range: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 0... ....= Extension indicator: Not set 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: DIS with final frame tag 2010-09-08 10:52:49.913375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 13 80 00 ce fa c4 80 95 80 80 80 18 2010-09-08 10:52:50.382125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:50.460250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:50.460250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2010-09-08 10:52:50.460250 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 4 2010-09-08 10:52:50.460250 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 0 2010-09-08 10:52:50.460250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Start T4 2010-09-08 10:52:50.491500 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2010-09-08 10:52:50.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2010-09-08 10:52:50.538375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2010-09-08 10:52:50.538375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 T4 expired in phase T30_PHASE_B_RX, state 17 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Retry number 2 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_B_TX 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 0 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 4 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Sending ident 'TEST123 VOIP' 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: CSI without final frame tag 2010-09-08 10:52:53.929000 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 03 40 50 49 4f 56 20 4f 55 55 4e 20 20 20 20 20 20 20 20 20 20 20 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 DIS: 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= 3G mobile network: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..1.= Can receive fax: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..00 11..= Supported data signalling rates: V.27 ter and V.29 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= 2-D coding: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 10..= Recording length: Unlimited 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .1.. ....= T.6 coding: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Polled sub-address: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= T.43 coding: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Plane interleave: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Selective polling: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Sub-addressing: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Password: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= Character mode: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Digital network capability: Not set 2010-09-08 10:52:55.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Duplex capability: Half only 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 0...= JPEG coding: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...0 ....= Full colour mode: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 1... ....= Extension indicator: Set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... ..0.= Custom illuminant: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... .0..= Custom gamut range: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 0... ....= Extension indicator: Not set 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: DIS with final frame tag 2010-09-08 10:52:55.522750 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 13 80 00 ce fa c4 80 95 80 80 80 18 2010-09-08 10:52:55.960250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:56.038375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2010-09-08 10:52:56.038375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2010-09-08 10:52:56.038375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 4 2010-09-08 10:52:56.038375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 0 2010-09-08 10:52:56.038375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Start T4 2010-09-08 10:52:56.085250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2010-09-08 10:52:56.085250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2010-09-08 10:52:56.132125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2010-09-08 10:52:56.132125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 T4 expired in phase T30_PHASE_B_RX, state 17 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Too many retries. Giving up. 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_D_TX 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 0 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 4 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from state 17 to 3 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: DCN with final frame tag 2010-09-08 10:52:59.507125 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Tx: ff 13 fa 2010-09-08 10:53:00.585250 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Disconnecting 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 0 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 1 2010-09-08 10:53:00.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from state 3 to 2 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Send complete in phase T30_PHASE_E, state 2 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:308 ============================================================================== 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:334 Fax processing not successful - result (48) Disconnected after permitted retries. 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:341 Remote station id: 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:342 Local station id: TEST123 VOIP 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:343 Pages transferred: 0 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:345 Total fax pages: 0 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:346 Image resolution: 0x0 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:347 Transfer Rate: 14400 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:349 ECM status off 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:350 remote country: 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:351 remote vendor: 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:352 remote model: 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:354 ============================================================================== 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from state 2 to 32 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW T.30 Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set rx type 9 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX FAX exchange complete 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX Set tx type 9 2010-09-08 10:53:01.663375 [DEBUG] mod_spandsp_fax.c:270 FLOW FAX FAX exchange complete 2010-09-08 10:53:01.679000 [DEBUG] switch_core_codec.c:140 sofia/internal/ test123_inner_fax@192.168.1.23:5566 Restore previous codec PCMA:8. 2010-09-08 10:53:01.679000 [NOTICE] mod_commands.c:4080 Executing command: extra\log\Log_2.exe 5585d019-0b99-43c2-9202-6901f83fb348 freeswitch receive from test123_inner_fax Disconnected after permitted retries 2010-09-08 10:53:01.772750 [DEBUG] switch_channel.c:2309 (sofia/internal/ test123_inner_fax@192.168.1.23:5566) Callstate Change ACTIVE -> HANGUP 2010-09-08 10:53:01.772750 [NOTICE] sofia.c:481 Hangup sofia/internal/ test123_inner_fax@192.168.1.23:5566 [CS_EXECUTE] [NORMAL_CLEARING] 2010-09-08 10:53:01.772750 [DEBUG] switch_channel.c:2325 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [KILL] 2010-09-08 10:53:01.772750 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:53:01.866500 [DEBUG] switch_cpp.cpp:602 CoreSession::hangup 2010-09-08 10:53:01.882125 [DEBUG] switch_cpp.cpp:968 sofia/internal/ test123_inner_fax@192.168.1.23:5566 destroy/unlink session from object 2010-09-08 10:53:01.882125 [DEBUG] switch_core_session.c:1905 sofia/internal/test123_inner_fax@192.168.1.23:5566 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2010-09-08 10:53:01.882125 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State EXECUTE going to sleep 2010-09-08 10:53:01.882125 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_HANGUP 2010-09-08 10:53:01.882125 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State HANGUP 2010-09-08 10:53:01.882125 [DEBUG] mod_sofia.c:447 sofia/internal/ test123_inner_fax@192.168.1.23:5566 Overriding SIP cause 480 with 200 from the other leg 2010-09-08 10:53:01.882125 [DEBUG] mod_sofia.c:453 Channel sofia/internal/ test123_inner_fax@192.168.1.23:5566 hanging up, cause: NORMAL_CLEARING 2010-09-08 10:53:01.991500 [DEBUG] switch_core_state_machine.c:46 sofia/internal/test123_inner_fax@192.168.1.23:5566 Standard HANGUP, cause: NORMAL_CLEARING 2010-09-08 10:53:01.991500 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State HANGUP going to sleep 2010-09-08 10:53:01.991500 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State Change CS_HANGUP -> CS_REPORTING 2010-09-08 10:53:01.991500 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:53:01.991500 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_REPORTING 2010-09-08 10:53:01.991500 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State REPORTING 2010-09-08 10:53:02.007125 [DEBUG] switch_core_state_machine.c:53 sofia/internal/test123_inner_fax@192.168.1.23:5566 Standard REPORTING, cause: NORMAL_CLEARING 2010-09-08 10:53:02.007125 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State REPORTING going to sleep 2010-09-08 10:53:02.007125 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State Change CS_REPORTING -> CS_DESTROY 2010-09-08 10:53:02.007125 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/test123_inner_fax@192.168.1.23:5566 [BREAK] 2010-09-08 10:53:02.007125 [DEBUG] switch_core_session.c:1202 Session 1 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Locked, Waiting on external entities 2010-09-08 10:53:02.007125 [NOTICE] switch_core_session.c:1220 Session 1 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Ended 2010-09-08 10:53:02.007125 [NOTICE] switch_core_session.c:1222 Close Channel sofia/internal/test123_inner_fax@192.168.1.23:5566 [CS_DESTROY] 2010-09-08 10:53:02.007125 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Callstate Change HANGUP -> DOWN 2010-09-08 10:53:02.007125 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/test123_inner_fax@192.168.1.23:5566) Running State Change CS_DESTROY 2010-09-08 10:53:02.022750 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State DESTROY 2010-09-08 10:53:02.022750 [DEBUG] mod_sofia.c:358 sofia/internal/ test123_inner_fax@192.168.1.23:5566 SOFIA DESTROY 2010-09-08 10:53:02.022750 [DEBUG] switch_core_state_machine.c:60 sofia/internal/test123_inner_fax@192.168.1.23:5566 Standard DESTROY 2010-09-08 10:53:02.022750 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/test123_inner_fax@192.168.1.23:5566) State DESTROY going to sleep