Update: Strange!  I am able to reproduce this consistently again and again!

regards,
Anita



On Thu, Mar 29, 2012 at 8:09 PM, Anita Hall <anita.hall@simmortel.com> wrote:
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