[Freeswitch-users] Unexpected DCS after Expected DCS !!!!

Hi As seen in the log below, I got an unexpected DCS after the expected DCS which led to disconnect and hangup. The set-up is rather unusual. FS <-> PSTN <-> Mobile (call forwarding) <-> PSTN <-> FS What should I blame? Echo, network delay or some other funky ghost? :) And what is the way out of this misery? If I ignore such unexpected DCS, do I risk some other error ? Thanks ! 86d8d618-79aa-11e1-8571-47d63f03be09 EXECUTE OpenZAP/2:1/30713846 rxfax(/srv/fax/in/86d8d618-79aa-11e1-8571-47d63f03be09.tiff) 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:51:52.718371 [DEBUG] mod_spandsp_fax.c:1083 Raw read codec activation Success L16 20000 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:51:52.718371 [DEBUG] switch_core_codec.c:116 OpenZAP/2:1/30713846 Push codec L16:10 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:51:52.718371 [DEBUG] mod_spandsp_fax.c:1099 Raw write codec activation Success L16 2012-03-29 19:51:52.722424 [DEBUG] ozmod_libpri.c:106 < Protocol Discriminator: Q.931 (8) len=5 2012-03-29 19:51:52.722424 [DEBUG] ozmod_libpri.c:106 < Call Ref: len= 2 (reference 136/0x88) (Originator) 2012-03-29 19:51:52.722424 [DEBUG] ozmod_libpri.c:106 < Message type: CONNECT ACKNOWLEDGE (15) 2012-03-29 19:51:55.738290 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 1 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Starting answer mode 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 0 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 4 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T2 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from state 1 to 17 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Sending ident 'chennai ident' 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: CSI without final frame tag 2012-03-29 19:51:55.798543 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: ff 03 40 74 6e 65 64 69 20 69 61 6e 6e 65 68 63 20 20 20 20 20 20 20 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 DIS: 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= 3G mobile network: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..1.= Can receive fax: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= 2-D coding: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 10..= Recording length: Unlimited 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .1.. ....= T.6 coding: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Polled sub-address: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= T.43 coding: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Plane interleave: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2012-03-29 19:51:57.378942 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Selective polling: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Sub-addressing: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Password: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= Character mode: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Digital network capability: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Duplex capability: Half only 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= JPEG coding: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Full colour mode: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Custom illuminant: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Custom gamut range: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 0... ....= Extension indicator: Not set 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: DIS with final frame tag 2012-03-29 19:51:57.379933 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: ff 13 80 00 ee fa c4 80 95 80 80 80 18 2012-03-29 19:51:57.838516 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:51:57.918984 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:51:57.918984 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2012-03-29 19:51:57.918984 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 4 2012-03-29 19:51:57.918984 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 0 2012-03-29 19:51:57.918984 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T4 2012-03-29 19:52:01.377951 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 T4 expired in phase T30_PHASE_B_RX, state 17 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Retry number 1 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_B_TX 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 0 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 4 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Sending ident 'chennai ident' 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: CSI without final frame tag 2012-03-29 19:52:01.378941 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: ff 03 40 74 6e 65 64 69 20 69 61 6e 6e 65 68 63 20 20 20 20 20 20 20 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 DIS: 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= 3G mobile network: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..1.= Can receive fax: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= 2-D coding: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1% 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 10..= Recording length: Unlimited 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .1.. ....= T.6 coding: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Polled sub-address: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= T.43 coding: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Plane interleave: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...1= R8x15.4lines/mm: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Selective polling: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Sub-addressing: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Password: Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set 2012-03-29 19:52:02.958770 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= Character mode: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Digital network capability: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Duplex capability: Half only 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= JPEG coding: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...0 ....= Full colour mode: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= 12bits/pel component: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= No subsampling (1:1:1): Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Custom illuminant: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Custom gamut range: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 0... ....= Extension indicator: Not set 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: DIS with final frame tag 2012-03-29 19:52:02.959765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: ff 13 80 00 ee fa c4 80 95 80 80 80 18 2012-03-29 19:52:03.438160 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:52:03.518033 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 17 2012-03-29 19:52:03.518033 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX 2012-03-29 19:52:03.518033 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 4 2012-03-29 19:52:03.518033 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 0 2012-03-29 19:52:03.518033 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T4 2012-03-29 19:52:03.998988 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-29 19:52:04.078900 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 17 2012-03-29 19:52:04.278765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Framing OK (-6) in state 17 2012-03-29 19:52:04.278765 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T4A 2012-03-29 19:52:05.538614 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop T4A (13920 remaining) 2012-03-29 19:52:05.538614 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: TSI without final frame tag 2012-03-29 19:52:05.538614 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 03 43 74 6e 65 64 49 20 78 61 46 20 61 6d 6f 67 6e 61 53 20 20 20 2012-03-29 19:52:05.538614 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Remote gave TSI as: "Sangoma Fax Ident" 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop none (0 remaining) 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: DCS with final frame tag 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 13 83 00 22 f8 44 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx final frame in state 17 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 DCS: 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= 3G mobile network: Not set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..1.= Receive fax: Set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 ..10 00..= Selected data signalling rate: V.17 14400bps 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 0... ....= 2-D coding: Not set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..00= Recording width: 215mm +- 1% 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 10..= Recording length: Unlimited 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .111 ....= Minimum scan line time: 0ms 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 1... ....= Extension indicator: Set 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2012-03-29 19:52:05.858271 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .... 0...= Frame size: 256 octets 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 .1.. ....= T.6 coding: Set 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 0... ....= Extension indicator: Not set 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Selected compression T.6 (3) 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Get document at 14400bps, modem 7 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from state 17 to 7 2012-03-29 19:52:05.859258 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T2 2012-03-29 19:52:05.898219 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2012-03-29 19:52:05.898219 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_C_NON_ECM_RX 2012-03-29 19:52:05.898219 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 0 2012-03-29 19:52:05.898219 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 7 2012-03-29 19:52:05.898219 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 0 2012-03-29 19:52:05.958033 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state 7 2012-03-29 19:52:05.958033 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2012-03-29 19:52:06.078320 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state 7 2012-03-29 19:52:07.138102 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2012-03-29 19:52:07.317993 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Training failed (-5) in state 7 2012-03-29 19:52:07.378781 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2012-03-29 19:52:08.878420 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state 7 2012-03-29 19:52:08.878420 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2012-03-29 19:52:12.438211 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state 7 2012-03-29 19:52:12.438211 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2012-03-29 19:52:12.578006 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Non-ECM signal status is Training failed (-5) in state 7 2012-03-29 19:52:12.657852 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Framing OK (-6) in state 7 2012-03-29 19:52:12.657852 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Start T2A 2012-03-29 19:52:13.998262 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop T2A (13280 remaining) 2012-03-29 19:52:13.998262 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: TSI without final frame tag 2012-03-29 19:52:13.998262 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 03 43 74 6e 65 64 49 20 78 61 46 20 61 6d 6f 67 6e 61 53 20 20 20 2012-03-29 19:52:13.998262 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Remote gave TSI as: "Sangoma Fax Ident" 2012-03-29 19:52:13.998262 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Switching from V.17 + V.21 to V.21 (-21.45dBm0) 2012-03-29 19:52:14.318385 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2012-03-29 19:52:14.378445 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2012-03-29 19:52:14.438480 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2012-03-29 19:52:15.878450 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2012-03-29 19:52:16.258042 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Abort (-8) in state 7 2012-03-29 19:52:17.358521 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier down (-1) in state 7 2012-03-29 19:52:20.898906 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier up (-2) in state 7 2012-03-29 19:52:21.118003 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Framing OK (-6) in state 7 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop none (0 remaining) 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: TSI without final frame tag 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 03 43 74 6e 65 64 49 20 78 61 46 20 61 6d 6f 67 6e 61 53 20 20 20 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Remote gave TSI as: "Sangoma Fax Ident" 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop none (0 remaining) 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: TSI without final frame tag 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 03 43 74 6e 65 64 49 20 78 61 46 20 61 6d 6f 67 6e 61 53 20 20 20 2012-03-29 19:52:22.458937 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Remote gave TSI as: "Sangoma Fax Ident" 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Stop none (0 remaining) 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: DCS with final frame tag 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx: ff 13 83 00 22 f8 44 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Rx final frame in state 7 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Unexpected DCS frame in state 7 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from state 7 to 3 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: DCN with final frame tag 2012-03-29 19:52:22.758302 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Tx: ff 13 fa 2012-03-29 19:52:22.838011 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 HDLC signal status is Carrier down (-1) in state 3 2012-03-29 19:52:22.839003 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_C_NON_ECM_RX to T30_PHASE_D_TX 2012-03-29 19:52:22.839003 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 0 2012-03-29 19:52:22.839003 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 4 2012-03-29 19:52:23.898025 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Disconnecting 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 0 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 1 2012-03-29 19:52:23.978342 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from state 3 to 2 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Send complete in phase T30_PHASE_E, state 2 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:321 ============================================================================== 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:333 Fax processing not successful - result (13) Unexpected message received. 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:338 Remote station id: Sangoma Fax Ident 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:339 Local station id: chennai ident 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:340 Pages transferred: 0 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:342 Total fax pages: 0 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:343 Image resolution: 8031x7700 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:344 Transfer Rate: 14400 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:346 ECM status on 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:347 remote country: 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:348 remote vendor: 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:349 remote model: 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:351 ============================================================================== 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from state 2 to 32 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW T.30 Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set rx type 9 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX FAX exchange complete 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX Set tx type 9 2012-03-29 19:52:24.978861 [DEBUG] mod_spandsp_fax.c:291 FLOW FAX FAX exchange complete 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:24.998043 [DEBUG] switch_core_codec.c:140 OpenZAP/2:1/30713846 Restore previous codec PCMA:8. 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:25.008098 [DEBUG] switch_core_session.c:885 Send signal OpenZAP/2:1/30713846 [BREAK] 86d8d618-79aa-11e1-8571-47d63f03be09 2012-03-29 19:52:25.018941 [DEBUG] switch_ivr.c:551 OpenZAP/2:1/30713846 Command Execute hangup() 86d8d618-79aa-11e1-8571-47d63f03be09 EXECUTE OpenZAP/2:1/30713846 hangup() regards, Anita