flexfax: blank faxes - conversion problem?

["Cheryl L. Huntington" <clh@mellis.com>]

Help please! I have been diligently trying to 
get HylaFax 4.0p10 running on a i386 BSD/OS 3.0
system for years! (OK, so only a few weeks that 
seem like years.) After working through the 
infamous "Waiting for modem to come ready" problem,
I now have another one.

I have faxq, hfaxd, and faxgetty running. When
I send a fax, it dials, connects, sends the fax,
and says it's OK. But the fax is a blank page on 
the fax machine and the fax machine shows an error
occurred.  This is for a one page fax sent with the command
sendfax -n -d tty01 /etc/hosts

If I include the cover page, then the job fails with this
error:

Sep 23 15:33:30 delta FaxQueuer[9411]: JOB 33 (active dest +14087336054 pri 127
tts 0:00 killtime 2:57:52): CMD DONE: exit status 0
Sep 23 15:33:30 delta FaxQueuer[9411]: JOB 33 (sleeping dest +14087336054 pri 12
6 tts 0:00 killtime 2:57:52): SEND INCOMPLETE: requeue for 4:59; Unspecified Tra
nsmit Phase D error, including +FPHCTO timeout between data and +FET command
Sep 23 15:33:30 delta FaxQueuer[9411]: JOB 33 (sleeping dest +14087336054 pri 12
6 tts 0:00 killtime 2:57:52): SLEEP FOR 4:59

Various logs are below.

My guess is that the problem is with the ps2fax conversion. The ps file prints
OK on an HP printer (albeit not aligned well). If I run ps2fax manually
then try to send the tiff/f format file with faxsend, I get the following
errors:

Sep 23 14:24:08 delta FaxSend[10044]: MODEM ZYXEL U1496E/V 5.02 M
Sep 23 14:24:08 delta FaxSend[10044]: ps.fax: line 1: Syntax error, missing ':' on line 1
Sep 23 14:24:08 delta FaxSend[10044]: ps.fax: line 2: Syntax error, missing ':' on line 2
Sep 23 14:24:08 delta FaxSend[10044]: ps.fax: line 3: Syntax error, missing ':' on line 3
Sep 23 14:24:08 delta FaxSend[10044]: ps.fax: line 4: Syntax error, missing ':' on line 4
Sep 23 14:24:08 delta FaxSend[10044]: ps.fax: line 5: Syntax error, missing ':' on line 5
[etc. for 61 lines]

The ps2fax uses Ghostscript version 2.6.2 (4/19/95) and I've set
"Use2D: no" in the faxq config file.

Has anyone seen this problem?  I know there are patches, but I don't want
to go through rebuilding this (especially since I didn't build it in the
first place) unless I have a good idea that it would fix the problem.



The faxq log shows (one page fax):

