Hi,
I have a HylaFax system sending out a fax via an iaxmodem.
The Asterisk system then receives the fax and processes it with ReceiveFax().
According to the HylaFax log, at 00:08:15.62 I get this error: “RSPREC error/got DCN (receiver abort) {E103}”.
If I look at the Asterisk log around that time, I get this:
[00:08:12] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Start T4A
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Stop T4A (15040 remaining)
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Rx: PPS with final frame tag
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Rx: ff 13 bf 2f 00 00 01
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Rx final frame in state 17
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Unexpected PPS frame in state 17
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from state 17 to 3
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Tx: DCN with final frame tag
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Tx: ff 13 fa
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 HDLC signal status is Carrier down (-1) in state 3
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_D_TX
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set rx type 0
[00:08:14] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set tx type 4
[00:08:14] VERBOSE[10513][C-00002cfa] res_fax.c: Channel 'DAHDI/i3/123456789-5' fax session '7', [ 027.518736 ], channel sent 68 frames (1360 ms) of energy.
[00:08:14] VERBOSE[10513][C-00002cfa] res_fax.c: Channel 'DAHDI/i3/123456789-5' fax session '7', [ 027.560076 ], stack sent 111 frames (2220 ms) of silence.
[00:08:14] VERBOSE[10513][C-00002cfa] res_fax.c: Channel 'DAHDI/i3/123456789-5' fax session '7', [ 027.678680 ], channel sent 8 frames (160 ms) of silence.
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Starting final pause before disconnecting
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set rx type 0
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set tx type 1
[00:08:15] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from state 3 to 2
[00:08:15] VERBOSE[10513][C-00002cfa] res_fax.c: Channel 'DAHDI/i3/123456789-5' fax session '7', [ 028.660088 ], stack sent 55 frames (1100 ms) of energy.
[00:08:15] VERBOSE[10513][C-00002cfa] res_fax.c: Channel 'DAHDI/i3/123456789-5' fax session '7', [ 028.678685 ], channel sent 50 frames (1000 ms) of energy.
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Send complete in phase T30_PHASE_E, state 2
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from state 2 to 30
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set rx type 9
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX FAX exchange complete
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX Set tx type 9
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW FAX FAX exchange complete
[00:08:16] FAX[10513][C-00002cfa] res_fax.c: FLOW T.30 Call completed
[00:08:16] VERBOSE[10513][C-00002cfa] pbx.c: Executing [fax@from-BRI:6] NoOp("DAHDI/i3/123456789-5", "PSTN: fax received with status FAILED") in new stack
[00:08:16] VERBOSE[10513][C-00002cfa] pbx.c: Executing [fax@from-BRI:7] Hangup("DAHDI/i3/123456789-5", "") in new stack
[00:08:16] VERBOSE[10513][C-00002cfa] pbx.c: Spawn extension (from-BRI, fax, 7) exited non-zero on 'DAHDI/i3/123456789-5'
[00:08:16] VERBOSE[10513][C-00002cfa] chan_dahdi.c: Hungup 'DAHDI/i3/123456789-5'
Here’s the full HylaFax log:
00:07:39.93: [10454]: SESSION BEGIN 000000001 ReceivingNumber (logging via thread)
00:07:39.93: [10454]: HylaFAX (tm) Version 7.0.6
00:07:39.93: [10454]: SEND FAX: JOB 1 DEST ReceivingNumber COMMID 000000001 DEVICE '/dev/ttyIAX10000' FROM 'myuser <mail@domain.com>' USER myuser
00:07:39.93: [10454]: <-- [12:AT+FCLASS=1\r]
00:07:39.93: [10454]: --> [2:OK]
00:07:39.94: [10454]: DIAL ReceivingNumber
00:07:39.94: [10454]: <-- [14:ATDTReceivingNumber\r]
00:07:49.78: [10454]: --> [7:CONNECT]
00:07:49.92: [10454]: --> [10:NO CARRIER]
00:07:49.92: [10454]: MODEM No carrier
00:07:49.92: [10454]: <-- [9:AT+FRH=3\r]
00:07:50.18: [10454]: --> [7:CONNECT]
00:07:51.34: [10454]: --> [2:OK]
00:07:51.34: [10454]: REMOTE best rate 14400 bit/s
00:07:51.34: [10454]: REMOTE max A4 page width (215 mm)
00:07:51.34: [10454]: REMOTE max unlimited page length
00:07:51.34: [10454]: REMOTE best vres 15.4 line/mm
00:07:51.34: [10454]: REMOTE format support: MH, MR, MMR
00:07:51.34: [10454]: REMOTE supports T.30 Annex A, 256-byte ECM
00:07:51.34: [10454]: REMOTE best 0 ms/scanline
00:07:51.34: [10454]: USE 14400 bit/s
00:07:51.34: [10454]: USE error correction mode
00:07:51.34: [10454]: SEND file "docq/doc1.pdf;1d81"
00:07:51.34: [10454]: USE A4 page width (215 mm)
00:07:51.34: [10454]: USE unlimited page length
00:07:51.34: [10454]: USE 7.7 line/mm
00:07:51.34: [10454]: USE 2-D MMR
00:07:51.34: [10454]: USE 0 ms/scanline
00:07:51.34: [10454]: SEND training at v.17 14400 bit/s
00:07:51.34: [10454]: <-- [9:AT+FRS=7\r]
00:07:51.42: [10454]: --> [2:OK]
00:07:51.42: [10454]: <-- [9:AT+FTH=3\r]
00:07:51.44: [10454]: --> [7:CONNECT]
00:07:51.44: [10454]: <-- data [23]
00:07:51.44: [10454]: <-- data [2]
00:07:52.98: [10454]: --> [7:CONNECT]
00:07:52.98: [10454]: <-- data [7]
00:07:52.98: [10454]: <-- data [2]
00:07:53.38: [10454]: --> [2:OK]
00:07:53.38: [10454]: <-- [9:AT+FTS=7\r]
00:07:53.48: [10454]: --> [2:OK]
00:07:53.48: [10454]: <-- [11:AT+FTM=145\r]
00:07:53.50: [10454]: --> [7:CONNECT]
00:07:53.50: [10454]: DELAY 400 ms
00:07:53.90: [10454]: <-- data [1024]
00:07:53.90: [10454]: <-- data [1024]
00:07:53.90: [10454]: <-- data [653]
00:07:53.90: [10454]: <-- data [2]
00:07:56.46: [10454]: --> [2:OK]
00:07:56.46: [10454]: <-- [9:AT+FRH=3\r]
00:07:57.30: [10454]: --> [7:CONNECT]
00:07:58.38: [10454]: --> [2:OK]
00:07:58.38: [10454]: SEND recv CFR (confirmation to receive)
00:07:58.38: [10454]: TRAINING succeeded
00:07:58.38: [10454]: SEND begin page
00:07:58.38: [10454]: SEND send frame number 0
00:07:58.38: [10454]: SEND send frame number 1
00:07:58.38: [10454]: <-- [9:AT+FRS=7\r]
00:07:58.46: [10454]: --> [2:OK]
00:07:58.46: [10454]: <-- [11:AT+FTM=146\r]
00:07:58.48: [10454]: --> [7:CONNECT]
00:07:58.48: [10454]: DELAY 400 ms
00:07:58.88: [10454]: <-- data [970]
00:07:58.88: [10454]: <-- data [2]
00:07:59.50: [10454]: --> [2:OK]
00:07:59.50: [10454]: <-- [9:AT+FTS=9\r]
00:07:59.62: [10454]: --> [2:OK]
00:07:59.62: [10454]: <-- [9:AT+FTH=3\r]
00:07:59.64: [10454]: --> [7:CONNECT]
00:07:59.64: [10454]: <-- data [7]
00:07:59.64: [10454]: <-- data [2]
00:08:00.82: [10454]: --> [2:OK]
00:08:00.82: [10454]: SEND send PPS (partial page signal)
00:08:00.82: [10454]: SEND send EOP (no more pages or documents)
00:08:00.82: [10454]: <-- [9:AT+FRH=3\r]
00:08:01.74: [10454]: --> [7:CONNECT]
00:08:11.74: [10454]: <-- data [1]
00:08:11.76: [10454]: --> [2:]
00:08:11.76: [10454]: --> [2:OK]
00:08:11.76: [10454]: <-- [9:AT+FRS=7\r]
00:08:12.38: [10454]: --> [2:OK]
00:08:12.38: [10454]: <-- [9:AT+FTH=3\r]
00:08:12.40: [10454]: --> [7:CONNECT]
00:08:12.40: [10454]: <-- data [7]
00:08:12.40: [10454]: <-- data [2]
00:08:13.58: [10454]: --> [2:OK]
00:08:13.58: [10454]: SEND send PPS (partial page signal)
00:08:13.58: [10454]: SEND send EOP (no more pages or documents)
00:08:13.58: [10454]: <-- [9:AT+FRH=3\r]
00:08:14.52: [10454]: --> [7:CONNECT]
00:08:15.54: [10454]: --> [2:OK]
00:08:15.54: [10454]: SEND recv DCN (disconnect)
00:08:15.54: [10454]: <-- [9:AT+FRS=7\r]
00:08:15.62: [10454]: --> [2:OK]
00:08:15.62: [10454]: RSPREC error/got DCN (receiver abort) {E103}
00:08:15.62: [10454]: SEND end page
00:08:15.62: [10454]: <-- [9:AT+FTH=3\r]
00:08:15.64: [10454]: --> [7:CONNECT]
00:08:15.64: [10454]: <-- data [3]
00:08:15.64: [10454]: <-- data [2]
00:08:16.34: [10454]: --> [10:NO CARRIER]
00:08:16.34: [10454]: MODEM No carrier
00:08:17.34: [10454]: <-- [5:ATH0\r]
00:08:17.34: [10454]: --> [2:OK]
00:08:17.34: [10454]: SESSION END
The info file in hylaFax for the ReceivingNumber:
supportsVRes:3
supports2DEncoding:yes
supportsMMR:yes
hasV34Trouble:no
hasV17Trouble:no
senderHasV17Trouble:no
senderSkipsV29:no
senderConfusesRTN:no
senderConfusesPIN:no
senderFumblesECM:no
senderDataSent:0
senderDataSent1:0
senderDataSent2:0
senderDataMissed:0
senderDataMissed1:0
senderDataMissed2:0
dataSent:2
dataSent1:0
dataSent2:0
dataMissed:0
dataMissed1:0
dataMissed2:0
supportsPostScript:no
supportsBatching:yes
calledBefore:yes
maxPageWidth:1728
maxPageLength:65535
maxSignallingRate:"14400"
minScanlineTime:"0ms"
remoteCSI:"<UNSPECIFIED>"
remoteNSF:""
remoteDIS:"00 77 1F 23 01 89 01 01 01 18"
sendFailures:1
lastSendFailure:"RSPREC error/got DCN (receiver abort) {E103}"
dialFailures:0
pagingProtocol:"ixo"
The Asterisk dialplan regarding ReceiveFax:
[from-BRI]
exten => fax,1,NoOp(PSTN: Incoming fax for ${FAXEXTEN}, caller ${CALLERID(all)})
same => n,Set(CUSTOM_FAXDIR=/tmp)
same => n,Set(CUSTOM_FAXRAND=${STRFTIME(,,%C%y%m%d%H%M)})
same => n,Set(FAXOPT(maxrate)=9600)
same => n,ReceiveFax(${CUSTOM_FAXDIR}/fax_${FAXEXTEN}_${CALLERID(num)}_${CUSTOM_FAXRAND}.tif,d)
same => n,NoOp(PSTN: fax received with status ${FAXSTATUS})
same => n,Hangup()
What is the correct way to set the max rate? In Asterisk, I’m setting it to 9600 via FAXOPT, but HylaFax says it’s 14400.
I see “NO CARRIER” messages in the HylaFax log, but I’m not sure they are the cause of the issue.
I guess that right after I get the “RSPREC error/got DCN (receiver abort) {E103}” in HylaFax, that’s when I get FAXSTATUS = FAILED.
However, I don’t see a reason for the failure in the Asterisk log (maybe “Carrier down” but not quite sure).
Any ideas?