freeswitch / spandsp

SpanDSP is a low-level signal processing library that modulates and demodulates signals commonly used in telephony, such as the "noise" generated by a fax modem or DTMF touchpad.
Other
141 stars 117 forks source link

update last git today and now cannot send faxes... #60

Closed ROBERT-MCDOWELL closed 10 months ago

ROBERT-MCDOWELL commented 10 months ago

HDLC carrier up and down if I send a fax from 2 freeswitch. no answer from the leg B if send to a fax machine after a page sent. no special errors in the logs. I updated spandsp, sofia-sip and freeswitch. everything compiled fine.

ROBERT-MCDOWELL commented 10 months ago

found the issue, my spandsp.conf.xml file was too old. I replaced with the vanilla one and worked again. thanks!

ROBERT-MCDOWELL commented 10 months ago

reopening it since the "No response after sending a page" still persists after each fax sent to a real fax machine.....

ROBERT-MCDOWELL commented 10 months ago

I get also 2023-09-12 15:35:50.716646 96.97% [INFO] mod_spandsp_fax.c:596 Fax processing not successful - result (20) Received no response to DCS or TCF. Remote station id: Channel-15 Local station id: + Pages transferred: 0 Total fax pages: 1 Image resolution: 8040x7700 Transfer Rate: 14400 ECM status on T38 status off remote country: remote vendor: remote model:

ROBERT-MCDOWELL commented 10 months ago

