flexfax: cu/minicom works but not faxgetty (hylafax-4.1beta2; RedHat 6.0)

[John Interrante <interran@crd.ge.com>]

HylaFAX 4.1beta2 on RedHat 6.0 with g++ --version: egcs-2.91.66

My RedHat 6.0 system (HP Kayak XAs - 400MHz Pentium II) has all the
latest errata RPMs applied.

I am using an U.S. Robotics Sportster 56K/x2/v.90 external modem
attached to /dev/ttyS0 (the port labelled serial A on the back).  I
have updated the firmware to the latest version available on the 3Com
website and I have set DIP switches 3, 5, and 8 DOWN (ON) which
enables result codes, disables auto answer, and enables AT command set
recognition.  I can successfully communicate with the modem using cu
or minicom; here is a transcript of a cu session.

$ sudo cu -l /dev/ttyS0
Connected.
ati3
U.S. Robotics 56K FAX V4.6.6

OK
ati7
Configuration Profile...
 
Product type           US/Canada External
Product ID:            00178600
Options                V32bis,V.34+,x2,V.90
Fax Options            Class 1/Class 2.0
Line Options           Caller ID, Distinctive Ring
Clock Freq             92.0Mhz
Eprom                  256k
Ram                    32k
 
EPROM date             5/26/98
DSP date               5/26/98
 
EPROM rev              4.6.6
DSP rev                4.6.6
 
OK
~.
Disconnected.
$

I know Sportsters aren't great fax modems, but the problem I'm
encountering happens even before faxgetty has a chance to read
anything from the modem.  I've used the modem successfully with a
commercial fax package, and this very same problem happens as well
when I try to set up HylaFAX on another RedHat Linux 6.0 computer with
a completely different modem from another manufacturer.

I fetched

ftp://ftp.hylafax.org/pub/hylafax/hylafax-4.1/source/hylafax-4.1beta2.tar.gz

unpacked the tar file;

ran ./configure and accepted all the default values;

built and installed with make all; su; make install;

ran /usr/local/sbin/faxsetup (as root) and accepted all the default
values (I did enter my area code though);

let faxsetup start up the servers and run faxaddmodem for me;

told faxaddmodem to look for an external modem attached to ttyS0;

accepted all the default values offered by faxaddmodem except for the
area code, the fax line's phone number, server tracing (which I
changed from 1 to 0xffffffff so that I could include debugging
information which might or might not help narrow down the problem),
and ClocalAsRoot (which I set to yes to rule out whether it might help
or not - it didn't help whether it was "" or yes);

let faxaddmodem, which recognized the U.S. Robotics Sportster 56K
modem, use the usr-2.0 defaults to set up /var/spool/etc/config.ttyS0;

told faxsetup there wasn't any more modems to set up;

and let faxsetup run faxmodem ttyS0.

Watch closely, this is where the problem happens.  I cannot get
faxgetty to run, either from /etc/inittab or by hand.  When I try to
run it by hand as root,

/usr/local/sbin/faxgetty ttyS0

faxgetty opens the serial port, sends an initial AT command string,
and tries to read a response but fails to read anything and times out.
This happens even though /dev/ttyS0 would appear to have the proper
permissions,

crw-------   1 uucp     uucp       4,  64 Sep  9 15:29 /dev/ttyS0

and cu, minicom, and a commercial fax package all can open the serial
port and talk to the modem just fine.  Even faxaddmodem was able to
interrogate the modem.  So why is faxgetty hanging and giving me so
much trouble?

Here are the server tracing messages that were sent to syslog:

Sep  9 15:05:14 winterran1crdge FaxQueuer[15976]: HylaFAX (tm) Version 4.1beta2
Sep  9 15:05:14 winterran1crdge FaxQueuer[15976]: Copyright (c) 1990-1996 Sam Leffler
Sep  9 15:05:14 winterran1crdge FaxQueuer[15976]: Copyright (c) 1991-1996 Silicon Graphics, Inc.
Sep  9 15:05:14 winterran1crdge HylaFAX[15977]: /etc/netconfig: Cannot open: No such file or directory
Sep  9 15:05:14 winterran1crdge HylaFAX[15978]: HylaFAX INET Protocol Server: restarted.
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: servertracing = 0xffffffff (line 42)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: sessiontracing = 0xffffffff (line 43)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: recvfilemode = 0600 (line 44)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: logfilemode = 0600 (line 45)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: devicemode = 0600 (line 46)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: ringsbeforeanswer = 1 (line 47)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: speakervolume = off (line 48)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: gettyargs = -h %l dx_%s (line 49)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: localidentifier = NothingSetup (line 50)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: clocalasroot = yes (line 51)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: taglinefont = etc/lutRS18.pcf (line 52)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: taglineformat = From %%l|%c|Page %%p of %%t (line 53)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: maxrecvpages = 25 (line 54)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemtype = Class2.0 (line 60)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemrate = 38400 (line 61)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemflowcontrol = rtscts (line 62)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemnoflowcmd = AT&H0&I0&R1 (line 64)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemhardflowcmd = AT&H1&I0&R2 (line 65)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemsoftflowcmd = AT&H2&I2&R1 (line 66)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemsetupdtrcmd = ATS13=1&D2 (line 68)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemsetupdcdcmd = AT&C1 (line 69)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemresultcodescmd = ATQ0X4 (line 70)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemsetupaacmd = AT+FAA=1 (line 75)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: modemsetvolumecmd = ATM0 ATM1 ATM1 ATM1 ATM1 (line 80)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: class2bugcmd = AT+FBU=0 (line 85)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: class2cqquerycmd = !(0),(0) (line 91)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: class2nrcmd = AT+FNR=1,1,1,0 (line 97)
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define AreaCode = "518"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define CountryCode = "1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define LongDistancePrefix = "1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define InternationalPrefix = "011"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define Area = "518"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define Country = "1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define IDPrefix = "011"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define LDPrefix = "1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: Define WS = " ^I"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: CanonicalNumber := [
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "#.*" = ""
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[abcABC]" = "2"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[defDEF]" = "3"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[ghiGHI]" = "4"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[jklJKL]" = "5"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[mnoMNO]" = "6"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[prsPRS]" = "7"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[tuvTUV]" = "8"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[wxyWXY]" = "9"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[^+0-9]+" = ""
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "^011" = "+"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "^1" = "+1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "^[^+]" = "+1518&"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: ]
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: DialString := [
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[- ^I.]+" = ""
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[abcABC]" = "2"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[defDEF]" = "3"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[ghiGHI]" = "4"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[jklJKL]" = "5"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[mnoMNO]" = "6"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[prsPRS]" = "7"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[tuvTUV]" = "8"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "[wxyWXY]" = "9"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "^[+]1" = "1"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]:   "^[+]" = "011"
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: ]
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: OPEN /dev/ttyS0
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:28:05 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:28:08 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:28:08 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:28:08 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:28:08 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:28:13 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:28:13 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:28:13 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:28:13 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:28:15 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:28:15 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:28:15 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:28:15 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:28:20 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:28:20 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:28:20 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:28:20 winterran1crdge FaxGetty[16251]: /dev/ttyS0: Can not initialize modem.
Sep  9 15:28:20 winterran1crdge FaxGetty[16251]: STATE CHANGE: BASE -> MODEMWAIT (timeout 30)
Sep  9 15:28:50 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:28:50 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:28:53 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:28:53 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:28:53 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:28:53 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:28:58 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:28:58 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:28:58 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:28:58 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:29:01 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:29:01 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:29:01 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:29:01 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:29:06 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:29:06 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:29:06 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:29:36 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:29:36 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:29:38 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:29:38 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:29:38 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:29:38 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:29:43 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:29:43 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:29:43 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:29:43 winterran1crdge FaxGetty[16251]: DELAY 2600 ms
Sep  9 15:29:46 winterran1crdge FaxGetty[16251]: MODEM set DTR ON
Sep  9 15:29:46 winterran1crdge FaxGetty[16251]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Sep  9 15:29:46 winterran1crdge FaxGetty[16251]: MODEM flush i/o
Sep  9 15:29:46 winterran1crdge FaxGetty[16251]: <-- [17:ATE0V1Q0X4S0=0H0\r]
Sep  9 15:29:51 winterran1crdge FaxQueuer[15976]: MODEM /dev/ttyS0 appears to be wedged
Sep  9 15:29:51 winterran1crdge FaxQueuer[15976]: MODEM WEDGED: bin/wedged "ttyS0" "/dev/ttyS0"
Sep  9 15:29:51 winterran1crdge FaxGetty[16251]: MODEM TIMEOUT: reading line from modem
Sep  9 15:29:51 winterran1crdge FaxGetty[16251]: MODEM <Timeout>
Sep  9 15:29:51 winterran1crdge FaxGetty[16251]: MODEM set DTR OFF
Sep  9 15:29:51 winterran1crdge FaxGetty[16251]: Unable to setup modem on /dev/ttyS0; giving up after 2 attempts
Sep  9 15:29:51 winterran1crdge FaxGetty[16251]: CLOSE /dev/ttyS0
Sep  9 15:29:51 winterran1crdge sendmail[16256]: PAA16256: from=fax, size=336, class=0, pri=30336, nrcpts=1, msgid=<199909091929.PAA16256@winterran1crdge.crd.ge.com>, relay=uucp@localhost
Sep  9 15:29:52 winterran1crdge sendmail[16261]: PAA16256: to=interran, ctladdr=fax (10/14), delay=00:00:01, xdelay=00:00:01, mailer=local, stat=Sent

I've searched the mail archives and found other people who have posted
similar problem reports, but I haven't seen a solution.  If you have
encountered this problem or have an idea what causes it, will you
please tell us how to make faxgetty work?

		John