flexfax: Communication failure during Phase B/C

[Doc <doc@scott.net>]

Hello:

I'm new to this list and have recently inherited a hylafax server for
support.  There is a problem with faxes to apparently some fax machines -
so far 2 HP fax machines fail for sure.  In short:

Everything seems to work and the fax is delivered except for about the
last line or two.  Then the fax machine reports an error (doesn't say what
the error was that I can find).  (Again, the last line or two seems to
be missing on the printed fax).

After the 3rd attempt, this line is written to the logfile:
	Apr 19 10:26:47 faxgate FaxSend[20396]: SEND: Communication failure
	during Phase B/C (modem protocol botch); Giving up after 3 attempts
	to send same page "docq/doc4624.ps;30", dirnum 0

I'll include a log file of a run below.

I'm sure this is a very old version of hylafax - most dates in the
directories are 1996.  However it seems to be getting all the way to the
modem part so I'm wondering about the modem itself with those particular
fax machines.

Thanks for any ideas.

Derric



Apr 19 13:00:39.49: [21006]: SESSION BEGIN 00010048 15555551212
Apr 19 13:00:39.49: [21006]: DELAY 2600 ms
Apr 19 13:00:42.10: [21006]: <-- [15:ATE0V1Q0S0=0H0\r]
Apr 19 13:00:42.12: [21006]: --> [2:OK]
Apr 19 13:00:42.12: [21006]: <-- [21:ATS8=2S7=60&K3&D2&C1\r]
Apr 19 13:00:42.14: [21006]: --> [2:OK]
Apr 19 13:00:42.14: [21006]: <-- [12:AT+FCLASS=2\r]
Apr 19 13:00:42.15: [21006]: --> [2:OK]
Apr 19 13:00:42.15: [21006]: <-- [10:AT+FTBC=0\r]
Apr 19 13:00:42.16: [21006]: --> [2:OK]
Apr 19 13:00:42.16: [21006]: <-- [10:AT+FBOR=0\r]
Apr 19 13:00:42.17: [21006]: --> [2:OK]
Apr 19 13:00:42.17: [21006]: <-- [13:AT+FPHCTO=30\r]
Apr 19 13:00:42.18: [21006]: --> [2:OK]
Apr 19 13:00:42.18: [21006]: <-- [24:AT+FDCC=1,5,0,2,0,0,0,0\r]
Apr 19 13:00:42.20: [21006]: --> [2:OK]
Apr 19 13:00:42.20: [21006]: <-- [5:ATM0\r]
Apr 19 13:00:42.21: [21006]: --> [2:OK]
Apr 19 13:00:42.21: [21006]: <-- [12:AT+FCLASS=2\r]
Apr 19 13:00:42.33: [21006]: --> [2:OK]
Apr 19 13:00:42.33: [21006]: <-- [10:AT+FTBC=0\r]
Apr 19 13:00:42.44: [21006]: --> [2:OK]
Apr 19 13:00:42.44: [21006]: <-- [10:AT+FBOR=0\r]
Apr 19 13:00:42.55: [21006]: --> [2:OK]
Apr 19 13:00:42.55: [21006]: <-- [13:AT+FPHCTO=30\r]
Apr 19 13:00:42.66: [21006]: --> [2:OK]
Apr 19 13:00:42.66: [21006]: <-- [24:AT+FDCC=1,5,0,2,0,0,0,0\r]
Apr 19 13:00:42.78: [21006]: --> [2:OK]
Apr 19 13:00:42.78: [21006]: <-- [26:AT+FLID="QLI Fax Gateway"\r]
Apr 19 13:00:42.90: [21006]: --> [2:OK]
Apr 19 13:00:42.90: [21006]: DIAL 5551212
Apr 19 13:00:42.90: [21006]: <-- [12:ATDT5551212\r]
Apr 19 13:00:54.29: [21006]: --> [5:+FCON]
Apr 19 13:00:55.65: [21006]: --> [42:+FNSF:AD 00 36 20 00 44 00 0C 7F 34 0E 85 ]
Apr 19 13:00:55.65: [21006]: REMOTE NSF "AD 00 36 20 00 44 00 0C 7F 34 0E 85"
Apr 19 13:00:56.34: [21006]: --> [28:+FCSI:"        555 555 1212"]
Apr 19 13:00:56.34: [21006]: REMOTE CSI "555 555 1212"
Apr 19 13:00:56.80: [21006]: --> [21:+FDIS:1,5,0,2,1,2,0,0]
Apr 19 13:00:56.80: [21006]: --> [2:OK]
Apr 19 13:00:56.80: [21006]: REMOTE best rate 14400 bit/s
Apr 19 13:00:56.80: [21006]: REMOTE max page width 1728 pixels in 215 mm
Apr 19 13:00:56.80: [21006]: REMOTE max unlimited page length 
Apr 19 13:00:56.80: [21006]: REMOTE best vres 7.7 line/mm
Apr 19 13:00:56.80: [21006]: REMOTE best format 2-D MR
Apr 19 13:00:56.80: [21006]: REMOTE best 0 ms/scanline
Apr 19 13:00:56.80: [21006]: USE 14400 bit/s
Apr 19 13:00:56.80: [21006]: USE 0 ms/scanline
Apr 19 13:00:56.80: [21006]: SEND file "docq/doc2750.cover;30"
Apr 19 13:00:56.81: [21006]: USE page width 1728 pixels in 215 mm
Apr 19 13:00:56.81: [21006]: USE unlimited page length 
Apr 19 13:00:56.81: [21006]: USE 3.85 line/mm
Apr 19 13:00:56.81: [21006]: USE 1-D MR
Apr 19 13:00:56.81: [21006]: <-- [24:AT+FDIS=0,5,0,2,0,0,0,0\r]
Apr 19 13:00:56.93: [21006]: --> [2:OK]
Apr 19 13:00:56.93: [21006]: <-- [7:AT+FDT\r]
Apr 19 13:01:04.53: [21006]: --> [21:+FDCS:0,5,0,2,0,0,0,0]
Apr 19 13:01:04.53: [21006]: --> [7:CONNECT]
Apr 19 13:01:04.53: [21006]: SEND wait for XON
Apr 19 13:01:04.53: [21006]: --> [1:]
Apr 19 13:01:04.53: [21006]: SEND begin page
Apr 19 13:01:04.54: [21006]: <-- data [1029]
Apr 19 13:01:04.54: [21006]: <-- data [1031]
Apr 19 13:01:04.55: [21006]: <-- data [1049]
Apr 19 13:01:04.55: [21006]: <-- data [1031]
Apr 19 13:01:05.78: [21006]: <-- data [1028]
Apr 19 13:01:06.21: [21006]: <-- data [1032]
Apr 19 13:01:06.64: [21006]: <-- data [1029]
Apr 19 13:01:07.49: [21006]: <-- data [1027]
Apr 19 13:01:07.92: [21006]: <-- data [1028]
Apr 19 13:01:08.34: [21006]: <-- data [1036]
Apr 19 13:01:09.19: [21006]: <-- data [1043]
Apr 19 13:01:09.62: [21006]: <-- data [1039]
Apr 19 13:01:10.04: [21006]: <-- data [1034]
Apr 19 13:01:10.90: [21006]: <-- data [1041]
Apr 19 13:01:11.33: [21006]: <-- data [1038]
Apr 19 13:01:11.76: [21006]: <-- data [780]
Apr 19 13:01:12.19: [21006]: SENT 16140 bytes of data
Apr 19 13:01:12.19: [21006]: <-- data [2]
Apr 19 13:01:12.19: [21006]: SEND end page
Apr 19 13:01:14.63: [21006]: --> [42:]
Apr 19 13:01:14.63: [21006]: --> [2:OK]
Apr 19 13:01:14.63: [21006]: SEND send MPS (more pages, same document)
Apr 19 13:01:14.63: [21006]: <-- [9:AT+FET=0\r]
Apr 19 13:01:18.71: [21006]: --> [7:+FPTS:1]
Apr 19 13:01:18.71: [21006]: --> [2:OK]
Apr 19 13:01:18.71: [21006]: SEND recv MCF (message confirmation)
Apr 19 13:01:18.71: [21006]: SEND FAX (00010048): FROM root@fax.domain.com TO 555-1212 (page 1 of 2 sent in 0:22)
Apr 19 13:01:18.71: [21006]: SEND FAX (00010048): FROM root@fax.domain.com TO 555-1212 (docq/doc2750.cover;30 sent in 0:22)
Apr 19 13:01:18.72: [21006]: SEND file "docq/doc4636.ps;30"
Apr 19 13:01:18.73: [21006]: USE page width 1728 pixels in 215 mm
Apr 19 13:01:18.73: [21006]: USE unlimited page length 
Apr 19 13:01:18.73: [21006]: USE 3.85 line/mm
Apr 19 13:01:18.73: [21006]: USE 1-D MR
Apr 19 13:01:18.73: [21006]: <-- [7:AT+FDT\r]
Apr 19 13:01:19.16: [21006]: --> [7:CONNECT]
Apr 19 13:01:19.16: [21006]: SEND wait for XON
Apr 19 13:01:19.16: [21006]: --> [1:]
Apr 19 13:01:19.16: [21006]: SEND begin page
Apr 19 13:01:19.17: [21006]: <-- data [1030]
Apr 19 13:01:19.17: [21006]: <-- data [1026]
Apr 19 13:01:19.17: [21006]: <-- data [1031]
Apr 19 13:01:19.18: [21006]: <-- data [1026]
Apr 19 13:01:19.18: [21006]: <-- data [775]
Apr 19 13:01:20.84: [21006]: SENT 4871 bytes of data
Apr 19 13:01:20.84: [21006]: <-- data [2]
Apr 19 13:01:20.85: [21006]: SEND end page
Apr 19 13:01:23.01: [21006]: --> [12:]
Apr 19 13:01:23.01: [21006]: --> [2:OK]
Apr 19 13:01:23.01: [21006]: SEND send EOP (no more pages or documents)
Apr 19 13:01:23.01: [21006]: <-- [9:AT+FET=2\r]
Apr 19 13:01:27.07: [21006]: --> [7:+FPTS:2]
Apr 19 13:01:28.53: [21006]: --> [7:+FHNG:0]
Apr 19 13:01:28.53: [21006]: REMOTE HANGUP: Normal and proper end of connection (code 0)
Apr 19 13:01:28.53: [21006]: SEND recv RTN (retrain negative)
Apr 19 13:01:28.53: [21006]: <-- [5:ATH0\r]
Apr 19 13:01:29.15: [21006]: --> [2:OK]
Apr 19 13:01:29.15: [21006]: SESSION END