more info with debug: 2023-09-13 14:06:08.479248 92.93% [NOTICE] switch_core_session.c:3089 Execute [depth=3] txfax(${fax_path}) EXECUTE [depth=3] sofia/external/XXXXXXXXXXX txfax(/NFS_DATA/PBX/XXXXXXXXXXX/fax-XXXXXXXXXXX_58826_OK.tiff) 2023-09-13 14:06:08.959206 92.93% [DEBUG] mod_spandsp_fax.c:1607 Raw read codec activation Success L16 20000 2023-09-13 14:06:08.959206 92.93% [DEBUG] switch_core_codec.c:229 sofia/external/XXXXXXXXXXX Push codec L16:100 2023-09-13 14:06:08.959206 92.93% [DEBUG] mod_spandsp_fax.c:1625 Raw write codec activation Success L16 2023-09-13 14:06:08.999231 92.93% [DEBUG] switch_rtp.c:7503 Correct audio ip/port confirmed. 2023-09-13 14:06:09.219239 93.43% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier up (-2) in state T 2023-09-13 14:06:10.899304 93.43% [DEBUG] switch_rtp.c:7503 Correct video ip/port confirmed. 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:1830 data passed to lcr is [17784033915 default] 2023-09-13 14:06:11.979274 93.40% [WARNING] mod_lcr.c:1882 Using default CID [18005551212] 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:930 Has NPA NXX: [1 == 1] 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:889 SQL: SELECT 'state', count(DISTINCT state) FROM npa_nxx_company_ocn WHERE (npa=778 AND nxx=403) OR (npa=800 AND nxx=555) UNION SELECT 'lata', count(DISTINCT lata) FROM npa_nxx_company_ocn WHERE (npa=778 AND nxx=403) OR (npa=800 AND nxx=555) 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:844 Type: lata, Count: 0 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:844 Type: state, Count: 0 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:946 intra routing [state:0 lata:0] so rate field is [rate] 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:970 we have an event 2023-09-13 14:06:11.979274 93.40% [DEBUG] mod_lcr.c:998 SQL: SELECT l.digits, c.carrier_name, l.rate AS lcr_rate_field, cg.prefix AS gw_prefix, cg.suffix AS gw_suffix, l.lead_strip, l.trail_strip, l.prefix, l.suffix, cg.codec, l.cid FROM lcr l JOIN carriers c ON l.carrier_id=c.id JOIN carrier_gateway cg ON c.id=cg.carrier_id WHERE c.enabled='1' AND cg.enabled='1' AND l.enabled='1' AND digits_prefix @> '17784033915, 1778403391, 177840339, 17784033, 1778403, 177840, 17784, 1778, 177, 17, 1' ORDER BY digits DESC, prefix DESC, rate DESC LIMIT 1; 2023-09-13 14:06:12.039231 93.40% [DEBUG] mod_lcr.c:350 Returning Dialstring lcr_carrier=(null),lcr_rate=0.00860(null)17784033915(null)(null) 2023-09-13 14:06:12.039231 93.40% [DEBUG] mod_lcr.c:699 Adding (null) to head of list 2023-09-13 14:06:12.039231 93.40% [DEBUG] mod_lcr.c:350 Returning Dialstring lcr_carrier=(null),lcr_rate=0.00860(null)17784033915(null)(null) 2023-09-13 14:06:13.719232 93.10% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Abort (-8) in state T 2023-09-13 14:06:13.959207 93.10% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Abort (-8) in state T 2023-09-13 14:06:15.419236 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier down (-1) in state T 2023-09-13 14:06:15.479231 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier up (-2) in state T 2023-09-13 14:06:15.699205 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Framing OK (-6) in state T 2023-09-13 14:06:15.699205 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase A_CNG to B_RX 2023-09-13 14:06:15.699205 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:06:15.699205 91.70% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:06:16.639259 90.80% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier down (-1) in state T 2023-09-13 14:06:16.759320 90.80% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier up (-2) in state T 2023-09-13 14:06:17.559239 90.47% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier down (-1) in state T 2023-09-13 14:06:21.219317 87.30% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier up (-2) in state T 2023-09-13 14:06:21.459207 87.30% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Framing OK (-6) in state T 2023-09-13 14:06:22.959284 87.27% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Stop none (0 remaining) 2023-09-13 14:06:22.959284 87.27% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Rx: CSI without final frame tag 2023-09-13 14:06:22.959284 87.27% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Rx: ff 03 40 38 31 2d 6c 65 6e 6e 61 68 43 20 20 20 20 20 20 20 20 20 20 2023-09-13 14:06:22.959284 87.27% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Remote gave CSI as: "Channel-18" 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Stop none (0 remaining) 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Rx: DIS with final frame tag 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Rx: ff 13 80 00 ee f8 c4 80 10 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Rx final frame in state T 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Queuing phase B_TX 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 DIS: 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 0...= 3G mobile network: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ..0. ....= V.8 capabilities: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .0.. ....= Preferred octets: 256 octets 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..1.= Can receive fax: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 1... ....= 2-D coding: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..00= Recording width: 215mm +- 1% 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 10..= Recording length: Unlimited 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 1... ....= Extension indicator: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .1.. ....= T.6 coding: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 1... ....= Extension indicator: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ...0= "Field not valid" supported: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..0.= Multiple selective polling: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .0..= Polled sub-address: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 0...= T.43 coding: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ...0 ....= Plane interleave: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 1... ....= Extension indicator: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ...0= R8x15.4lines/mm: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 0...= Inch-based resolution preferred: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ...1 ....= Metric-based resolution preferred: Set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .0.. ....= Selective polling: Not set 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 0... ....= Extension indicator: Not set 2023-09-13 14:06:23.279207 86.87% [INFO] mod_spandsp_fax.c:360 === Negotiation Result

Remote station id: Channel-18 Local station id: +XXXXXXXXXXX Transfer Rate: 14400 ECM status on T38 status off remote country: remote vendor: remote model: Total fax pages: 0

