[Freeswitch-users] faxrx error 13 Unexpected message received

Travis Stutsman TStutsman at BossProductsInc.com
Wed Sep 16 10:21:02 PDT 2009


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 at lists.freeswitch.org
[mailto:freeswitch-users-bounces at lists.freeswitch.org] On Behalf Of
Steve Underwood
Sent: Wednesday, September 16, 2009 12:51 PM
To: freeswitch-users at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org




More information about the FreeSWITCH-users mailing list