Problem: SEND recv RTN (retrain negative).

[egullich@taz.warp.com (Eric Gullichsen)]

Hylafaxers:

I'm running a ZyXEL 1496E with 6.17 firmware and HylaFAX 4.0p1
on an Indigo running IRIX 5.3

When sending to a FAX machine from which I had previously obtained
a "Normal and proper end of connection", I am now repeatedly
getting a SEND recv RTN (retrain negative).

Anyone have any idea how to avoid this problem?
Did the FAX actually get sent?

Many thanks for any suggestions.

- Eric Gullichsen
  Warp Ltd.
  S.S. Vallejo
  Varda Landing
  Sausalito CA 94965
  FAX:  +1.415.332.8003
  Internet: eric@warp.com
  Home Page: http://www.warp.com/





Here's the log:

Mar 26 12:14:19.78: [ 4968]: SESSION BEGIN 00000615 180059880006495256296
Mar 26 12:14:19.80: [ 4968]: SEND FAX: JOB 889 DEST 18005988000,,,6495256296# COMMID 00000615
Mar 26 12:14:19.80: [ 4968]: DELAY 2600 ms
Mar 26 12:14:22.40: [ 4968]: <-- [51:AT&B1&N0&S0*F0S18=2S38.3=1S39=0S44.7=1E0V1Q0S0=0H0\r]
Mar 26 12:14:22.55: [ 4968]: --> [2:OK]
Mar 26 12:14:22.56: [ 4968]: <-- [21:ATS8=2S7=45&H3&D2&C1\r]
Mar 26 12:14:22.57: [ 4968]: --> [2:OK]
Mar 26 12:14:22.57: [ 4968]: <-- [14:AT+FCLASS=2.0\r]
Mar 26 12:14:22.66: [ 4968]: --> [2:OK]
Mar 26 12:14:22.66: [ 4968]: <-- [9:AT+FLO=2\r]
Mar 26 12:14:22.67: [ 4968]: --> [2:OK]
Mar 26 12:14:22.67: [ 4968]: <-- [9:AT+FPP=0\r]
Mar 26 12:14:22.68: [ 4968]: --> [2:OK]
Mar 26 12:14:22.68: [ 4968]: <-- [9:AT+FBO=0\r]
Mar 26 12:14:22.69: [ 4968]: --> [2:OK]
Mar 26 12:14:22.69: [ 4968]: <-- [13:AT+FPHCTO=60\r]
Mar 26 12:14:22.70: [ 4968]: --> [2:OK]
Mar 26 12:14:22.70: [ 4968]: <-- [15:AT+FNR=1,1,1,1\r]
Mar 26 12:14:22.71: [ 4968]: --> [2:OK]
Mar 26 12:14:22.71: [ 4968]: <-- [9:AT+FIE=0\r]
Mar 26 12:14:22.72: [ 4968]: --> [2:OK]
Mar 26 12:14:22.72: [ 4968]: <-- [23:AT+FCC=1,5,2,2,1,0,0,0\r]
Mar 26 12:14:22.74: [ 4968]: --> [2:OK]
Mar 26 12:14:22.74: [ 4968]: <-- [5:ATM0\r]
Mar 26 12:14:22.74: [ 4968]: --> [2:OK]
Mar 26 12:14:22.75: [ 4968]: <-- [14:AT+FCLASS=2.0\r]
Mar 26 12:14:22.93: [ 4968]: --> [2:OK]
Mar 26 12:14:22.93: [ 4968]: <-- [9:AT+FLO=2\r]
Mar 26 12:14:23.03: [ 4968]: --> [2:OK]
Mar 26 12:14:23.03: [ 4968]: <-- [9:AT+FPP=0\r]
Mar 26 12:14:23.13: [ 4968]: --> [2:OK]
Mar 26 12:14:23.13: [ 4968]: <-- [9:AT+FBO=0\r]
Mar 26 12:14:23.23: [ 4968]: --> [2:OK]
Mar 26 12:14:23.23: [ 4968]: <-- [13:AT+FPHCTO=60\r]
Mar 26 12:14:23.33: [ 4968]: --> [2:OK]
Mar 26 12:14:23.33: [ 4968]: <-- [15:AT+FNR=1,1,1,1\r]
Mar 26 12:14:23.43: [ 4968]: --> [2:OK]
Mar 26 12:14:23.43: [ 4968]: <-- [9:AT+FIE=0\r]
Mar 26 12:14:23.53: [ 4968]: --> [2:OK]
Mar 26 12:14:23.53: [ 4968]: <-- [23:AT+FCC=1,5,2,2,1,0,0,0\r]
Mar 26 12:14:23.64: [ 4968]: --> [2:OK]
Mar 26 12:14:23.64: [ 4968]: <-- [14:AT+FLI="TESS"\r]
Mar 26 12:14:23.74: [ 4968]: --> [2:OK]
Mar 26 12:14:23.76: [ 4968]: DIAL 18005988000,,,6495256296#
Mar 26 12:14:23.76: [ 4968]: <-- [30:ATDT18005988000,,,6495256296#\r]
Mar 26 12:14:55.60: [ 4968]: --> [4:+FCO]
Mar 26 12:14:55.67: [ 4968]: --> [186:+FNF:00 00 25 00 00 00 12 10 0D 02 00 50 00 2A B8 2C 00 00 25 01 44 54 4C 20 5A 4E 20 53 46 41 00 00 25 00 00 00 12 10 0D 02 00 50 00 2A B8 2C 00 00 25 01 44 54 4C 20 5A 4E 20 53 46 41  ]
Mar 26 12:14:55.67: [ 4968]: REMOTE NSF "00 00 25 00 00 00 12 10 0D 02 00 50 00 2A B8 2C 00 00 25 01 44 54 4C 20 5A 4E 20 53 46 41 00 00 25 00 00 00 12 10 0D 02 00 50 00 2A B8 2C 00 00 25 01 44 54 4C 20 5A 4E 20 53 46 41"
Mar 26 12:14:55.67: [ 4968]: --> [26:+FCI:        64 9 5256296 ]
Mar 26 12:14:55.67: [ 4968]: REMOTE CSI "64 9 5256296"
Mar 26 12:14:55.67: [ 4968]: --> [20:+FIS:1,3,0,2,1,1,0,2]
Mar 26 12:14:55.75: [ 4968]: --> [2:OK]
Mar 26 12:14:55.76: [ 4968]: REMOTE best rate 9600 bit/s
Mar 26 12:14:55.76: [ 4968]: REMOTE max page width 1728 pixels in 215 mm
Mar 26 12:14:55.76: [ 4968]: REMOTE max unlimited page length 
Mar 26 12:14:55.76: [ 4968]: REMOTE best vres 7.7 line/mm
Mar 26 12:14:55.76: [ 4968]: REMOTE best format 2-D MR
Mar 26 12:14:55.77: [ 4968]: REMOTE supports T.30 Annex A, ECM
Mar 26 12:14:55.77: [ 4968]: REMOTE best 10 ms, 5 ms/scanline
Mar 26 12:14:55.77: [ 4968]: USE 9600 bit/s
Mar 26 12:14:55.77: [ 4968]: USE 10 ms, 5 ms/scanline
Mar 26 12:14:55.77: [ 4968]: SEND file "docq/doc609.tif;70"
Mar 26 12:14:55.78: [ 4968]: USE page width 1728 pixels in 215 mm
Mar 26 12:14:55.78: [ 4968]: USE unlimited page length 
Mar 26 12:14:55.78: [ 4968]: USE 3.85 line/mm
Mar 26 12:14:55.78: [ 4968]: USE 2-D MR
Mar 26 12:14:55.78: [ 4968]: <-- [23:AT+FIS=0,3,0,2,1,0,0,2\r]
Mar 26 12:14:55.88: [ 4968]: --> [2:OK]
Mar 26 12:14:55.89: [ 4968]: <-- [7:AT+FDT\r]
Mar 26 12:15:02.53: [ 4968]: --> [20:+FCS:0,3,0,2,1,0,0,3]
Mar 26 12:15:02.53: [ 4968]: --> [7:CONNECT]
Mar 26 12:15:02.53: [ 4968]: SEND begin page
Mar 26 12:15:02.54: [ 4968]: <-- data [1036]
Mar 26 12:15:02.54: [ 4968]: <-- data [1035]
Mar 26 12:15:02.54: [ 4968]: <-- data [1041]
Mar 26 12:15:02.54: [ 4968]: <-- data [1028]
Mar 26 12:15:02.81: [ 4968]: <-- data [1034]
Mar 26 12:15:03.08: [ 4968]: <-- data [1033]
Mar 26 12:15:03.35: [ 4968]: <-- data [1032]
Mar 26 12:15:03.62: [ 4968]: <-- data [1048]
Mar 26 12:15:03.89: [ 4968]: <-- data [1037]
Mar 26 12:15:04.16: [ 4968]: <-- data [1037]
Mar 26 12:15:04.43: [ 4968]: <-- data [1039]
Mar 26 12:15:04.70: [ 4968]: <-- data [1038]
Mar 26 12:15:05.40: [ 4968]: <-- data [1043]
Mar 26 12:15:06.09: [ 4968]: <-- data [1042]
Mar 26 12:15:06.80: [ 4968]: <-- data [1044]
Mar 26 12:15:07.99: [ 4968]: <-- data [259]
Mar 26 12:15:08.71: [ 4968]: SENT 15617 bytes of data
Mar 26 12:15:08.72: [ 4968]: SEND 2D RTC
Mar 26 12:15:08.72: [ 4968]: <-- data [10]
Mar 26 12:15:09.42: [ 4968]: SEND end page
Mar 26 12:15:09.42: [ 4968]: SEND send EOP (no more pages or documents)
Mar 26 12:15:09.43: [ 4968]: <-- data [2]
Mar 26 12:15:20.47: [ 4968]: --> [5:ERROR]
Mar 26 12:15:20.48: [ 4968]: SEND recv RTN (retrain negative)
Mar 26 12:15:20.48: [ 4968]: <-- [7:AT+FDT\r]
Mar 26 12:15:26.92: [ 4968]: --> [20:+FCS:0,3,0,2,1,0,0,3]
Mar 26 12:15:26.92: [ 4968]: --> [7:CONNECT]
Mar 26 12:15:26.92: [ 4968]: SEND begin page
Mar 26 12:15:26.92: [ 4968]: <-- data [1036]
Mar 26 12:15:26.92: [ 4968]: <-- data [1035]
Mar 26 12:15:26.93: [ 4968]: <-- data [1041]
Mar 26 12:15:26.93: [ 4968]: <-- data [1028]
Mar 26 12:15:27.19: [ 4968]: <-- data [1034]
Mar 26 12:15:27.47: [ 4968]: <-- data [1033]
Mar 26 12:15:27.74: [ 4968]: <-- data [1032]
Mar 26 12:15:28.01: [ 4968]: <-- data [1048]
Mar 26 12:15:28.28: [ 4968]: <-- data [1037]
Mar 26 12:15:28.55: [ 4968]: <-- data [1037]
Mar 26 12:15:28.82: [ 4968]: <-- data [1039]
Mar 26 12:15:29.09: [ 4968]: <-- data [1038]
Mar 26 12:15:29.79: [ 4968]: <-- data [1043]
Mar 26 12:15:30.48: [ 4968]: <-- data [1042]
Mar 26 12:15:31.19: [ 4968]: <-- data [1044]
Mar 26 12:15:32.38: [ 4968]: <-- data [259]
Mar 26 12:15:33.10: [ 4968]: SENT 15617 bytes of data
Mar 26 12:15:33.10: [ 4968]: SEND 2D RTC
Mar 26 12:15:33.10: [ 4968]: <-- data [10]
Mar 26 12:15:33.81: [ 4968]: SEND end page
Mar 26 12:15:33.81: [ 4968]: SEND send EOP (no more pages or documents)
Mar 26 12:15:33.81: [ 4968]: <-- data [2]
Mar 26 12:15:44.85: [ 4968]: --> [5:ERROR]
Mar 26 12:15:44.85: [ 4968]: SEND recv RTN (retrain negative)
Mar 26 12:15:44.85: [ 4968]: <-- [7:AT+FDT\r]
Mar 26 12:15:51.29: [ 4968]: --> [20:+FCS:0,3,0,2,1,0,0,3]
Mar 26 12:15:51.29: [ 4968]: --> [7:CONNECT]
Mar 26 12:15:51.29: [ 4968]: SEND begin page
Mar 26 12:15:51.30: [ 4968]: <-- data [1036]
Mar 26 12:15:51.30: [ 4968]: <-- data [1035]
Mar 26 12:15:51.30: [ 4968]: <-- data [1041]
Mar 26 12:15:51.31: [ 4968]: <-- data [1028]
Mar 26 12:15:51.57: [ 4968]: <-- data [1034]
Mar 26 12:15:51.84: [ 4968]: <-- data [1033]
Mar 26 12:15:52.11: [ 4968]: <-- data [1032]
Mar 26 12:15:52.38: [ 4968]: <-- data [1048]
Mar 26 12:15:52.65: [ 4968]: <-- data [1037]
Mar 26 12:15:52.92: [ 4968]: <-- data [1037]
Mar 26 12:15:53.19: [ 4968]: <-- data [1039]
Mar 26 12:15:53.47: [ 4968]: <-- data [1038]
Mar 26 12:15:54.17: [ 4968]: <-- data [1043]
Mar 26 12:15:54.86: [ 4968]: <-- data [1042]
Mar 26 12:15:55.56: [ 4968]: <-- data [1044]
Mar 26 12:15:56.76: [ 4968]: <-- data [259]
Mar 26 12:15:57.48: [ 4968]: SENT 15617 bytes of data
Mar 26 12:15:57.48: [ 4968]: SEND 2D RTC
Mar 26 12:15:57.48: [ 4968]: <-- data [10]
Mar 26 12:15:58.19: [ 4968]: SEND end page
Mar 26 12:15:58.19: [ 4968]: SEND send EOP (no more pages or documents)
Mar 26 12:15:58.19: [ 4968]: <-- data [2]
Mar 26 12:16:09.22: [ 4968]: --> [5:ERROR]
Mar 26 12:16:09.23: [ 4968]: SEND recv RTN (retrain negative)
Mar 26 12:16:09.23: [ 4968]: <-- [7:AT+FKS\r]
Mar 26 12:16:10.69: [ 4968]: --> [7:+FHS:02]
Mar 26 12:16:10.69: [ 4968]: REMOTE HANGUP: Call aborted,  from +FK or <CAN> (code 2)
Mar 26 12:16:10.69: [ 4968]: --> [5:ERROR]
Mar 26 12:16:10.69: [ 4968]: MODEM Command error
Mar 26 12:16:10.70: [ 4968]: <-- [5:ATH0\r]
Mar 26 12:16:11.04: [ 4968]: ABORT: job abort requested
Mar 26 12:16:11.04: [ 4968]: --> [0:]
Mar 26 12:16:11.04: [ 4968]: MODEM <Empty line>
Mar 26 12:16:11.05: [ 4968]: SESSION END


------------------------------------------

And here's my modem configuration:

# Configuration for a ZyXEL-1496E or 2864 w/ Class 2.0 firmware.
# Firmware revisions from 6.12 on should work for the 1496E; for
# the 2864 you must have firmware rev 0.07 or later.
#
# This configuration file sets up the ZyXEL to run at 38.4 for
# both sending and receiving.  RTS/CTS flow control is used on
# the tty port--you probably shouldn't use XON/XOFF.  Note that
# on an SGI system the getty speed is the following non-standard
# gettydefs entry:
#
# dx_38400# B38400 # B38400 SANE TAB3 HUPCL #\r\n\n$HOSTNAME login: #dx_38400
#
#
CountryCode:		1
AreaCode:		415
FAXNumber:		+1.415.222.3433
LongDistancePrefix:	1
InternationalPrefix:	011
DialStringRules:	"etc/dialrules"
ServerTracing:		1
SessionTracing:		11
RecvFileMode:		0660
LogFileMode:		0660
DeviceMode:		0600
RingsBeforeAnswer:	2
SpeakerVolume:		off
GettyArgs:		"-h %l dx_%s"
LocalIdentifier:	"FORT"
TagLineFont:		etc/lutRS18.pcf
TagLineFormat:		""
NoCarrierRetrys:	3
MaxRecvPages:		25
JobReqBusy:			600
PageChopThreshold	1.0
#
#
# Modem-related stuff: should reflect modem command interface
# and hardware connection/cabling (e.g. flow control).
#
ModemType:		Class2.0	# use class 2.0 interface
ModemRate:		38400		# 38.4 works fine

ModemFlowControl:	rtscts		
ModemWaitTimeCmd:  ATS7=45		# we pay for 30 sec min anyway
#
ModemNoFlowCmd:		AT&H0		# disable flow control
ModemHardFlowCmd:	AT&H3		# hardware flow control
ModemSoftFlowCmd:	AT&H4		# software flow control
ModemSetupDTRCmd:	AT&D2		# DTR off causes modem to hang up
ModemSetupDCDCmd:	AT&C1		# DCD tracks carrier
#
ModemSetupAACmd:	AT+FAA=1	# enable in current class
#
# Additional reset commands:
#
# &B1	  DTE-DCE rate is fixed at DTE setting
# &N0	  Auto-negotiate highest possible DCE-DCE link rate
# &S0	  DSR always on
# *F0	  Deny remote configuration
# S18=2	  Receive at 38400
# S38.3=1 DCD on/off sequence follows UNIX standard; also
#	  fix receiving baud rate at S18 value
# S39=0	  (avoid Class 2 compatibility hacks)
# S44.7=1 ZyXEL 649 spurious busy workaround
# 
ModemResetCmds:		AT&B1&N0&S0*F0S18=2S38.3=1S39=0S44.7=1
#
ModemDialCmd:		ATDT%s		# no '@' 'cuz then busy not recognized
NoCarrierRetrys:	3		# retry 3 times on no carrier
#
ModemSetVolumeCmd:	"ATM0 ATM1L1 ATM1L3 ATM1L5 ATM1L7"
#
# Caller ID configuration setup.
#
#QualifyCID:		etc/cid		# CID access control list file
#CIDNumber:		"CALLER NUMBER: " # pattern string for phone number info
#CIDName:		"CALLER NAME: "	# pattern string for identity info
#
PagerSetupCmds:		AT&K0&N15	# use V.22 at 1200 bps (PageNet)
#
# Rev 6.1x firmware have a bug in the ECM support so
# explicitly disable it's use.  To re-enable its use just
# comment out the following line.
#
Class2DCCQueryCmd:	"!(0,1),(0-5),(0-4),(0-2),(0,1),(0),(0),(0-7)"

# is this a workaround to "No response to MPS" ?
Class2PHCTOCmd:       AT+FPHCTO=60  # hey double it!