2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Trying to send file '/NFS_DATA/PBX/XXXXXXXXXXX/fax-XXXXXXXXXXX_58826_OK.tiff' 2023-09-13 14:06:23.279207 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start sending document 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Choose image type bi-level (0), compression T.6 (8) 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Minimum bits per row will be 0 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Starting page 1 of transfer 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Partial document buffer contains 165 frames (256 per frame) 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Image width is A4 at 8040dpm x 7700dpm 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Put document with modem (7) V.17 at 14400bps 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from state T to D 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending ident '+XXXXXXXXXXX' 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: TSI without final frame tag 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 03 43 30 31 35 30 33 38 37 38 37 37 31 2b 20 20 20 20 20 20 20 20 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 HDLC signal status is Carrier down (-1) in state D 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase B_RX to B_TX 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:06:23.439357 86.87% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase B_TX, state D 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 DCS: 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 0...= 3G mobile network: Not set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..1.= Receive fax: Set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 ..10 00..= Selected data signalling rate: V.17 14400bps 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 0... ....= 2-D coding: Not set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..00= Recording width: 215mm +- 1% 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 10..= Recording length: Unlimited 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .111 ....= Minimum scan line time: 0ms 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 1... ....= Extension indicator: Set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... .1..= Error correction mode (ECM): ECM 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .... 0...= Frame size: 256 octets 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 .1.. ....= T.6 coding: Set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 0... ....= Extension indicator: Not set 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: DCS with final frame tag 2023-09-13 14:06:25.039206 86.07% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 83 00 62 f8 44 2023-09-13 14:06:25.319357 84.90% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase B_TX, state D 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase C_ECM_TX, state IV 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: RCP without final frame tag 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 03 86 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase C_ECM_TX, state IV 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: RCP without final frame tag 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 03 86 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase C_ECM_TX, state IV 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: RCP without final frame tag 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 03 86 2023-09-13 14:06:56.299254 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase C_ECM_TX, state IV 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase C_ECM_TX, state IV 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase C_ECM_TX to D_TX 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 No more pages to send 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:06:56.359320 79.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from state IV to IV_PPS_Q 2023-09-13 14:06:57.519225 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:06:57.599245 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:06:57.599245 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:06:57.599245 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:06:57.599245 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:06:57.599245 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Retry number 1 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:07:01.039320 79.63% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:07:02.239360 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:02.299305 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:02.299305 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:07:02.299305 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:07:02.299305 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:07:02.299305 79.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Retry number 2 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:07:05.759255 79.13% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:07:06.939318 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:07.019255 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:07.019255 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:07:07.019255 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:07:07.019255 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:07:07.019255 79.17% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:09.139305 78.80% [DEBUG] mod_nibblebill.c:695 Received request via SESSION_HEARTBEAT! 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Retry number 3 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:07:10.479304 78.70% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:07:11.659318 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:11.739229 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:11.739229 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:07:11.739229 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:07:11.739229 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:07:11.739229 78.77% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:07:15.179379 78.53% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:07:16.359210 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:16.439207 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:16.439207 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:07:16.439207 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:07:16.439207 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:07:16.439207 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Retry number 5 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Sending PPS-EOP 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: PPS with final frame tag 2023-09-13 14:07:19.899205 78.40% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 bf 2f 00 00 a4 2023-09-13 14:07:21.059306 78.37% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:21.159228 78.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state IV_PPS_Q 2023-09-13 14:07:21.159228 78.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to D_RX 2023-09-13 14:07:21.159228 78.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type V.21 (4) 2023-09-13 14:07:21.159228 78.33% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type None (0) 2023-09-13 14:07:21.159228 78.33% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Start T4 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Too many retries. Giving up. 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Status changing to 'No response after sending a page' 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_RX to D_TX 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type V.21 (4) 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from state IV_PPS_Q to C 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: DCN with final frame tag 2023-09-13 14:07:24.619223 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Tx: ff 13 fb 2023-09-13 14:07:25.679255 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state C 2023-09-13 14:07:25.759322 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase D_TX, state C 2023-09-13 14:07:25.759322 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Starting final pause before disconnecting 2023-09-13 14:07:25.919312 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from phase D_TX to E 2023-09-13 14:07:25.919312 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set rx type None (0) 2023-09-13 14:07:25.919312 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW FAX Set tx type Pause (1) 2023-09-13 14:07:25.919312 78.23% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Changing from state C to B 2023-09-13 14:07:26.879243 78.20% [DEBUG] mod_spandsp_fax.c:302 FLOW T.30 Send complete in phase E, state B 2023-09-13 14:07:26.879243 78.20% [INFO] mod_spandsp_fax.c:596

Fax processing not successful - result (21) No response after sending a page. Remote station id: Channel-18 Local station id: +XXXXXXXXXXX Pages transferred: 0 Total fax pages: 1 Image resolution: 8040x7700 Transfer Rate: 14400 ECM status on T38 status off remote country: remote vendor: remote model: