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

Question

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

ROBERT-MCDOWELL opened this issue a year ago · 4 comments

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.

Answer 1 · 2023-09-12T15:05:25.000Z

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

Answer 2 · 2023-09-12T15:07:58.000Z

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

Answer 3 · 2023-09-12T15:37:29.000Z

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:

Answer 4 · 2023-09-13T14:12:22.000Z

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: