Alrighty. Here is mod_fax from beginning to end. ################################################# 2009-09-15 10:41:26.433382 [DEBUG] mod_fax.c:591 Raw read codec activation Success L16 20000 2009-09-15 10:41:26.433382 [DEBUG] mod_fax.c:607 Raw write codec activation Success L16 2009-09-15 10:41:26.433382 [DEBUG] switch_channel.c:182 sofia/external/**********@**.***.**.*** receive message [AUDIO_SYNC] 2009-09-15 10:41:26.464633 [DEBUG] switch_core_io.c:232 sofia/external/**********@**.***.**.*** receive message [TRANSCODING_NECESSARY] 2009-09-15 10:41:27.589676 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 1 2009-09-15 10:41:27.761558 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier down (-1) in state 1 2009-09-15 10:41:27.792809 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 1 2009-09-15 10:41:27.870937 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:28.308454 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:28.355331 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:28.370956 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:28.824099 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:29.27231 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:29.261615 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 1 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Starting answer mode 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 0 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 4 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Start T2 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 1 to 17 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Sending ident 'SpanDSP Fax Ident' 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: CSI without final frame tag 2009-09-15 10:41:29.511625 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: ff 03 40 74 6e 65 64 49 20 78 61 46 20 50 53 44 6e 61 70 53 20 20 20 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 DIS: 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= 3G mobile network: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..1.= Can receive fax: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= 2-D coding: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 10..= Recording length: Unlimited 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .1.. ....= T.6 coding: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Polled sub-address: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= T.43 coding: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ...0 ....= Plane interleave: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= Selective polling: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Sub-addressing: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Password: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= Character mode: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Digital network capability: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Duplex capability: Half only 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= JPEG coding: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ...0 ....= Full colour mode: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Custom illuminant: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Custom gamut range: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 0... ....= Extension indicator: Not set 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: DIS with final frame tag 2009-09-15 10:41:31.89811 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: ff 13 80 00 ee fa c4 80 95 80 80 80 18 2009-09-15 10:41:31.542953 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2009-09-15 10:41:31.621081 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2009-09-15 10:41:31.621081 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2009-09-15 10:41:31.621081 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 4 2009-09-15 10:41:31.621081 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 0 2009-09-15 10:41:31.621081 [DEBUG] mod_fax.c:137 FLOW T.30 Start T4 2009-09-15 10:41:31.652332 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2009-09-15 10:41:32.152351 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2009-09-15 10:41:32.261731 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2009-09-15 10:41:32.402361 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Framing OK (-6) in state 17 2009-09-15 10:41:32.402361 [DEBUG] mod_fax.c:137 FLOW T.30 Start T4A 2009-09-15 10:41:34.11798 [DEBUG] mod_fax.c:137 FLOW T.30 Stop T4A (11200 remaining) 2009-09-15 10:41:34.11798 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: TSI without final frame tag 2009-09-15 10:41:34.11798 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: ff 03 43 38 37 34 31 32 36 38 34 37 35 31 20 20 20 20 20 20 20 20 20 2009-09-15 10:41:34.11798 [DEBUG] mod_fax.c:137 FLOW T.30 Remote gave TSI as: "***********" 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Stop none (0 remaining) 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: DCS with final frame tag 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: ff 13 83 00 22 f8 44 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 In state 17 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 DCS: 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= 3G mobile network: Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..1.= Receive fax: Set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 ..10 00..= Selected data signalling rate: V.17 14400bps 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 0... ....= 2-D coding: Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..00= Recording width: 215mm +- 1% 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... 10..= Recording length: Unlimited 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .111 ....= Minimum scan line time: 0ms 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 1... ....= Extension indicator: Set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .... 0...= Frame size: 256 octets 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 .1.. ....= T.6 coding: Set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 0... ....= Extension indicator: Not set 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Selected compression 3 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Get document at 14400bps, modem 7 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 17 to 7 2009-09-15 10:41:34.293059 [DEBUG] mod_fax.c:137 FLOW T.30 Start T2 2009-09-15 10:41:34.371187 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2009-09-15 10:41:34.371187 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_C_NON_ECM_RX 2009-09-15 10:41:34.371187 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 0 2009-09-15 10:41:34.371187 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 7 2009-09-15 10:41:34.371187 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 0 2009-09-15 10:41:34.402438 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state 7 2009-09-15 10:41:34.402438 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2009-09-15 10:41:34.574319 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Training failed (-5) in state 7 2009-09-15 10:41:34.605571 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state 7 2009-09-15 10:41:34.605571 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2009-09-15 10:41:34.621196 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state 7 2009-09-15 10:41:34.621196 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2009-09-15 10:41:34.730575 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state 7 2009-09-15 10:41:35.246220 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2009-09-15 10:41:36.27500 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state 7 2009-09-15 10:41:36.27500 [DEBUG] mod_fax.c:137 FLOW T.30 Stop T2 (42080 remaining) 2009-09-15 10:41:36.27500 [DEBUG] mod_fax.c:137 FLOW FAX Switching from V.17 + V.21 to V.17 (-16.66dBm0) 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state 7 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Trainability (TCF) test result - 21822 total bits. longest run of zeros was 21600 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_C_NON_ECM_RX to T30_PHASE_B_TX 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 0 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 4 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 7 to 8 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: CFR with final frame tag 2009-09-15 10:41:37.574435 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: ff 13 84 2009-09-15 10:41:38.652601 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 8 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 8 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 8 to 12 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_C_ECM_RX 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 7 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 0 2009-09-15 10:41:38.730729 [DEBUG] mod_fax.c:137 FLOW T.30 Start T2 2009-09-15 10:41:38.746355 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier up (-2) in state 12 2009-09-15 10:41:38.793231 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Training failed (-5) in state 12 2009-09-15 10:41:38.871359 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Framing OK (-6) in state 12 2009-09-15 10:41:38.871359 [DEBUG] mod_fax.c:137 FLOW T.30 Start T1A 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Stop T1A (277280 remaining) 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: CFR with final frame tag 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: ff 13 84 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 In state 12 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Unexpected CFR received in state 12 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 12 to 3 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: DCN with final frame tag 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Tx: ff 13 fa 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW FAX Switching from V.17 + V.21 to V.21 (-33.64dBm0) 2009-09-15 10:41:39.261999 [DEBUG] mod_fax.c:137 FLOW T.30 HDLC signal status is Carrier down (-1) in state 3 2009-09-15 10:41:39.261999 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_C_ECM_RX to T30_PHASE_D_TX 2009-09-15 10:41:39.261999 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 0 2009-09-15 10:41:39.261999 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 4 2009-09-15 10:41:40.324540 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW T.30 Disconnecting 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 0 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 1 2009-09-15 10:41:40.402668 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 3 to 2 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW T.30 Send complete in phase T30_PHASE_E, state 2 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:167 ======================================================================== ====== 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:180 Fax processing not successful - result (13) Unexpected message received. 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:185 Remote station id: *********** 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:186 Local station id: SpanDSP Fax Ident 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:187 Pages transferred: 0 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:189 Total fax pages: 0 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:190 Image resolution: 8031x3850 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:191 Transfer Rate: 14400 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:193 ECM status on 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:194 remote country: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:195 remote vendor: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:196 remote model: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:198 ======================================================================== ====== 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from state 2 to 32 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW T.30 Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW FAX Set rx type 8 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW FAX FAX exchange complete 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW FAX Set tx type 8 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:137 FLOW FAX FAX exchange complete 2009-09-15 10:41:41.433958 [DEBUG] switch_core_codec.c:122 Restore original codec. ################################################# CFR in phase C? Hmm... Thanks again. -- Travis -----Original Message----- From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Steve Underwood Sent: Wednesday, September 16, 2009 12:51 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] faxrx error 13 Unexpected message received On 09/17/2009 12:08 AM, Travis Stutsman wrote:
In my attempts to receive a fax from a PSTN fax machine, the transaction fails with error code 13 "Unexpected message received". Verbose logging is on for mod_fax. Here is an exerpt:
################################################# 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: CFR with final frame tag 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Rx: ff 13 84 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 In state 12 2009-09-15 10:41:39.215123 [DEBUG] mod_fax.c:137 FLOW T.30 Unexpected CFR received in state 12 ......
========================================================================
====== 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:180 Fax processing not successful - result (13) Unexpected message received. 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:185 Remote station id: ********** 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:186 Local station id: SpanDSP Fax Ident 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:187 Pages transferred: 0 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:189 Total fax pages: 0 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:190 Image resolution: 8031x3850 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:191 Transfer Rate: 14400 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:193 ECM status on 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:194 remote country: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:195 remote vendor: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:196 remote model: 2009-09-15 10:41:41.402707 [DEBUG] mod_fax.c:198
========================================================================
====== #################################################
I have successfully received a fax from faxzero.com on this installation, as have I successfully sent a fax from freeswitch to the PSTN fax machine in question.
I've been digging, but there doesn't seem to be a whole lot of information on faxing. I guess I could use a bit of direction. Any input is much appreciated.
You seem to have chopped out all the interesting parts of that log. A full log might say something interesting. Steve _______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org