Sep 23 15:15:36 delta HylaFAX[10179]: Filesystem has BSD-style file creation semantics.
Sep 23 15:15:36 delta FaxQueuer[9411]: SUBMIT JOB 32
Sep 23 15:15:36 delta FaxQueuer[9411]: JOB 32 (suspended dest  pri 127 tts 0:00 killtime 2:59:00): CREATE
Sep 23 15:15:36 delta FaxQueuer[9411]: JOB 32 (ready dest +14087336054 pri 127 tts 0:00 killtime 2:59:00): READY
Sep 23 15:15:36 delta FaxQueuer[9411]: JOB 32 (ready dest +14087336054 pri 127 tts 0:00 killtime 2:59:00): PROCESS
Sep 23 15:15:37 delta FaxQueuer[9411]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:59): ACTIVE
Sep 23 15:15:37 delta FaxQueuer[9411]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:59): PREPARE START
Sep 23 15:15:37 delta FaxQueuer[10182]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:59): CONVERT DOCUMENT: bin/ps2fax -o docq/doc45.ps;30 -r98 -w 1728 -l 280 -m 4294967295 -1 docq/doc45.ps.32
Sep 23 15:15:37 delta FaxQueuer[9411]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:59): PREPARE DONE
Sep 23 15:15:37 delta FaxQueuer[9411]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:59): CMD START /usr/contrib/lib/hylafax/faxsend -m tty01 sendq/q32 (PID 10196)
Sep 23 15:15:42 delta FaxSend[10196]: MODEM ZYXEL U1496E/V 5.02 M
Sep 23 15:15:42 delta FaxSend[10196]: SEND FAX: JOB 32 DEST 7336054 COMMID 00000054
Sep 23 15:16:23 delta FaxQueuer[9411]: JOB 32 (active dest +14087336054 pri 127 tts 0:00 killtime 2:58:13): CMD DONE: exit status 0x200
Sep 23 15:16:23 delta FaxQueuer[9411]: JOB 32 (done dest +14087336054 pri 127 tts 0:00 killtime 2:58:13): SEND DONE: 0:46
Sep 23 15:16:23 delta FaxQueuer[9411]: JOB 32 (done dest +14087336054 pri 127 tts 0:00 killtime 2:58:13): DEAD
Sep 23 15:16:23 delta FaxQueuer[9411]: JOB 32 (done dest +14087336054 pri 127 tts 0:00 killtime 2:58:13): DELETE

The faxq log for a two page fax is basically the same except it has
a line for converting the cover page, then fails with the error
I show above.

The log file C00000054 shows this (one page fax):

Sep 23 15:15:42.36: [10196]: SESSION BEGIN 00000054 14087336054
Sep 23 15:15:42.36: [10196]: SEND FAX: JOB 32 DEST 7336054 COMMID 00000054
Sep 23 15:15:42.36: [10196]: MODEM set DTR OFF
Sep 23 15:15:42.36: [10196]: DELAY 2600 ms
Sep 23 15:15:44.95: [10196]: MODEM set DTR ON
Sep 23 15:15:44.95: [10196]: MODEM set baud rate: 38400 baud, input flow RTS/CTS
, output flow RTS/CTS
Sep 23 15:15:44.95: [10196]: MODEM flush i/o
Sep 23 15:15:44.95: [10196]: <-- [44:AT&B1&N0&S0*F0S18=2S38.3=1S39=0E0V1Q0S0=0H0
\r]
Sep 23 15:15:45.16: [10196]: --> [2:OK]
Sep 23 15:15:45.16: [10196]: <-- [21:ATS8=2S7=60&H3&D2&C1\r]
Sep 23 15:15:45.17: [10196]: --> [2:OK]
Sep 23 15:15:45.17: [10196]: <-- [12:AT+FCLASS=2\r]
Sep 23 15:15:45.18: [10196]: --> [2:OK]
Sep 23 15:15:45.18: [10196]: <-- [10:AT+FTBC=0\r]
Sep 23 15:15:45.19: [10196]: --> [2:OK]
Sep 23 15:15:45.19: [10196]: <-- [10:AT+FBOR=0\r]
Sep 23 15:15:45.20: [10196]: --> [2:OK]
Sep 23 15:15:45.20: [10196]: <-- [13:AT+FPHCTO=30\r]
Sep 23 15:15:45.21: [10196]: --> [2:OK]
Sep 23 15:15:45.21: [10196]: <-- [10:AT+FBUG=1\r]
Sep 23 15:15:45.21: [10196]: --> [2:OK]
Sep 23 15:15:45.22: [10196]: <-- [24:AT+FDCC=1,5,2,2,1,0,0,0\r]
Sep 23 15:15:45.23: [10196]: --> [2:OK]
Sep 23 15:15:45.23: [10196]: <-- [5:ATM0\r]
Sep 23 15:15:45.23: [10196]: --> [2:OK]
Sep 23 15:15:45.23: [10196]: MODEM input buffering enabled
Sep 23 15:15:45.25: [10196]: <-- [12:AT+FCLASS=2\r]
Sep 23 15:15:45.36: [10196]: --> [2:OK]
Sep 23 15:15:45.36: [10196]: <-- [10:AT+FTBC=0\r]
Sep 23 15:15:45.46: [10196]: --> [2:OK]
Sep 23 15:15:45.46: [10196]: <-- [10:AT+FBOR=0\r]
Sep 23 15:15:45.56: [10196]: --> [2:OK]
Sep 23 15:15:45.56: [10196]: <-- [13:AT+FPHCTO=30\r]
Sep 23 15:15:45.66: [10196]: --> [2:OK]
Sep 23 15:15:45.66: [10196]: <-- [10:AT+FBUG=1\r]
Sep 23 15:15:45.76: [10196]: --> [2:OK]
Sep 23 15:15:45.76: [10196]: <-- [24:AT+FDCC=1,5,2,2,1,0,0,0\r]
Sep 23 15:15:45.87: [10196]: --> [2:OK]
Sep 23 15:15:45.87: [10196]: <-- [30:AT+FLID="Mellis & Associates"\r]
Sep 23 15:15:45.97: [10196]: --> [2:OK]
Sep 23 15:15:45.98: [10196]: DIAL 7336054
Sep 23 15:15:45.98: [10196]: <-- [12:ATDT7336054\r]
Sep 23 15:16:07.22: [10196]: --> [5:+FCON]
Sep 23 15:16:07.22: [10196]: --> [18:+FNSF:00 00 00 00 ]
Sep 23 15:16:07.22: [10196]: REMOTE NSF "00 00 00 00"
Sep 23 15:16:07.22: [10196]: --> [27:+FCSI:        408 733 6054 ]
Sep 23 15:16:07.22: [10196]: REMOTE CSI "408 733 6054"
Sep 23 15:16:07.22: [10196]: --> [21:+FDIS:1,3,0,2,1,0,0,4]
Sep 23 15:16:07.22: [10196]: --> [2:OK]
Sep 23 15:16:07.23: [10196]: REMOTE best rate 9600 bit/s
Sep 23 15:16:07.23: [10196]: REMOTE max page width 1728 pixels in 215 mm
Sep 23 15:16:07.23: [10196]: REMOTE max unlimited page length
Sep 23 15:16:07.23: [10196]: REMOTE best vres 7.7 line/mm
Sep 23 15:16:07.23: [10196]: REMOTE best format 2-D MR
Sep 23 15:16:07.23: [10196]: REMOTE best 20 ms, 10 ms/scanline
Sep 23 15:16:07.23: [10196]: USE 9600 bit/s
Sep 23 15:16:07.23: [10196]: USE 20 ms, 10 ms/scanline
Sep 23 15:16:07.23: [10196]: SEND file "docq/doc45.ps;30"
Sep 23 15:16:07.23: [10196]: USE page width 1728 pixels in 215 mm
Sep 23 15:16:07.23: [10196]: USE unlimited page length
Sep 23 15:16:07.23: [10196]: USE 3.85 line/mm
Sep 23 15:16:07.23: [10196]: USE 1-D MR
Sep 23 15:16:07.23: [10196]: <-- [24:AT+FDIS=0,3,0,2,0,0,0,4\r]
Sep 23 15:16:07.33: [10196]: --> [2:OK]
Sep 23 15:16:07.33: [10196]: <-- [7:AT+FDT\r]
Sep 23 15:16:07.47: [10196]: --> [18:+FNSF:00 00 00 00 ]
Sep 23 15:16:07.47: [10196]: --> [27:+FCSI:        408 733 6054 ]
Sep 23 15:16:07.47: [10196]: --> [21:+FDIS:1,3,0,2,1,0,0,4]
Sep 23 15:16:13.62: [10196]: --> [21:+FDCS:1,3,0,2,0,0,0,4]
Sep 23 15:16:13.62: [10196]: --> [7:CONNECT]
Sep 23 15:16:13.62: [10196]: SEND wait for XON
Sep 23 15:16:13.62: [10196]: --> [1:^Q]
Sep 23 15:16:13.62: [10196]: SEND begin page
Sep 23 15:16:13.62: [10196]: <-- data [1027]
Sep 23 15:16:13.63: [10196]: <-- data [1027]
Sep 23 15:16:13.63: [10196]: <-- data [1030]
Sep 23 15:16:13.63: [10196]: <-- data [692]
Sep 23 15:16:13.63: [10196]: SENT 3762 bytes of data
Sep 23 15:16:13.63: [10196]: <-- data [2]
Sep 23 15:16:13.63: [10196]: SEND end page
Sep 23 15:16:18.74: [10196]: --> [2:OK]
Sep 23 15:16:18.74: [10196]: SEND send EOP (no more pages or documents)
Sep 23 15:16:18.74: [10196]: <-- [9:AT+FET=2\r]
Sep 23 15:16:22.01: [10196]: --> [13:+FPTS:1,2,0,0]
Sep 23 15:16:22.01: [10196]: SEND recv MCF (message confirmation)
Sep 23 15:16:22.01: [10196]: SEND FAX (00000054): FROM root@delta.mellis.com TO
7336054 (page 1 of 1 sent in 0:15)
Sep 23 15:16:22.01: [10196]: SEND FAX (00000054): FROM root@delta.mellis.com TO
7336054 (docq/doc45.ps;30 sent in 0:15)
Sep 23 15:16:22.07: [10196]: <-- [5:ATH0\r]
Sep 23 15:16:23.41: [10196]: --> [8:+FHNG:00]
Sep 23 15:16:23.41: [10196]: REMOTE HANGUP: Normal and proper end of connection
(code 0)
Sep 23 15:16:23.41: [10196]: --> [2:OK]
Sep 23 15:16:23.41: [10196]: MODEM set DTR OFF
Sep 23 15:16:23.42: [10196]: SESSION END



The comm log file for a two page fax:

Sep 23 12:11:30.34: [ 9726]: SESSION BEGIN 00000047 14087336054
Sep 23 12:11:30.34: [ 9726]: SEND FAX: JOB 24 DEST 7336054 COMMID 00000047
Sep 23 12:11:30.34: [ 9726]: MODEM set DTR OFF
Sep 23 12:11:30.34: [ 9726]: DELAY 2600 ms
Sep 23 12:11:32.93: [ 9726]: MODEM set DTR ON
Sep 23 12:11:32.94: [ 9726]: MODEM set baud rate: 38400 baud, input flow RTS/CTS
, output flow RTS/CTS
Sep 23 12:11:32.94: [ 9726]: MODEM flush i/o
Sep 23 12:11:32.94: [ 9726]: <-- [44:AT&B1&N0&S0*F0S18=2S38.3=1S39=0E0V1Q0S0=0H0
\r]
Sep 23 12:11:33.15: [ 9726]: --> [2:OK]
Sep 23 12:11:33.15: [ 9726]: <-- [21:ATS8=2S7=60&H3&D2&C1\r]
Sep 23 12:11:33.16: [ 9726]: --> [2:OK]
Sep 23 12:11:33.16: [ 9726]: <-- [12:AT+FCLASS=2\r]
Sep 23 12:11:33.17: [ 9726]: --> [2:OK]
Sep 23 12:11:33.17: [ 9726]: <-- [10:AT+FTBC=0\r]
Sep 23 12:11:33.18: [ 9726]: --> [2:OK]
Sep 23 12:11:33.18: [ 9726]: <-- [10:AT+FBOR=0\r]
Sep 23 12:11:33.18: [ 9726]: --> [2:OK]
Sep 23 12:11:33.18: [ 9726]: <-- [13:AT+FPHCTO=30\r]
Sep 23 12:11:33.19: [ 9726]: --> [2:OK]
Sep 23 12:11:33.19: [ 9726]: <-- [24:AT+FDCC=1,5,2,2,1,0,0,0\r]
Sep 23 12:11:33.21: [ 9726]: --> [2:OK]
Sep 23 12:11:33.21: [ 9726]: <-- [5:ATM0\r]
Sep 23 12:11:33.21: [ 9726]: --> [2:OK]
Sep 23 12:11:33.21: [ 9726]: MODEM input buffering enabled
Sep 23 12:11:33.22: [ 9726]: <-- [12:AT+FCLASS=2\r]
Sep 23 12:11:33.32: [ 9726]: --> [2:OK]
Sep 23 12:11:33.32: [ 9726]: <-- [10:AT+FTBC=0\r]
Sep 23 12:11:33.42: [ 9726]: --> [2:OK]
Sep 23 12:11:33.42: [ 9726]: <-- [10:AT+FBOR=0\r]
Sep 23 12:11:33.52: [ 9726]: --> [2:OK]
Sep 23 12:11:33.52: [ 9726]: <-- [13:AT+FPHCTO=30\r]
Sep 23 12:11:33.62: [ 9726]: --> [2:OK]
Sep 23 12:11:33.62: [ 9726]: <-- [24:AT+FDCC=1,5,2,2,1,0,0,0\r]
Sep 23 12:11:33.73: [ 9726]: --> [2:OK]
Sep 23 12:11:33.73: [ 9726]: <-- [30:AT+FLID="Mellis & Associates"\r]
Sep 23 12:11:33.84: [ 9726]: --> [2:OK]
Sep 23 12:11:33.85: [ 9726]: DIAL 7336054
Sep 23 12:11:33.85: [ 9726]: <-- [12:ATDT7336054\r]
Sep 23 12:11:55.28: [ 9726]: --> [5:+FCON]
Sep 23 12:11:55.28: [ 9726]: --> [18:+FNSF:00 00 00 00 ]
Sep 23 12:11:55.28: [ 9726]: REMOTE NSF "00 00 00 00"
Sep 23 12:11:55.28: [ 9726]: --> [27:+FCSI:        408 733 6054 ]
Sep 23 12:11:55.28: [ 9726]: REMOTE CSI "408 733 6054"
Sep 23 12:11:55.28: [ 9726]: --> [21:+FDIS:1,3,0,2,1,0,0,4]
Sep 23 12:11:55.28: [ 9726]: --> [2:OK]
Sep 23 12:11:55.28: [ 9726]: REMOTE best rate 9600 bit/s
Sep 23 12:11:55.28: [ 9726]: REMOTE max page width 1728 pixels in 215 mm
Sep 23 12:11:55.28: [ 9726]: REMOTE max unlimited page length
Sep 23 12:11:55.28: [ 9726]: REMOTE best vres 7.7 line/mm
Sep 23 12:11:55.28: [ 9726]: REMOTE best format 2-D MR
Sep 23 12:11:55.28: [ 9726]: REMOTE best 20 ms, 10 ms/scanline
Sep 23 12:11:55.28: [ 9726]: USE 9600 bit/s
Sep 23 12:11:55.28: [ 9726]: USE 20 ms, 10 ms/scanline
Sep 23 12:11:55.28: [ 9726]: SEND file "docq/doc24.cover;70"
Sep 23 12:11:55.29: [ 9726]: USE page width 1728 pixels in 215 mm
Sep 23 12:11:55.29: [ 9726]: USE unlimited page length
Sep 23 12:11:55.29: [ 9726]: USE 3.85 line/mm
Sep 23 12:11:55.29: [ 9726]: USE 1-D MR
Sep 23 12:11:55.29: [ 9726]: <-- [24:AT+FDIS=0,3,0,2,0,0,0,4\r]
Sep 23 12:11:55.39: [ 9726]: --> [2:OK]
Sep 23 12:11:55.39: [ 9726]: <-- [7:AT+FDT\r]
Sep 23 12:11:55.53: [ 9726]: --> [18:+FNSF:00 00 00 00 ]
Sep 23 12:11:55.53: [ 9726]: --> [27:+FCSI:        408 733 6054 ]
Sep 23 12:11:55.53: [ 9726]: --> [21:+FDIS:1,3,0,2,1,0,0,4]
Sep 23 12:12:01.68: [ 9726]: --> [21:+FDCS:1,3,0,2,0,0,0,4]
Sep 23 12:12:01.68: [ 9726]: --> [7:CONNECT]
Sep 23 12:12:01.68: [ 9726]: SEND wait for XON
Sep 23 12:12:01.68: [ 9726]: --> [1:^Q]
Sep 23 12:12:01.68: [ 9726]: SEND begin page
Sep 23 12:12:01.69: [ 9726]: <-- data [1029]
Sep 23 12:12:01.69: [ 9726]: <-- data [1037]
Sep 23 12:12:01.69: [ 9726]: <-- data [1029]
Sep 23 12:12:01.69: [ 9726]: <-- data [1034]
Sep 23 12:12:02.69: [ 9726]: <-- data [1032]
Sep 23 12:12:02.69: [ 9726]: <-- data [1034]
Sep 23 12:12:02.69: [ 9726]: <-- data [1031]
Sep 23 12:12:02.69: [ 9726]: <-- data [1029]
Sep 23 12:12:05.88: [ 9726]: <-- data [1040]
Sep 23 12:12:05.88: [ 9726]: <-- data [1043]
Sep 23 12:12:05.88: [ 9726]: <-- data [1036]
Sep 23 12:12:05.88: [ 9726]: <-- data [1027]
Sep 23 12:12:09.07: [ 9726]: <-- data [830]
Sep 23 12:12:09.07: [ 9726]: SENT 13118 bytes of data
Sep 23 12:12:09.07: [ 9726]: <-- data [2]
Sep 23 12:12:09.07: [ 9726]: SEND end page
Sep 23 12:12:14.99: [ 9726]: --> [10:^S^Q^S^Q^S^Q^S^Q^S^Q]
Sep 23 12:12:14.99: [ 9726]: --> [2:OK]
Sep 23 12:12:14.99: [ 9726]: SEND send MPS (more pages, same document)
Sep 23 12:12:14.99: [ 9726]: <-- [9:AT+FET=0\r]
Sep 23 12:12:24.43: [ 9726]: --> [21:+FDCS:1,3,0,2,0,0,0,4]
Sep 23 12:12:24.43: [ 9726]: --> [7:CONNECT]
Sep 23 12:12:30.81: [ 9726]: --> [1:^Q]
Sep 23 12:12:30.81: [ 9726]: --> [10:NO CARRIER]
Sep 23 12:12:30.81: [ 9726]: REMOTE HANGUP: Unspecified Transmit Phase D error,
including +FPHCTO timeout between data and +FET command (code 50)
Sep 23 12:12:30.81: [ 9726]: <-- [6:AT+FK\r]
Sep 23 12:12:30.91: [ 9726]: --> [2:OK]
Sep 23 12:12:30.91: [ 9726]: <-- [5:ATH0\r]
Sep 23 12:12:31.21: [ 9726]: --> [2:OK]
Sep 23 12:12:31.21: [ 9726]: MODEM set DTR OFF
Sep 23 12:12:31.22: [ 9726]: SESSION END


Thank you thank you thank you for any and all help.

Cheryl Huntington


--
Cheryl Huntington	 Mellis & Associates		clh@mellis.com
		    655 Town and Country Village
			Sunnyvale, CA 94086
		Office: 408-733-6054	Pager: 800-789-7695