[hylafax-users] faxgetty hangs

["Sauro Saltini" <saltini@xxxxxx>]

My setup is :

 

- RH 7.3

- HylaFax 4.1.7 (installed via RPM)

- two Zyxel U90E modems both configured as Class 2 modems

- the only modified parameter in config.ttyS0/S1 is Class2RecvDataTrigger: "\022" (I can't receive faxes without this !)

 

I can receive faxes from different fax machines for some hours without any problem then, suddently, during the receive phase faxgetty stops logging data in the session logs , faxstat -s says that the modem is receiving but the transmission never ends !

 

Transcription of sample log follows:

 

Dec 03 15:08:02.08: [18335]: SESSION BEGIN 00006673 390289428428
Dec 03 15:08:02.08: [18335]: HylaFAX (tm) Version 4.1.7
Dec 03 15:08:02.08: [18335]: <-- [4:ATA\r]
Dec 03 15:08:11.80: [18335]: --> [5:+FCON]
Dec 03 15:08:11.80: [18335]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyS0'
Dec 03 15:08:11.80: [18335]: RECV FAX: begin
Dec 03 15:08:12.10: [18335]: --> [28:+FTSI:"                    "]
Dec 03 15:08:12.10: [18335]: REMOTE TSI ""
Dec 03 15:08:12.10: [18335]: --> [21:+FDCS:0,5,0,2,1,0,0,0]
Dec 03 15:08:12.10: [18335]: REMOTE wants 14400 bit/s
Dec 03 15:08:12.10: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:12.10: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:12.10: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:12.10: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:12.10: [18335]: --> [2:OK]
Dec 03 15:08:12.10: [18335]: <-- [7:AT+FDR\r]
Dec 03 15:08:18.85: [18335]: --> [28:+FTSI:"                    "]
Dec 03 15:08:18.85: [18335]: REMOTE TSI ""
Dec 03 15:08:25.16: [18335]: --> [21:+FDCS:0,4,0,2,1,0,0,0]
Dec 03 15:08:25.16: [18335]: REMOTE wants 12000 bit/s
Dec 03 15:08:25.16: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:25.16: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:25.16: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:25.16: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:25.46: [18335]: --> [28:+FTSI:"                    "]
Dec 03 15:08:25.46: [18335]: REMOTE TSI ""
Dec 03 15:08:31.77: [18335]: --> [21:+FDCS:0,3,0,2,1,0,0,0]
Dec 03 15:08:31.77: [18335]: REMOTE wants 9600 bit/s
Dec 03 15:08:31.77: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:31.77: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:31.77: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:31.77: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:32.06: [18335]: --> [28:+FTSI:"                    "]
Dec 03 15:08:32.06: [18335]: REMOTE TSI ""
Dec 03 15:08:38.38: [18335]: --> [21:+FDCS:0,2,0,2,1,0,0,0]
Dec 03 15:08:38.38: [18335]: REMOTE wants 7200 bit/s
Dec 03 15:08:38.38: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:38.38: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:38.38: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:38.38: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:38.68: [18335]: --> [28:+FTSI:"                    "]
Dec 03 15:08:38.68: [18335]: REMOTE TSI ""
Dec 03 15:08:42.40: [18335]: --> [21:+FDCS:0,1,0,2,1,0,0,0]
Dec 03 15:08:42.40: [18335]: REMOTE wants 4800 bit/s
Dec 03 15:08:42.40: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:42.40: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:42.40: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:42.40: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:42.40: [18335]: --> [5:+FCFR]
Dec 03 15:08:44.11: [18335]: --> [21:+FDCS:0,1,0,2,1,0,0,0]
Dec 03 15:08:44.11: [18335]: REMOTE wants 4800 bit/s
Dec 03 15:08:44.11: [18335]: REMOTE wants page width 1728 pixels in 215 mm
Dec 03 15:08:44.11: [18335]: REMOTE wants unlimited page length
Dec 03 15:08:44.11: [18335]: REMOTE wants 3.85 line/mm
Dec 03 15:08:44.11: [18335]: REMOTE wants 2-D MR
Dec 03 15:08:44.11: [18335]: --> [7:CONNECT]
Dec 03 15:08:44.11: [18335]: RECV: begin page
Dec 03 15:08:44.11: [18335]: RECV: send trigger 022
Dec 03 15:08:44.11: [18335]: <-- data [1]
Dec 03 15:09:08.53: [18335]: RECV: 14536 bytes of data, 1140 total lines

 

at this point the only way I have to go on is to kill faxgetty (i.e. restart hylafax) then I can see a new line in the session log :

 

Dec 03 15:12:50.11: [18335]: CLOSE /dev/ttyS0

 

I've found some similar (but not identical) posts in the archives and I've installed 4.1.7 over my old 4.1.5 trying to solve the problem but nothing changed.

 

I've tried to configure Zyxel as Class 1 but I can't send or receive faxes succesfully :

 

Receive session Log ( Class 1 ) :

 

Nov 24 14:18:17.27: [13383]: SESSION BEGIN 00005903 390289428428
Nov 24 14:18:17.27: [13383]: HylaFAX (tm) Version 4.1.6
Nov 24 14:18:17.27: [13383]: <-- [4:ATA\r]
Nov 24 14:18:23.97: [13383]: --> [7:CONNECT]
Nov 24 14:18:23.97: [13383]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyS0'
Nov 24 14:18:23.97: [13383]: RECV FAX: begin
Nov 24 14:18:24.05: [13383]: <-- data [23]
Nov 24 14:18:24.05: [13383]: <-- data [2]
Nov 24 14:18:25.07: [13383]: --> [7:CONNECT]
Nov 24 14:18:25.07: [13383]: <-- data [10]
Nov 24 14:18:25.07: [13383]: <-- data [2]
Nov 24 14:18:25.49: [13383]: --> [2:OK]
Nov 24 14:18:25.49: [13383]: <-- [9:AT+FRH=3\r]
Nov 24 14:18:26.00: [13383]: --> [7:CONNECT]
Nov 24 14:18:27.51: [13383]: --> [2:OK]
Nov 24 14:18:27.51: [13383]: REMOTE TSI "257601416"
Nov 24 14:18:27.51: [13383]: <-- [9:AT+FRH=3\r]
Nov 24 14:18:27.55: [13383]: --> [7:CONNECT]
Nov 24 14:18:27.85: [13383]: --> [2:OK]
Nov 24 14:18:27.85: [13383]: REMOTE wants 14400 bit/s
Nov 24 14:18:27.85: [13383]: REMOTE wants page width 1728 pixels in 215 mm
Nov 24 14:18:27.85: [13383]: REMOTE wants unlimited page length
Nov 24 14:18:27.85: [13383]: REMOTE wants 3.85 line/mm
Nov 24 14:18:27.85: [13383]: REMOTE wants 2-D MR
Nov 24 14:18:27.85: [13383]: RECV training at v.17 14400 bit/s
Nov 24 14:18:27.85: [13383]: <-- [11:AT+FRM=145\r]
Nov 24 14:18:29.56: [13383]: --> [7:CONNECT]
Nov 24 14:18:31.04: [13383]: RECV: TCF 2715 bytes, 0% non-zero, 2644 zero-run
Nov 24 14:18:31.05: [13383]: --> [10:NO CARRIER]
Nov 24 14:18:31.05: [13383]: DELAY 75 ms
Nov 24 14:18:31.13: [13383]: TRAINING succeeded
Nov 24 14:18:31.13: [13383]: <-- [9:AT+FTH=3\r]
Nov 24 14:18:32.27: [13383]: --> [7:CONNECT]
Nov 24 14:18:32.27: [13383]: <-- data [3]
Nov 24 14:18:32.27: [13383]: <-- data [2]
Nov 24 14:18:32.51: [13383]: --> [2:OK]
Nov 24 14:18:32.51: [13383]: <-- [11:AT+FRM=146\r]
Nov 24 14:18:33.67: [13383]: --> [7:CONNECT]
Nov 24 14:18:33.67: [13383]: RECV: begin page
Nov 24 14:18:47.35: [13383]: RECV: 1128 total lines, 0 bad lines, 0 consecutive bad lines
Nov 24 14:18:47.35: [13383]: RECV: end page
Nov 24 14:18:47.35: [13383]: --> [10:NO CARRIER]
Nov 24 14:18:47.35: [13383]: <-- [9:AT+FRH=3\r]
Nov 24 14:18:47.62: [13383]: --> [7:CONNECT]
Nov 24 14:18:48.53: [13383]: --> [2:OK]
Nov 24 14:18:48.53: [13383]: HDLC frame too short (3 bytes)
Nov 24 14:18:48.53: [13383]: <-- [9:AT+FRH=3\r]
Nov 24 14:18:51.72: [13383]: --> [7:CONNECT]
Nov 24 14:18:52.90: [13383]: --> [2:OK]
Nov 24 14:18:52.90: [13383]: HDLC frame too short (3 bytes)
Nov 24 14:18:52.90: [13383]: <-- [9:AT+FRH=3\r]
Nov 24 14:18:56.10: [13383]: --> [7:CONNECT]
Nov 24 14:18:57.28: [13383]: --> [2:OK]
Nov 24 14:18:57.28: [13383]: HDLC frame too short (3 bytes)
Nov 24 14:18:57.28: [13383]: RECV FAX (00005903): recvq/fax03656.tif from 257601416, route to <unspecified>, 0 pages in 0:33
Nov 24 14:18:57.28: [13383]: RECV FAX: T.30 T2 timeout, expected page not received
Nov 24 14:18:57.28: [13383]: <-- [9:AT+FTH=3\r]
Nov 24 14:18:58.32: [13383]: --> [7:CONNECT]
Nov 24 14:18:58.32: [13383]: <-- data [3]
Nov 24 14:18:58.32: [13383]: <-- data [2]
Nov 24 14:18:58.55: [13383]: --> [2:OK]
Nov 24 14:18:58.55: [13383]: RECV FAX (00005903): session with 257601416 terminated abnormally: T.30 T2 timeout, expected page not received
Nov 24 14:18:58.55: [13383]: RECV FAX: bin/faxrcvd "recvq/fax03656.tif" "ttyS0" "00005903" "T.30 T2 timeout, expected page not received" "" ""
Nov 24 14:18:58.94: [13383]: RECV FAX: end
Nov 24 14:18:58.94: [13383]: SESSION END

 

 

Send Session Log ( Class 1 )

 

nov 24 14:19:25.43: [14271]: SESSION BEGIN 00005904 39020254100811
nov 24 14:19:25.43: [14271]: HylaFAX (tm) Version 4.1.6
nov 24 14:19:28.12: [14271]: SEND FAX: JOB 671 DEST 0254100811 COMMID 00005904 DEVICE '/dev/ttyS0'
nov 24 14:19:28.12: [14271]: DELAY 75 ms
nov 24 14:19:28.20: [14271]: DELAY 2600 ms
nov 24 14:19:31.81: [14271]: DELAY 10 ms
nov 24 14:19:31.82: [14271]: <-- [4:ATZ\r]
nov 24 14:19:32.11: [14271]: --> [2:OK]
nov 24 14:19:32.11: [14271]: DELAY 3000 ms
nov 24 14:19:35.11: [14271]: <-- [5:ATE0\r]
nov 24 14:19:35.19: [14271]: --> [4:ATE0]
nov 24 14:19:35.19: [14271]: --> [2:OK]
nov 24 14:19:35.19: [14271]: <-- [5:ATV1\r]
nov 24 14:19:35.22: [14271]: --> [2:OK]
nov 24 14:19:35.22: [14271]: <-- [5:ATQ0\r]
nov 24 14:19:35.24: [14271]: --> [2:OK]
nov 24 14:19:35.24: [14271]: <-- [7:ATS0=0\r]
nov 24 14:19:35.27: [14271]: --> [2:OK]
nov 24 14:19:35.27: [14271]: <-- [7:ATS8=2\r]
nov 24 14:19:35.29: [14271]: --> [2:OK]
nov 24 14:19:35.29: [14271]: <-- [8:ATS7=60\r]
nov 24 14:19:35.32: [14271]: --> [2:OK]
nov 24 14:19:35.32: [14271]: <-- [12:AT+FCLASS=1\r]
nov 24 14:19:35.35: [14271]: --> [2:OK]
nov 24 14:19:35.35: [14271]: <-- [5:ATM0\r]
nov 24 14:19:35.38: [14271]: --> [2:OK]
nov 24 14:19:35.38: [14271]: <-- [12:AT+FCLASS=1\r]
nov 24 14:19:35.52: [14271]: --> [2:OK]
nov 24 14:19:35.52: [14271]: DIAL 0254100811
nov 24 14:19:35.52: [14271]: <-- [15:ATDT0254100811\r]
nov 24 14:19:58.77: [14271]: --> [7:CONNECT]
nov 24 14:20:00.20: [14271]: --> [2:OK]
nov 24 14:20:00.20: [14271]: REMOTE CSI ""
nov 24 14:20:00.20: [14271]: <-- [9:AT+FRH=3\r]
nov 24 14:20:00.23: [14271]: --> [7:CONNECT]
nov 24 14:20:00.49: [14271]: --> [2:OK]
nov 24 14:20:00.49: [14271]: REMOTE best rate 9600 bit/s
nov 24 14:20:00.49: [14271]: REMOTE max page width 1728 pixels in 215 mm
nov 24 14:20:00.49: [14271]: REMOTE max unlimited page length
nov 24 14:20:00.49: [14271]: REMOTE best vres 7.7 line/mm
nov 24 14:20:00.49: [14271]: REMOTE best format 1-D MR
nov 24 14:20:00.49: [14271]: REMOTE best 20 ms, 10 ms/scanline
nov 24 14:20:00.49: [14271]: USE 9600 bit/s
nov 24 14:20:00.49: [14271]: USE 20 ms, 10 ms/scanline
nov 24 14:20:00.49: [14271]: SEND file "docq/doc695.ps;01"
nov 24 14:20:00.51: [14271]: USE page width 1728 pixels in 215 mm
nov 24 14:20:00.51: [14271]: USE unlimited page length
nov 24 14:20:00.51: [14271]: USE 7.7 line/mm
nov 24 14:20:00.51: [14271]: USE 1-D MR
nov 24 14:20:00.51: [14271]: SEND training at v.29 9600 bit/s
nov 24 14:20:00.51: [14271]: <-- [9:AT+FTH=3\r]
nov 24 14:20:01.56: [14271]: --> [7:CONNECT]
nov 24 14:20:01.56: [14271]: <-- data [23]
nov 24 14:20:01.56: [14271]: <-- data [2]
nov 24 14:20:02.59: [14271]: --> [7:CONNECT]
nov 24 14:20:02.59: [14271]: <-- data [6]
nov 24 14:20:02.59: [14271]: <-- data [2]
nov 24 14:20:02.91: [14271]: --> [2:OK]
nov 24 14:20:02.91: [14271]: <-- [9:AT+FTS=7\r]
nov 24 14:20:03.01: [14271]: --> [2:OK]
nov 24 14:20:03.01: [14271]: <-- [10:AT+FTM=96\r]
nov 24 14:20:03.63: [14271]: --> [7:CONNECT]
nov 24 14:20:03.63: [14271]: <-- data [1024]
nov 24 14:20:03.63: [14271]: <-- data [776]
nov 24 14:20:03.63: [14271]: <-- data [2]
nov 24 14:20:05.55: [14271]: --> [2:OK]
nov 24 14:20:05.55: [14271]: <-- [9:AT+FRH=3\r]
nov 24 14:20:05.84: [14271]: --> [7:CONNECT]
nov 24 14:20:06.75: [14271]: --> [2:OK]
nov 24 14:20:06.75: [14271]: HDLC frame too short (3 bytes)
nov 24 14:20:06.75: [14271]: DELAY 1500 ms
nov 24 14:20:08.25: [14271]: SEND training at v.29 7200 bit/s
nov 24 14:20:08.25: [14271]: <-- [9:AT+FTH=3\r]
nov 24 14:20:09.29: [14271]: --> [7:CONNECT]
nov 24 14:20:09.29: [14271]: <-- data [23]
nov 24 14:20:09.29: [14271]: <-- data [2]
nov 24 14:20:10.29: [14271]: --> [7:CONNECT]
nov 24 14:20:10.29: [14271]: <-- data [6]
nov 24 14:20:10.29: [14271]: <-- data [2]
nov 24 14:20:10.59: [14271]: --> [2:OK]
nov 24 14:20:10.59: [14271]: <-- [9:AT+FTS=7\r]
nov 24 14:20:10.69: [14271]: --> [2:OK]
nov 24 14:20:10.69: [14271]: <-- [10:AT+FTM=72\r]
nov 24 14:20:11.30: [14271]: --> [7:CONNECT]
nov 24 14:20:11.30: [14271]: <-- data [1024]
nov 24 14:20:11.30: [14271]: <-- data [326]
nov 24 14:20:11.30: [14271]: <-- data [2]
nov 24 14:20:12.95: [14271]: --> [2:OK]
nov 24 14:20:12.95: [14271]: <-- [9:AT+FRH=3\r]
nov 24 14:20:13.41: [14271]: --> [7:CONNECT]
nov 24 14:20:14.40: [14271]: --> [2:OK]
nov 24 14:20:14.40: [14271]: HDLC frame too short (3 bytes)
nov 24 14:20:14.40: [14271]: DELAY 1500 ms
nov 24 14:20:15.90: [14271]: SEND training at v.27ter 4800 bit/s
nov 24 14:20:15.90: [14271]: <-- [9:AT+FTH=3\r]
nov 24 14:20:16.94: [14271]: --> [7:CONNECT]
nov 24 14:20:16.94: [14271]: <-- data [23]
nov 24 14:20:16.94: [14271]: <-- data [2]
nov 24 14:20:17.95: [14271]: --> [7:CONNECT]
nov 24 14:20:17.95: [14271]: <-- data [6]
nov 24 14:20:17.95: [14271]: <-- data [2]
nov 24 14:20:18.25: [14271]: --> [2:OK]
nov 24 14:20:18.25: [14271]: <-- [9:AT+FTS=7\r]
nov 24 14:20:18.35: [14271]: --> [2:OK]
nov 24 14:20:18.35: [14271]: <-- [10:AT+FTM=48\r]
nov 24 14:20:19.37: [14271]: --> [7:CONNECT]
nov 24 14:20:19.37: [14271]: <-- data [900]
nov 24 14:20:19.37: [14271]: <-- data [2]
nov 24 14:20:20.93: [14271]: --> [2:OK]
nov 24 14:20:20.93: [14271]: <-- [9:AT+FRH=3\r]
nov 24 14:20:21.48: [14271]: --> [7:CONNECT]
nov 24 14:20:22.47: [14271]: --> [2:OK]
nov 24 14:20:22.47: [14271]: HDLC frame too short (3 bytes)
nov 24 14:20:22.47: [14271]: DELAY 1500 ms
nov 24 14:20:23.97: [14271]: SEND training at v.27ter fallback mode 2400 bit/s
nov 24 14:20:23.97: [14271]: <-- [9:AT+FTH=3\r]
nov 24 14:20:25.00: [14271]: --> [7:CONNECT]
nov 24 14:20:25.00: [14271]: <-- data [23]
nov 24 14:20:25.00: [14271]: <-- data [2]
nov 24 14:20:26.00: [14271]: --> [7:CONNECT]
nov 24 14:20:26.00: [14271]: <-- data [6]
nov 24 14:20:26.00: [14271]: <-- data [2]
nov 24 14:20:26.30: [14271]: --> [2:OK]
nov 24 14:20:26.30: [14271]: <-- [9:AT+FTS=7\r]
nov 24 14:20:26.40: [14271]: --> [2:OK]
nov 24 14:20:26.40: [14271]: <-- [10:AT+FTM=24\r]
nov 24 14:20:27.68: [14271]: --> [7:CONNECT]
nov 24 14:20:27.68: [14271]: <-- data [450]
nov 24 14:20:27.68: [14271]: <-- data [2]
nov 24 14:20:29.23: [14271]: --> [2:OK]
nov 24 14:20:29.23: [14271]: <-- [9:AT+FRH=3\r]
nov 24 14:20:29.79: [14271]: --> [7:CONNECT]
nov 24 14:20:30.77: [14271]: --> [2:OK]
nov 24 14:20:30.81: [14271]: HDLC frame too short (3 bytes)
nov 24 14:20:30.81: [14271]: DELAY 1500 ms
nov 24 14:20:32.31: [14271]: TRAINING failed
nov 24 14:20:32.38: [14271]: <-- [9:AT+FTH=3\r]
nov 24 14:20:33.42: [14271]: --> [7:CONNECT]
nov 24 14:20:33.42: [14271]: <-- data [3]
nov 24 14:20:33.42: [14271]: <-- data [2]
nov 24 14:20:33.65: [14271]: --> [2:OK]
nov 24 14:20:33.65: [14271]: <-- [5:ATH0\r]
nov 24 14:20:33.84: [14271]: --> [2:OK]
nov 24 14:20:33.84: [14271]: SESSION END

 

It seems there are problems related to Training phase but I'm not a fax communication expert....

 

What's the best way to configure Zyxel U90E for Hylafax usage ???

 

Many thanks.

Sauro Saltini.