[hylafax-users] Communication errors

["Ian Newlands" <ian.newlands@vahosting.net.au>]

Hi

 

This is my first go at getting hylafax up and running.  I am attempting to run this in class1.  Each fax I send it scrambled and looking at the logs it seems to be constantly attempting to retrain.  The logs are below:

 

Jul 18 14:03:48.48: [ 5481]: SESSION BEGIN 00000010 <28912892782>
Jul 18 14:03:48.48: [ 5481]: HylaFAX (tm) Version 4.1.6
Jul 18 14:03:48.48: [ 5481]: SEND FAX: JOB 8 DEST 28912892782 COMMID 00000010 DEVICE '/dev/ttyS0'
Jul 18 14:03:48.48: [ 5481]: DELAY 75 ms
Jul 18 14:03:48.56: [ 5481]: DELAY 2600 ms
Jul 18 14:03:52.16: [ 5481]: DELAY 10 ms
Jul 18 14:03:52.17: [ 5481]: <-- [4:ATZ\r]
Jul 18 14:03:52.34: [ 5481]: --> [2:OK]
Jul 18 14:03:52.34: [ 5481]: DELAY 3000 ms
Jul 18 14:03:55.34: [ 5481]: <-- [5:ATE0\r]
Jul 18 14:03:55.44: [ 5481]: --> [4:ATE0]
Jul 18 14:03:55.44: [ 5481]: --> [2:OK]
Jul 18 14:03:55.44: [ 5481]: <-- [5:ATV1\r]
Jul 18 14:03:55.54: [ 5481]: --> [2:OK]
Jul 18 14:03:55.54: [ 5481]: <-- [5:ATQ0\r]
Jul 18 14:03:55.64: [ 5481]: --> [2:OK]
Jul 18 14:03:55.64: [ 5481]: <-- [7:ATS0=0\r]
Jul 18 14:03:55.75: [ 5481]: --> [2:OK]
Jul 18 14:03:55.75: [ 5481]: <-- [7:ATS8=2\r]
Jul 18 14:03:55.85: [ 5481]: --> [2:OK]
Jul 18 14:03:55.85: [ 5481]: <-- [8:ATS7=60\r]
Jul 18 14:03:55.96: [ 5481]: --> [2:OK]
Jul 18 14:03:55.96: [ 5481]: <-- [12:AT+FCLASS=1\r]
Jul 18 14:03:56.08: [ 5481]: --> [2:OK]
Jul 18 14:03:56.08: [ 5481]: <-- [7:ATL0M1\r]
Jul 18 14:03:56.18: [ 5481]: --> [2:OK]
Jul 18 14:03:56.19: [ 5481]: <-- [12:AT+FCLASS=1\r]
Jul 18 14:03:56.40: [ 5481]: --> [2:OK]
Jul 18 14:03:56.40: [ 5481]: DIAL 28912892782
Jul 18 14:03:56.40: [ 5481]: <-- [15:ATDT28912892782\r]
Jul 18 14:04:14.19: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:15.35: [ 5481]: --> [2:OK]
Jul 18 14:04:15.35: [ 5481]: REMOTE NSF "AD 00 36 A0 00 00 00 00 38"
Jul 18 14:04:15.35: [ 5481]: NSF remote fax equipment: HP
Jul 18 14:04:15.35: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:15.37: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:16.06: [ 5481]: --> [2:OK]
Jul 18 14:04:16.06: [ 5481]: REMOTE CSI "28912892782"
Jul 18 14:04:16.06: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:16.07: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:16.51: [ 5481]: --> [2:OK]
Jul 18 14:04:16.52: [ 5481]: REMOTE best rate 33600 bit/s
Jul 18 14:04:16.52: [ 5481]: REMOTE max page width 1728 pixels in 215 mm
Jul 18 14:04:16.52: [ 5481]: REMOTE max unlimited page length
Jul 18 14:04:16.52: [ 5481]: REMOTE best vres 7.7 line/mm
Jul 18 14:04:16.52: [ 5481]: REMOTE best format 2-D MMR
Jul 18 14:04:16.52: [ 5481]: REMOTE supports T.30 Annex A, ECM
Jul 18 14:04:16.52: [ 5481]: REMOTE best 0 ms/scanline
Jul 18 14:04:16.52: [ 5481]: USE 14400 bit/s
Jul 18 14:04:16.52: [ 5481]: USE 0 ms/scanline
Jul 18 14:04:16.52: [ 5481]: SEND file "docq/doc7.ps;00"
Jul 18 14:04:16.52: [ 5481]: USE page width 1728 pixels in 215 mm
Jul 18 14:04:16.52: [ 5481]: USE unlimited page length
Jul 18 14:04:16.52: [ 5481]: USE 3.85 line/mm
Jul 18 14:04:16.52: [ 5481]: USE 1-D MR
Jul 18 14:04:16.52: [ 5481]: SEND training at v.17 14400 bit/s
Jul 18 14:04:16.52: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:04:16.56: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:16.56: [ 5481]: <-- data [23]
Jul 18 14:04:16.56: [ 5481]: <-- data [2]
Jul 18 14:04:16.59: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:16.59: [ 5481]: <-- data [6]
Jul 18 14:04:16.59: [ 5481]: <-- data [2]
Jul 18 14:04:18.76: [ 5481]: --> [2:OK]
Jul 18 14:04:18.76: [ 5481]: DELAY 70 ms
Jul 18 14:04:18.83: [ 5481]: <-- [11:AT+FTM=145\r]
Jul 18 14:04:20.50: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:20.50: [ 5481]: <-- data [1024]
Jul 18 14:04:20.50: [ 5481]: <-- data [1024]
Jul 18 14:04:20.50: [ 5481]: <-- data [652]
Jul 18 14:04:20.50: [ 5481]: <-- data [2]
Jul 18 14:04:22.05: [ 5481]: --> [2:OK]
Jul 18 14:04:22.05: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:22.94: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:24.10: [ 5481]: --> [2:OK]
Jul 18 14:04:24.10: [ 5481]: SEND training at v.17 12000 bit/s
Jul 18 14:04:24.10: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:04:24.15: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:24.15: [ 5481]: <-- data [23]
Jul 18 14:04:24.15: [ 5481]: <-- data [2]
Jul 18 14:04:24.17: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:24.17: [ 5481]: <-- data [6]
Jul 18 14:04:24.17: [ 5481]: <-- data [2]
Jul 18 14:04:26.34: [ 5481]: --> [2:OK]
Jul 18 14:04:26.34: [ 5481]: DELAY 70 ms
Jul 18 14:04:26.41: [ 5481]: <-- [11:AT+FTM=121\r]
Jul 18 14:04:28.09: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:28.09: [ 5481]: <-- data [1024]
Jul 18 14:04:28.09: [ 5481]: <-- data [1024]
Jul 18 14:04:28.09: [ 5481]: <-- data [202]
Jul 18 14:04:28.09: [ 5481]: <-- data [2]
Jul 18 14:04:29.63: [ 5481]: --> [2:OK]
Jul 18 14:04:29.63: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:30.53: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:31.68: [ 5481]: --> [2:OK]
Jul 18 14:04:31.68: [ 5481]: SEND training at v.17 9600 bit/s
Jul 18 14:04:31.68: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:04:31.73: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:31.73: [ 5481]: <-- data [23]
Jul 18 14:04:31.73: [ 5481]: <-- data [2]
Jul 18 14:04:31.75: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:31.75: [ 5481]: <-- data [6]
Jul 18 14:04:31.75: [ 5481]: <-- data [2]
Jul 18 14:04:33.93: [ 5481]: --> [2:OK]
Jul 18 14:04:33.93: [ 5481]: DELAY 70 ms
Jul 18 14:04:34.00: [ 5481]: <-- [10:AT+FTM=97\r]
Jul 18 14:04:35.67: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:35.67: [ 5481]: <-- data [1024]
Jul 18 14:04:35.67: [ 5481]: <-- data [776]
Jul 18 14:04:35.67: [ 5481]: <-- data [2]
Jul 18 14:04:37.22: [ 5481]: --> [2:OK]
Jul 18 14:04:37.22: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:38.11: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:39.27: [ 5481]: --> [2:OK]
Jul 18 14:04:39.27: [ 5481]: SEND training at v.17 7200 bit/s
Jul 18 14:04:39.27: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:04:39.32: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:39.32: [ 5481]: <-- data [23]
Jul 18 14:04:39.32: [ 5481]: <-- data [2]
Jul 18 14:04:39.34: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:39.34: [ 5481]: <-- data [6]
Jul 18 14:04:39.34: [ 5481]: <-- data [2]
Jul 18 14:04:41.51: [ 5481]: --> [2:OK]
Jul 18 14:04:41.51: [ 5481]: DELAY 70 ms
Jul 18 14:04:41.58: [ 5481]: <-- [10:AT+FTM=73\r]
Jul 18 14:04:43.26: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:43.26: [ 5481]: <-- data [1024]
Jul 18 14:04:43.26: [ 5481]: <-- data [326]
Jul 18 14:04:43.26: [ 5481]: <-- data [2]
Jul 18 14:04:44.81: [ 5481]: --> [2:OK]
Jul 18 14:04:44.81: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:45.70: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:46.85: [ 5481]: --> [2:OK]
Jul 18 14:04:46.85: [ 5481]: SEND training at v.27ter 4800 bit/s
Jul 18 14:04:46.85: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:04:46.90: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:46.90: [ 5481]: <-- data [23]
Jul 18 14:04:46.90: [ 5481]: <-- data [2]
Jul 18 14:04:46.92: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:46.92: [ 5481]: <-- data [6]
Jul 18 14:04:46.92: [ 5481]: <-- data [2]
Jul 18 14:04:49.10: [ 5481]: --> [2:OK]
Jul 18 14:04:49.10: [ 5481]: DELAY 70 ms
Jul 18 14:04:49.17: [ 5481]: <-- [10:AT+FTM=48\r]
Jul 18 14:04:50.15: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:50.15: [ 5481]: <-- data [900]
Jul 18 14:04:50.15: [ 5481]: <-- data [2]
Jul 18 14:04:51.70: [ 5481]: --> [2:OK]
Jul 18 14:04:51.70: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:04:51.96: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:53.12: [ 5481]: --> [2:OK]
Jul 18 14:04:53.12: [ 5481]: TRAINING succeeded
Jul 18 14:04:53.12: [ 5481]: DELAY 75 ms
Jul 18 14:04:53.19: [ 5481]: <-- [10:AT+FTM=48\r]
Jul 18 14:04:54.25: [ 5481]: --> [7:CONNECT]
Jul 18 14:04:54.25: [ 5481]: SEND begin page
Jul 18 14:04:54.25: [ 5481]: <-- data [1029]
Jul 18 14:04:54.25: [ 5481]: <-- data [1025]
Jul 18 14:04:54.25: [ 5481]: <-- data [1027]
Jul 18 14:04:54.25: [ 5481]: <-- data [1034]
Jul 18 14:04:56.25: [ 5481]: <-- data [1028]
Jul 18 14:04:56.25: [ 5481]: <-- data [1027]
Jul 18 14:04:56.25: [ 5481]: <-- data [1031]
Jul 18 14:04:56.25: [ 5481]: <-- data [1025]
Jul 18 14:04:58.25: [ 5481]: <-- data [1029]
Jul 18 14:04:58.25: [ 5481]: <-- data [1027]
Jul 18 14:04:58.25: [ 5481]: <-- data [1029]
Jul 18 14:04:58.25: [ 5481]: <-- data [1026]
Jul 18 14:05:00.24: [ 5481]: <-- data [1032]
Jul 18 14:05:00.24: [ 5481]: <-- data [1030]
Jul 18 14:05:00.24: [ 5481]: <-- data [1033]
Jul 18 14:05:00.24: [ 5481]: <-- data [1034]
Jul 18 14:05:02.24: [ 5481]: <-- data [1032]
Jul 18 14:05:02.24: [ 5481]: <-- data [1030]
Jul 18 14:05:02.24: [ 5481]: <-- data [1034]
Jul 18 14:05:04.24: [ 5481]: <-- data [1029]
Jul 18 14:05:04.24: [ 5481]: <-- data [1028]
Jul 18 14:05:04.24: [ 5481]: <-- data [1028]
Jul 18 14:05:04.24: [ 5481]: <-- data [1038]
Jul 18 14:05:06.23: [ 5481]: <-- data [1031]
Jul 18 14:05:06.23: [ 5481]: <-- data [1028]
Jul 18 14:05:06.23: [ 5481]: <-- data [1033]
Jul 18 14:05:06.23: [ 5481]: <-- data [1029]
Jul 18 14:05:08.23: [ 5481]: <-- data [998]
Jul 18 14:05:08.23: [ 5481]: SENT 28640 bytes of data
Jul 18 14:05:08.23: [ 5481]: SEND 1D RTC
Jul 18 14:05:08.23: [ 5481]: <-- data [29]
Jul 18 14:05:08.23: [ 5481]: <-- data [2]
Jul 18 14:05:08.23: [ 5481]: SEND end page
Jul 18 14:05:42.32: [ 5481]: --> [2:OK]
Jul 18 14:05:42.32: [ 5481]: DELAY 70 ms
Jul 18 14:05:42.39: [ 5481]: SEND send MPS (more pages, same document)
Jul 18 14:05:42.39: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:05:42.44: [ 5481]: --> [7:CONNECT]
Jul 18 14:05:42.44: [ 5481]: <-- data [3]
Jul 18 14:05:42.44: [ 5481]: <-- data [2]
Jul 18 14:05:43.75: [ 5481]: --> [2:OK]
Jul 18 14:05:43.75: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:05:46.85: [ 5481]: --> [0:]
Jul 18 14:05:46.85: [ 5481]: MODEM <Empty line>
Jul 18 14:05:46.85: [ 5481]: <-- data [1]
Jul 18 14:05:47.05: [ 5481]: MODEM <Timeout>
Jul 18 14:05:47.05: [ 5481]: SEND send MPS (more pages, same document)
Jul 18 14:05:47.05: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:05:47.10: [ 5481]: --> [7:CONNECT]
Jul 18 14:05:47.10: [ 5481]: <-- data [3]
Jul 18 14:05:47.10: [ 5481]: <-- data [2]
Jul 18 14:05:48.41: [ 5481]: --> [2:OK]
Jul 18 14:05:48.41: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:05:51.52: [ 5481]: --> [0:]
Jul 18 14:05:51.52: [ 5481]: MODEM <Empty line>
Jul 18 14:05:51.52: [ 5481]: <-- data [1]
Jul 18 14:05:51.72: [ 5481]: MODEM <Timeout>
Jul 18 14:05:51.72: [ 5481]: SEND send MPS (more pages, same document)
Jul 18 14:05:51.72: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:05:51.76: [ 5481]: --> [7:CONNECT]
Jul 18 14:05:51.76: [ 5481]: <-- data [3]
Jul 18 14:05:51.77: [ 5481]: <-- data [2]
Jul 18 14:05:53.08: [ 5481]: --> [2:OK]
Jul 18 14:05:53.08: [ 5481]: <-- [9:AT+FRH=3\r]
Jul 18 14:05:56.18: [ 5481]: --> [0:]
Jul 18 14:05:56.18: [ 5481]: MODEM <Empty line>
Jul 18 14:05:56.18: [ 5481]: <-- data [1]
Jul 18 14:05:56.38: [ 5481]: MODEM <Timeout>
Jul 18 14:05:56.38: [ 5481]: No response to MPS or EOP repeated 3 tries
Jul 18 14:05:56.38: [ 5481]: <-- [9:AT+FTH=3\r]
Jul 18 14:05:56.43: [ 5481]: --> [7:CONNECT]
Jul 18 14:05:56.43: [ 5481]: <-- data [3]
Jul 18 14:05:56.43: [ 5481]: <-- data [2]
Jul 18 14:05:57.74: [ 5481]: --> [2:OK]
Jul 18 14:05:57.74: [ 5481]: <-- [5:ATH0\r]
Jul 18 14:05:58.17: [ 5481]: --> [10:NO CARRIER]
Jul 18 14:05:58.17: [ 5481]: MODEM No carrier
Jul 18 14:05:58.17: [ 5481]: SESSION END

Can anyone offer me any advise or hints as to how I can get this going?

 

Regards,

 

Ian Newlands

 

BEGIN:VCARD
VERSION:2.1
N:Newlands;Ian
FN:Ian Newlands
ORG:Value Added Hosting;IT
TITLE:Managing Director
TEL;WORK;VOICE:+61 8 9328 5858
TEL;WORK;FAX:+61 8 9328 5859
ADR;WORK;ENCODING=QUOTED-PRINTABLE:;;PoBox 56=0D=0A;Karrinyup;WA;6921;Australia
LABEL;WORK;ENCODING=QUOTED-PRINTABLE:PoBox 56=0D=0A=0D=0AKarrinyup, WA 6921=0D=0AAustralia
URL;WORK:http://www.vahosting.net.au
EMAIL;PREF;INTERNET:ian.newlands@vahosting.net.au
REV:20030718T061953Z
END:VCARD