[hylafax-users] EOP problems with t38modem and Cisco 5850

["Glenn Dalgliesh" <glenn@xxxxxxxxxxxxx>]

We are attempting use hylax, t38modem, & Cisco 5850's for outbound faxes but with certain fax machines we are seeing issues where after the EOP message the far end seem to results in a Line Error and fax fails. We can take a difference fax machine on the same line and have successful transmissions every time. The interesting thing is that if I fax a document that is 3.85 line/mm the fax seems to go thru to any machine but when 7.7 line/mm fax is sent only certain fax machines will accept it. The results are very consistent and are reproducible.

 

Thanks in advance for any insight any might have!

 

I am running t38modem with the following options:

 

/root/t38modem/obj_linux_x86_r/t38modem -n -o trace.log -p/dev/ttyx0 --old-asn --h245tunneldisable --route all@xxxxxxxxxxxxxx -g xxx.159.69.101 -u hylafax2 -tttt

 

Cisco dial-peer

dial-peer voice 30 voip
 incoming called-number ^23801..........$
 voice-class codec 1
 voice-class h323 1
 session protocol sipv2
 session target sip-server
 dtmf-relay rtp-nte
 fax rate 14400
 fax nsf 000000
 fax protocol t38 ls-redundancy 0 hs-redundancy 0
 no vad

 

 

This is one of the failed traces:

