[hylafax-users] Frequent transmission breakdowns HF4.1 und HF4.1b3

[Peter Bauer <p.bauer@itserv-gmbh.com>]

Hi,

I encounter frequent transmission breakdowns. I try to send a quite
complex PostScript image (/usr/openwin/share/images/PostScript/golfer.ps), but
After a few lines sent to my fax machine, the connection seems to be cut off
by hylafax. I use a Class 1 SupraFAX 144LT Modem (Rockwell Chipset).

Even stranger: since the image is quite complex, it looks for me as if the
"SEND send EOP" is being transmitted too soon. There must be more data to
send...

Cabeling seems to be no problem - receiving faxes works.

Also strange: when I fax another document to myself, the fax machine
displays an transmission error, but does not hang up. Then, hylafax
resends the page, fails again, and the cycle starts again (up to 
three times).

Any idea what I can look for to trace back the problem? Here is a
typical transmisson log:

Jul 17 22:47:20.04: [ 5961]: SESSION BEGIN 00000012 4970032
Jul 17 22:47:20.05: [ 5961]: HylaFAX (tm) Version 4.1
Jul 17 22:47:20.05: [ 5961]: SEND FAX: JOB 10 DEST 32 COMMID 00000012
Jul 17 22:47:20.05: [ 5961]: DEVICE '/dev/cua/b'
Jul 17 22:47:20.05: [ 5961]: DELAY 75 ms
Jul 17 22:47:20.13: [ 5961]: DELAY 2600 ms
Jul 17 22:47:22.74: [ 5961]: <-- [4:ATZ\r]
Jul 17 22:47:24.88: [ 5961]: --> [2:OK]
Jul 17 22:47:24.88: [ 5961]: <-- [5:ATE0\r]
Jul 17 22:47:25.02: [ 5961]: --> [4:ATE0]
Jul 17 22:47:25.02: [ 5961]: --> [2:OK]
Jul 17 22:47:25.02: [ 5961]: <-- [5:ATV1\r]
Jul 17 22:47:25.16: [ 5961]: --> [2:OK]
Jul 17 22:47:25.16: [ 5961]: <-- [5:ATQ0\r]
Jul 17 22:47:25.30: [ 5961]: --> [2:OK]
Jul 17 22:47:25.30: [ 5961]: <-- [7:ATS0=0\r]
Jul 17 22:47:25.44: [ 5961]: --> [2:OK]
Jul 17 22:47:25.44: [ 5961]: <-- [7:ATS8=2\r]
Jul 17 22:47:25.58: [ 5961]: --> [2:OK]
Jul 17 22:47:25.58: [ 5961]: <-- [8:ATS7=60\r]
Jul 17 22:47:25.72: [ 5961]: --> [2:OK]
Jul 17 22:47:25.72: [ 5961]: <-- [6:AT&K3\r]
Jul 17 22:47:25.86: [ 5961]: --> [2:OK]
Jul 17 22:47:25.86: [ 5961]: <-- [6:AT&D3\r]
Jul 17 22:47:26.00: [ 5961]: --> [2:OK]
Jul 17 22:47:26.00: [ 5961]: <-- [6:AT&C1\r]
Jul 17 22:47:26.14: [ 5961]: --> [2:OK]
Jul 17 22:47:26.14: [ 5961]: <-- [12:AT+FCLASS=1\r]
Jul 17 22:47:26.28: [ 5961]: --> [2:OK]
Jul 17 22:47:26.28: [ 5961]: <-- [9:AT+FAA=0\r]
Jul 17 22:47:26.29: [ 5961]: --> [2:OK]
Jul 17 22:47:26.29: [ 5961]: <-- [5:ATM0\r]
Jul 17 22:47:26.29: [ 5961]: --> [2:OK]
Jul 17 22:47:26.29: [ 5961]: <-- [12:AT+FCLASS=1\r]
Jul 17 22:47:26.39: [ 5961]: --> [2:OK]
Jul 17 22:47:26.43: [ 5961]: DIAL 32
Jul 17 22:47:26.44: [ 5961]: <-- [9:ATX3DT32\r]
Jul 17 22:47:44.95: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:46.73: [ 5961]: --> [2:OK]
Jul 17 22:47:46.73: [ 5961]: REMOTE NSF "00 00 11 90 00 85 57 10 49 54 53 45 52 56 20 47 4D 42 48 20 20 20 20 20 01 0C 01 0A 00 2C 00 80 91 80 02 01 01 4A"
Jul 17 22:47:46.73: [ 5961]: NSF remote fax equipment: Canon 
Jul 17 22:47:46.73: [ 5961]: NSF remote station ID: "ITSERV GMBH     "
Jul 17 22:47:46.73: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:47:46.74: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:47.42: [ 5961]: --> [2:OK]
Jul 17 22:47:47.42: [ 5961]: REMOTE CSI "+49 700 487378329"
Jul 17 22:47:47.42: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:47:47.43: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:47.69: [ 5961]: --> [2:OK]
Jul 17 22:47:47.69: [ 5961]: REMOTE best rate 9600 bit/s
Jul 17 22:47:47.69: [ 5961]: REMOTE max page width 1728 pixels in 215 mm
Jul 17 22:47:47.69: [ 5961]: REMOTE max unlimited page length 
Jul 17 22:47:47.69: [ 5961]: REMOTE best vres 7.7 line/mm
Jul 17 22:47:47.69: [ 5961]: REMOTE best format 2-D MR
Jul 17 22:47:47.69: [ 5961]: REMOTE supports T.30 Annex A, ECM
Jul 17 22:47:47.69: [ 5961]: REMOTE best 10 ms, 5 ms/scanline
Jul 17 22:47:47.69: [ 5961]: USE 9600 bit/s
Jul 17 22:47:47.69: [ 5961]: USE 10 ms, 5 ms/scanline
Jul 17 22:47:47.69: [ 5961]: SEND file "docq/doc11.ps;40"
Jul 17 22:47:47.69: [ 5961]: USE page width 1728 pixels in 215 mm
Jul 17 22:47:47.69: [ 5961]: USE unlimited page length 
Jul 17 22:47:47.69: [ 5961]: USE 3.85 line/mm
Jul 17 22:47:47.70: [ 5961]: USE 2-D MR
Jul 17 22:47:47.70: [ 5961]: SEND training at v.29 9600 bit/s
Jul 17 22:47:47.70: [ 5961]: <-- [9:AT+FTH=3\r]
Jul 17 22:47:47.74: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:47.74: [ 5961]: <-- data [23]
Jul 17 22:47:47.74: [ 5961]: <-- data [2]
Jul 17 22:47:49.47: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:49.47: [ 5961]: <-- data [6]
Jul 17 22:47:49.47: [ 5961]: <-- data [2]
Jul 17 22:47:49.85: [ 5961]: --> [2:OK]
Jul 17 22:47:49.85: [ 5961]: DELAY 75 ms
Jul 17 22:47:49.93: [ 5961]: <-- [10:AT+FTM=96\r]
Jul 17 22:47:49.96: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:49.96: [ 5961]: <-- data [1024]
Jul 17 22:47:49.96: [ 5961]: <-- data [776]
Jul 17 22:47:49.96: [ 5961]: <-- data [2]
Jul 17 22:47:51.95: [ 5961]: --> [2:OK]
Jul 17 22:47:51.95: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:47:52.36: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:53.31: [ 5961]: --> [2:OK]
Jul 17 22:47:53.31: [ 5961]: TRAINING succeeded
Jul 17 22:47:53.31: [ 5961]: <-- [10:AT+FTM=96\r]
Jul 17 22:47:53.34: [ 5961]: --> [7:CONNECT]
Jul 17 22:47:53.34: [ 5961]: SEND begin page
Jul 17 22:47:53.34: [ 5961]: <-- data [1027]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1025]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1025]
Jul 17 22:47:53.34: [ 5961]: <-- data [1024]
Jul 17 22:47:53.34: [ 5961]: <-- data [1026]
Jul 17 22:47:53.34: [ 5961]: <-- data [1027]
Jul 17 22:47:53.34: [ 5961]: <-- data [413]
Jul 17 22:47:53.34: [ 5961]: SENT 13719 bytes of data
Jul 17 22:47:53.35: [ 5961]: <-- data [1038]
Jul 17 22:47:53.35: [ 5961]: <-- data [1051]
Jul 17 22:47:53.35: [ 5961]: <-- data [1058]
Jul 17 22:47:53.35: [ 5961]: <-- data [1071]
Jul 17 22:47:53.35: [ 5961]: <-- data [1065]
Jul 17 22:47:53.35: [ 5961]: <-- data [1065]
Jul 17 22:47:53.35: [ 5961]: <-- data [1074]
Jul 17 22:47:53.35: [ 5961]: <-- data [1067]
Jul 17 22:47:53.35: [ 5961]: <-- data [1067]
Jul 17 22:47:53.35: [ 5961]: <-- data [1084]
Jul 17 22:47:53.35: [ 5961]: <-- data [1080]
Jul 17 22:47:53.35: [ 5961]: <-- data [1087]
Jul 17 22:47:53.35: [ 5961]: <-- data [1080]
Jul 17 22:47:53.35: [ 5961]: <-- data [360]
Jul 17 22:47:53.35: [ 5961]: SENT 13659 bytes of data
Jul 17 22:47:53.35: [ 5961]: <-- data [1082]
Jul 17 22:47:53.35: [ 5961]: <-- data [1077]
Jul 17 22:47:53.35: [ 5961]: <-- data [1086]
Jul 17 22:47:53.35: [ 5961]: <-- data [1081]
Jul 17 22:47:53.35: [ 5961]: <-- data [1079]
Jul 17 22:47:53.35: [ 5961]: <-- data [1080]
Jul 17 22:47:53.35: [ 5961]: <-- data [1078]
Jul 17 22:47:53.35: [ 5961]: <-- data [1077]
Jul 17 22:47:53.35: [ 5961]: <-- data [1084]
Jul 17 22:47:53.35: [ 5961]: <-- data [1065]
Jul 17 22:47:53.35: [ 5961]: <-- data [1064]
Jul 17 22:47:53.35: [ 5961]: <-- data [1037]
Jul 17 22:47:53.35: [ 5961]: <-- data [1034]
Jul 17 22:47:53.35: [ 5961]: <-- data [383]
Jul 17 22:47:53.35: [ 5961]: SENT 13695 bytes of data
Jul 17 22:47:53.35: [ 5961]: <-- data [1026]
Jul 17 22:47:53.35: [ 5961]: <-- data [1026]
Jul 17 22:47:53.35: [ 5961]: <-- data [1026]
Jul 17 22:47:53.36: [ 5961]: <-- data [1025]
Jul 17 22:47:53.36: [ 5961]: <-- data [1024]
Jul 17 22:47:53.36: [ 5961]: <-- data [1024]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1024]
Jul 17 22:47:53.36: [ 5961]: <-- data [1025]
Jul 17 22:47:53.36: [ 5961]: <-- data [1024]
Jul 17 22:47:53.36: [ 5961]: <-- data [1025]
Jul 17 22:47:53.36: [ 5961]: <-- data [1032]
Jul 17 22:47:53.36: [ 5961]: <-- data [404]
Jul 17 22:47:53.36: [ 5961]: SENT 13714 bytes of data
Jul 17 22:47:53.36: [ 5961]: <-- data [1029]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1030]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1029]
Jul 17 22:47:53.36: [ 5961]: <-- data [1031]
Jul 17 22:47:53.36: [ 5961]: <-- data [1031]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1027]
Jul 17 22:47:53.36: [ 5961]: <-- data [1026]
Jul 17 22:47:53.36: [ 5961]: <-- data [422]
Jul 17 22:47:53.36: [ 5961]: SENT 13734 bytes of data
Jul 17 22:47:53.36: [ 5961]: <-- data [1029]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1025]
Jul 17 22:47:53.36: [ 5961]: <-- data [1028]
Jul 17 22:47:53.36: [ 5961]: <-- data [1025]
Jul 17 22:47:53.37: [ 5961]: <-- data [1024]
Jul 17 22:47:53.37: [ 5961]: <-- data [1028]
Jul 17 22:47:53.37: [ 5961]: <-- data [1025]
Jul 17 22:47:53.37: [ 5961]: <-- data [1026]
Jul 17 22:47:53.37: [ 5961]: <-- data [1031]
Jul 17 22:47:53.37: [ 5961]: <-- data [1028]
Jul 17 22:47:53.37: [ 5961]: <-- data [1029]
Jul 17 22:47:53.37: [ 5961]: <-- data [438]
Jul 17 22:47:53.37: [ 5961]: SENT 13747 bytes of data
Jul 17 22:47:53.37: [ 5961]: <-- data [1024]
Jul 17 22:47:53.37: [ 5961]: <-- data [205]
Jul 17 22:47:53.37: [ 5961]: SENT 1229 bytes of data
Jul 17 22:47:53.37: [ 5961]: SEND 2D RTC
Jul 17 22:47:53.37: [ 5961]: <-- data [30]
Jul 17 22:47:53.37: [ 5961]: <-- data [2]
Jul 17 22:47:53.37: [ 5961]: SEND end page
Jul 17 22:48:29.07: [ 5961]: --> [2:OK]
Jul 17 22:48:29.07: [ 5961]: DELAY 95 ms
Jul 17 22:48:29.17: [ 5961]: SEND send EOP (no more pages or documents)
Jul 17 22:48:29.17: [ 5961]: <-- [9:AT+FTH=3\r]
Jul 17 22:48:29.20: [ 5961]: --> [7:CONNECT]
Jul 17 22:48:29.20: [ 5961]: <-- data [3]
Jul 17 22:48:29.20: [ 5961]: <-- data [2]
Jul 17 22:48:30.47: [ 5961]: --> [2:OK]
Jul 17 22:48:30.47: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:48:33.58: [ 5961]: --> [0:]
Jul 17 22:48:33.58: [ 5961]: MODEM <Empty line>
Jul 17 22:48:33.58: [ 5961]: <-- data [1]
Jul 17 22:48:33.58: [ 5961]: --> [2:OK]
Jul 17 22:48:33.58: [ 5961]: SEND send EOP (no more pages or documents)
Jul 17 22:48:33.58: [ 5961]: <-- [9:AT+FTH=3\r]
Jul 17 22:48:33.63: [ 5961]: --> [7:CONNECT]
Jul 17 22:48:33.63: [ 5961]: <-- data [3]
Jul 17 22:48:33.63: [ 5961]: <-- data [2]
Jul 17 22:48:34.90: [ 5961]: --> [2:OK]
Jul 17 22:48:34.90: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:48:38.01: [ 5961]: --> [0:]
Jul 17 22:48:38.01: [ 5961]: MODEM <Empty line>
Jul 17 22:48:38.01: [ 5961]: <-- data [1]
Jul 17 22:48:38.01: [ 5961]: --> [2:OK]
Jul 17 22:48:38.01: [ 5961]: SEND send EOP (no more pages or documents)
Jul 17 22:48:38.01: [ 5961]: <-- [9:AT+FTH=3\r]
Jul 17 22:48:38.06: [ 5961]: --> [7:CONNECT]
Jul 17 22:48:38.06: [ 5961]: <-- data [3]
Jul 17 22:48:38.06: [ 5961]: <-- data [2]
Jul 17 22:48:39.33: [ 5961]: --> [2:OK]
Jul 17 22:48:39.33: [ 5961]: <-- [9:AT+FRH=3\r]
Jul 17 22:48:42.43: [ 5961]: --> [0:]
Jul 17 22:48:42.43: [ 5961]: MODEM <Empty line>
Jul 17 22:48:42.43: [ 5961]: <-- data [1]
Jul 17 22:48:42.43: [ 5961]: --> [2:OK]
Jul 17 22:48:42.43: [ 5961]: No response to MPS or EOP repeated 3 tries
Jul 17 22:48:42.43: [ 5961]: <-- [9:AT+FTH=3\r]
Jul 17 22:48:42.48: [ 5961]: --> [7:CONNECT]
Jul 17 22:48:42.48: [ 5961]: <-- data [3]
Jul 17 22:48:42.48: [ 5961]: <-- data [2]
Jul 17 22:48:43.76: [ 5961]: --> [2:OK]
Jul 17 22:48:43.76: [ 5961]: <-- [5:ATH0\r]
Jul 17 22:48:44.86: [ 5961]: --> [2:OK]
Jul 17 22:48:44.86: [ 5961]: SESSION END




____________________ HylaFAX(tm) Users Mailing List _______________________
 To unsub: mail -s unsubscribe hylafax-users-request@hylafax.org < /dev/null