Aug 17 14:46:55.99: [27049]: SESSION BEGIN 00000376 4102959745
Aug 17 14:46:55.99: [27049]: HylaFAX (tm) Version 4.1.8
Aug 17 14:46:55.99: [27049]: SEND FAX: JOB 139 DEST 4102959745 COMMID 00000376 DEVICE '/dev/ttyx0'
Aug 17 14:46:55.99: [27049]: MODEM set DTR OFF
Aug 17 14:46:55.99: [27049]: MODEM set baud rate: 0 baud (flow control unchanged)
Aug 17 14:46:55.99: [27049]: DELAY 75 ms
Aug 17 14:46:56.07: [27049]: MODEM set DTR ON
Aug 17 14:46:56.07: [27049]: DELAY 2600 ms
Aug 17 14:46:59.68: [27049]: MODEM set baud rate: 19200 baud, input flow RTS/CTS, output flow RTS/CTS
Aug 17 14:46:59.68: [27049]: DELAY 10 ms
Aug 17 14:46:59.69: [27049]: MODEM flush i/o
Aug 17 14:46:59.69: [27049]: <-- [4:ATZ\r]
Aug 17 14:46:59.69: [27049]: --> [2:OK]
Aug 17 14:46:59.69: [27049]: DELAY 3000 ms
Aug 17 14:47:02.69: [27049]: <-- [5:ATE0\r]
Aug 17 14:47:02.69: [27049]: --> [4:ATE0]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [5:ATV1\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [5:ATQ0\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [7:ATS0=0\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [7:ATS8=2\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [8:ATS7=60\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [12:AT+FCLASS=1\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: <-- [7:ATL0M1\r]
Aug 17 14:47:02.69: [27049]: --> [2:OK]
Aug 17 14:47:02.69: [27049]: STATE CHANGE: RUNNING -> SENDING
Aug 17 14:47:02.69: [27049]: MODEM input buffering enabled
Aug 17 14:47:02.69: [27049]: <-- [12:AT+FCLASS=1\r]
Aug 17 14:47:02.79: [27049]: --> [2:OK]
Aug 17 14:47:02.79: [27049]: DIAL 4102959745
Aug 17 14:47:02.79: [27049]: <-- [15:ATDT4102959745\r]
Aug 17 14:47:29.51: [27049]: --> [7:CONNECT]
Aug 17 14:47:29.51: [27049]: MODEM input buffering disabled
Aug 17 14:47:29.74: [27049]: --> HDLC<9:FF C8 01 00 F6 1D 01 01 88>
Aug 17 14:47:29.74: [27049]: --> [2:OK]
Aug 17 14:47:29.74: [27049]: REMOTE best rate 14400 bit/s
Aug 17 14:47:29.74: [27049]: REMOTE max page width 1728 pixels in 215 mm
Aug 17 14:47:29.74: [27049]: REMOTE max unlimited page length
Aug 17 14:47:29.74: [27049]: REMOTE best vres 7.7 line/mm
Aug 17 14:47:29.74: [27049]: REMOTE best format 1-D MR
Aug 17 14:47:29.74: [27049]: REMOTE best 20 ms, 10 ms/scanline
Aug 17 14:47:29.74: [27049]: USE 14400 bit/s
Aug 17 14:47:29.74: [27049]: USE 20 ms, 10 ms/scanline
Aug 17 14:47:29.74: [27049]: SEND file "docq/doc139.tif;31"
Aug 17 14:47:29.74: [27049]: USE page width 1728 pixels in 215 mm
Aug 17 14:47:29.74: [27049]: USE unlimited page length
Aug 17 14:47:29.74: [27049]: USE 7.7 line/mm
Aug 17 14:47:29.74: [27049]: USE 1-D MR
Aug 17 14:47:29.74: [27049]: SEND training at v.17 14400 bit/s
Aug 17 14:47:29.74: [27049]: <-- [9:AT+FTH=3\r]
Aug 17 14:47:29.74: [27049]: --> [7:CONNECT]
Aug 17 14:47:29.74: [27049]: <-- HDLC<23:FF C0 C2 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04>
Aug 17 14:47:29.74: [27049]: <-- data [23]
Aug 17 14:47:29.74: [27049]: <-- data [2]
Aug 17 14:47:31.43: [27049]: --> [7:CONNECT]
Aug 17 14:47:31.43: [27049]: <-- HDLC<6:FF C8 C1 00 46 10>
Aug 17 14:47:31.43: [27049]: <-- data [6]
Aug 17 14:47:31.43: [27049]: <-- data [2]
Aug 17 14:47:31.81: [27049]: --> [2:OK]
Aug 17 14:47:31.81: [27049]: <-- [10:AT+FTS=20\r]
Aug 17 14:47:32.10: [27049]: --> [2:OK]
Aug 17 14:47:32.10: [27049]: <-- [11:AT+FTM=145\r]
Aug 17 14:47:32.10: [27049]: --> [7:CONNECT]
Aug 17 14:47:32.10: [27049]: <-- data [1024]
Aug 17 14:47:32.10: [27049]: <-- data [1024]
Aug 17 14:47:32.10: [27049]: <-- data [652]
Aug 17 14:47:32.10: [27049]: <-- data [2]
Aug 17 14:47:35.20: [27049]: --> [2:OK]
Aug 17 14:47:35.20: [27049]: <-- [9:AT+FRH=3\r]
Aug 17 14:47:36.05: [27049]: --> [7:CONNECT]
Aug 17 14:47:37.00: [27049]: --> HDLC<3:FF C8 21>
Aug 17 14:47:37.00: [27049]: --> [2:OK]
Aug 17 14:47:37.00: [27049]: TRAINING succeeded
Aug 17 14:47:37.00: [27049]: DELAY 75 ms
Aug 17 14:47:37.08: [27049]: <-- [11:AT+FTM=146\r]
Aug 17 14:47:37.08: [27049]: --> [7:CONNECT]
Aug 17 14:47:37.08: [27049]: SEND begin page
Aug 17 14:47:37.08: [27049]: <-- data [1029]
Aug 17 14:47:37.08: [27049]: <-- data [1030]
Aug 17 14:47:37.08: [27049]: <-- data [1024]
Aug 17 14:47:37.08: [27049]: <-- data [1024]
Aug 17 14:47:37.11: [27049]: <-- data [1024]
Aug 17 14:47:37.11: [27049]: <-- data [1027]
Aug 17 14:47:37.11: [27049]: <-- data [1026]
Aug 17 14:47:37.11: [27049]: <-- data [1026]
Aug 17 14:47:39.18: [27049]: <-- data [1024]
Aug 17 14:47:39.18: [27049]: <-- data [1026]
Aug 17 14:47:39.18: [27049]: <-- data [1024]
Aug 17 14:47:39.18: [27049]: <-- data [1024]
Aug 17 14:47:41.40: [27049]: <-- data [1024]
Aug 17 14:47:41.40: [27049]: <-- data [1024]
Aug 17 14:47:41.40: [27049]: <-- data [1024]
Aug 17 14:47:41.40: [27049]: <-- data [1024]
Aug 17 14:47:43.93: [27049]: <-- data [1024]
Aug 17 14:47:43.93: [27049]: <-- data [1024]
Aug 17 14:47:43.93: [27049]: <-- data [1024]
Aug 17 14:47:43.93: [27049]: <-- data [1024]
Aug 17 14:47:46.15: [27049]: <-- data [1024]
Aug 17 14:47:46.15: [27049]: <-- data [1024]
Aug 17 14:47:46.15: [27049]: <-- data [1024]
Aug 17 14:47:46.15: [27049]: <-- data [1024]
Aug 17 14:47:48.39: [27049]: <-- data [1024]
Aug 17 14:47:48.39: [27049]: <-- data [1024]
Aug 17 14:47:48.39: [27049]: <-- data [1024]
Aug 17 14:47:48.39: [27049]: <-- data [1024]
Aug 17 14:47:50.60: [27049]: <-- data [1024]
Aug 17 14:47:50.60: [27049]: <-- data [1024]
Aug 17 14:47:50.60: [27049]: <-- data [1024]
Aug 17 14:47:50.60: [27049]: <-- data [1024]
Aug 17 14:47:52.81: [27049]: <-- data [1024]
Aug 17 14:47:52.81: [27049]: <-- data [1024]
Aug 17 14:47:52.81: [27049]: <-- data [1024]
Aug 17 14:47:52.81: [27049]: <-- data [1024]
Aug 17 14:47:55.35: [27049]: <-- data [1024]
Aug 17 14:47:55.35: [27049]: <-- data [1024]
Aug 17 14:47:55.35: [27049]: <-- data [1024]
Aug 17 14:47:55.35: [27049]: <-- data [1024]
Aug 17 14:47:57.57: [27049]: <-- data [423]
Aug 17 14:47:57.57: [27049]: SENT 41383 bytes of data
Aug 17 14:47:57.57: [27049]: SEND 1D RTC
Aug 17 14:47:57.57: [27049]: <-- data [29]
Aug 17 14:47:57.57: [27049]: <-- data [2]
Aug 17 14:47:57.57: [27049]: SEND end page
Aug 17 14:48:00.48: [27049]: --> [2:OK]
Aug 17 14:48:00.48: [27049]: <-- [10:AT+FTS=50\r]
Aug 17 14:48:01.07: [27049]: --> [2:OK]
Aug 17 14:48:01.07: [27049]: SEND send EOP (no more pages or documents)
Aug 17 14:48:01.07: [27049]: <-- [9:AT+FTH=3\r]
Aug 17 14:48:01.07: [27049]: --> [7:CONNECT]
Aug 17 14:48:01.07: [27049]: <-- HDLC<3:FF C8 F4>
Aug 17 14:48:01.07: [27049]: <-- data [3]
Aug 17 14:48:01.07: [27049]: <-- data [2]
Aug 17 14:48:02.18: [27049]: --> [2:OK]
Aug 17 14:48:02.18: [27049]: <-- [9:AT+FRH=3\r]
Aug 17 14:48:05.28: [27049]: --> [0:]
Aug 17 14:48:05.28: [27049]: MODEM <Empty line>
Aug 17 14:48:05.28: [27049]: MODEM TIMEOUT: waiting for v.21 carrier
Aug 17 14:48:05.28: [27049]: <-- data [1]
Aug 17 14:48:05.28: [27049]: --> [2:OK]
Aug 17 14:48:05.28: [27049]: SEND send EOP (no more pages or documents)
Aug 17 14:48:05.28: [27049]: <-- [9:AT+FTH=3\r]
Aug 17 14:48:05.28: [27049]: --> [7:CONNECT]
Aug 17 14:48:05.28: [27049]: <-- HDLC<3:FF C8 F4>
Aug 17 14:48:05.28: [27049]: <-- data [3]
Aug 17 14:48:05.28: [27049]: <-- data [2]
Aug 17 14:48:06.39: [27049]: --> [2:OK]
Aug 17 14:48:06.39: [27049]: <-- [9:AT+FRH=3\r]
Aug 17 14:48:09.49: [27049]: --> [0:]
Aug 17 14:48:09.49: [27049]: MODEM <Empty line>
Aug 17 14:48:09.49: [27049]: MODEM TIMEOUT: waiting for v.21 carrier
Aug 17 14:48:09.49: [27049]: <-- data [1]
Aug 17 14:48:09.49: [27049]: --> [2:OK]
Aug 17 14:48:09.49: [27049]: SEND send EOP (no more pages or documents)
Aug 17 14:48:09.49: [27049]: <-- [9:AT+FTH=3\r]
Aug 17 14:48:09.49: [27049]: --> [7:CONNECT]
Aug 17 14:48:09.49: [27049]: <-- HDLC<3:FF C8 F4>
Aug 17 14:48:09.49: [27049]: <-- data [3]
Aug 17 14:48:09.49: [27049]: <-- data [2]
Aug 17 14:48:10.60: [27049]: --> [2:OK]
Aug 17 14:48:10.60: [27049]: <-- [9:AT+FRH=3\r]
Aug 17 14:48:13.70: [27049]: --> [0:]
Aug 17 14:48:13.70: [27049]: MODEM <Empty line>
Aug 17 14:48:13.70: [27049]: MODEM TIMEOUT: waiting for v.21 carrier
Aug 17 14:48:13.70: [27049]: <-- data [1]
Aug 17 14:48:13.70: [27049]: --> [2:OK]
Aug 17 14:48:13.70: [27049]: No response to MPS or EOP repeated 3 tries
Aug 17 14:48:13.70: [27049]: SEND: No response to MPS or EOP repeated 3 tries; Giving up after 3 attempts to send same page "docq/doc139.tif;31", dirnum 0
Aug 17 14:48:13.70: [27049]: <-- [9:AT+FTH=3\r]
Aug 17 14:48:13.70: [27049]: --> [7:CONNECT]
Aug 17 14:48:13.70: [27049]: <-- HDLC<3:FF C8 DF>
Aug 17 14:48:13.71: [27049]: <-- data [3]
Aug 17 14:48:13.71: [27049]: <-- data [2]
Aug 17 14:48:14.81: [27049]: --> [2:OK]
Aug 17 14:48:14.81: [27049]: MODEM input buffering enabled
Aug 17 14:48:14.81: [27049]: <-- [5:ATH0\r]
Aug 17 14:48:14.91: [27049]: --> [2:OK]
Aug 17 14:48:14.91: [27049]: MODEM set DTR OFF
Aug 17 14:48:14.91: [27049]: MODEM set baud rate: 0 baud (flow control unchanged)
Aug 17 14:48:14.91: [27049]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Aug 17 14:48:14.91: [27049]: SESSION END