flexfax: Failure to train remote modem at 2400 bps or minimum speed (long)

["Michael Glauche" <mg@plum.de>]

Hi,

  I got a problem sending faxes to SOME faxmachines. Most seem to work, but
for some
i get the following :

>Mar 26 12:20:54.75: [22468]: DELAY 2600 ms
>Mar 26 12:20:57.35: [22468]: <-- [15:ATE0V1Q0S0=0H0\r]
>Mar 26 12:20:57.37: [22468]: --> [2:OK]
>Mar 26 12:20:57.37: [22468]: <-- [12:ATS8=2S7=60\r]
>Mar 26 12:20:57.39: [22468]: --> [2:OK]
>Mar 26 12:20:57.39: [22468]: <-- [14:ATX3+FCLASS=1\r]
>Mar 26 12:20:57.41: [22468]: --> [2:OK]
>Mar 26 12:20:57.41: [22468]: <-- [5:ATM0\r]
>Mar 26 12:20:57.42: [22468]: --> [2:OK]
>Mar 26 12:20:57.42: [22468]: <-- [14:ATX3+FCLASS=1\r]
>Mar 26 12:20:57.54: [22468]: --> [2:OK]
>Mar 26 12:20:57.54: [22468]: DIAL 02161<snip>
>Mar 26 12:20:57.55: [22468]: <-- [20:ATDT0,,02161<snip>@\r]
>Mar 26 12:21:15.41: [22468]: --> [7:CONNECT]
>Mar 26 12:21:16.53: [22468]: --> [2:OK]
>Mar 26 12:21:16.53: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:16.55: [22468]: --> [7:CONNECT]
>Mar 26 12:21:17.25: [22468]: --> [2:OK]
>Mar 26 12:21:17.25: [22468]: REMOTE CSI "+49 2161 <snip>"
>Mar 26 12:21:17.25: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:17.27: [22468]: --> [7:CONNECT]
>Mar 26 12:21:17.62: [22468]: --> [2:OK]
>Mar 26 12:21:17.62: [22468]: REMOTE best rate 9600 bit/s
>Mar 26 12:21:17.62: [22468]: REMOTE max page width 1728 pixels in 215 mm
>Mar 26 12:21:17.62: [22468]: REMOTE max unlimited page length
>Mar 26 12:21:17.62: [22468]: REMOTE best vres 7.7 line/mm
>Mar 26 12:21:17.62: [22468]: REMOTE best format 1-D MR
>Mar 26 12:21:17.62: [22468]: REMOTE supports T.30 Annex A, ECM
>Mar 26 12:21:17.62: [22468]: REMOTE best 20 ms, 10 ms/scanline
>Mar 26 12:21:17.62: [22468]: USE 9600 bit/s
>Mar 26 12:21:17.62: [22468]: USE 20 ms, 10 ms/scanline
>Mar 26 12:21:17.62: [22468]: SEND file "docq/doc510.ps;01"
>Mar 26 12:21:17.63: [22468]: USE page width 1728 pixels in 215 mm
>Mar 26 12:21:17.63: [22468]: USE unlimited page length
>Mar 26 12:21:17.63: [22468]: USE 7.7 line/mm
>Mar 26 12:21:17.63: [22468]: USE 1-D MR
>Mar 26 12:21:17.63: [22468]: SEND training at v.29 9600 bit/s
>Mar 26 12:21:17.63: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:17.68: [22468]: --> [7:CONNECT]
>Mar 26 12:21:17.69: [22468]: --> [7:CONNECT]
>Mar 26 12:21:19.49: [22468]: --> [7:CONNECT]
>Mar 26 12:21:20.24: [22468]: --> [0:]
>Mar 26 12:21:20.24: [22468]: MODEM <Empty line>
>Mar 26 12:21:20.24: [22468]: Error sending T.30 prologue frames
>Mar 26 12:21:20.24: [22468]: SEND training at v.29 9600 bit/s
>Mar 26 12:21:20.24: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:20.70: [22468]: --> [2:OK]
>Mar 26 12:21:20.70: [22468]: Error sending T.30 prologue frames
>Mar 26 12:21:20.70: [22468]: SEND training at v.29 7200 bit/s
>Mar 26 12:21:20.70: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:20.75: [22468]: --> [7:CONNECT]
>Mar 26 12:21:22.54: [22468]: --> [7:CONNECT]
>Mar 26 12:21:22.98: [22468]: --> [2:OK]
>Mar 26 12:21:22.98: [22468]: DELAY 75 ms
>Mar 26 12:21:23.07: [22468]: <-- [10:AT+FTM=72\r]
>Mar 26 12:21:23.13: [22468]: --> [7:CONNECT]
>Mar 26 12:21:25.08: [22468]: --> [4:]
>Mar 26 12:21:25.08: [22468]: --> [2:OK]
>Mar 26 12:21:25.08: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:28.18: [22468]: --> [0:]
>Mar 26 12:21:28.18: [22468]: MODEM <Empty line>
>Mar 26 12:21:28.23: [22468]: --> [2:OK]
>Mar 26 12:21:28.23: [22468]: DELAY 1500 ms
>Mar 26 12:21:29.74: [22468]: SEND training at v.29 7200 bit/s
>Mar 26 12:21:29.74: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:29.79: [22468]: --> [7:CONNECT]
>Mar 26 12:21:31.58: [22468]: --> [7:CONNECT]
>Mar 26 12:21:32.01: [22468]: --> [2:OK]
>Mar 26 12:21:32.01: [22468]: DELAY 75 ms
>Mar 26 12:21:32.10: [22468]: <-- [10:AT+FTM=72\r]
>Mar 26 12:21:32.16: [22468]: --> [7:CONNECT]
>Mar 26 12:21:34.11: [22468]: --> [4:]
>Mar 26 12:21:34.11: [22468]: --> [2:OK]
>Mar 26 12:21:34.11: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:37.21: [22468]: --> [0:]
>Mar 26 12:21:37.21: [22468]: MODEM <Empty line>
>Mar 26 12:21:37.27: [22468]: --> [2:OK]
>Mar 26 12:21:37.27: [22468]: DELAY 1500 ms
>Mar 26 12:21:38.78: [22468]: SEND training at v.27ter 4800 bit/s
>Mar 26 12:21:38.78: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:38.83: [22468]: --> [7:CONNECT]
>Mar 26 12:21:40.62: [22468]: --> [7:CONNECT]
>Mar 26 12:21:41.06: [22468]: --> [2:OK]
>Mar 26 12:21:41.06: [22468]: DELAY 75 ms
>Mar 26 12:21:41.15: [22468]: <-- [10:AT+FTM=48\r]
>Mar 26 12:21:41.22: [22468]: --> [7:CONNECT]
>Mar 26 12:21:43.65: [22468]: --> [2:]
>Mar 26 12:21:43.65: [22468]: --> [2:OK]
>Mar 26 12:21:43.65: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:46.75: [22468]: --> [0:]
>Mar 26 12:21:46.75: [22468]: MODEM <Empty line>
>Mar 26 12:21:46.81: [22468]: --> [2:OK]
>Mar 26 12:21:46.81: [22468]: DELAY 1500 ms
>Mar 26 12:21:48.32: [22468]: SEND training at v.27ter 4800 bit/s
>Mar 26 12:21:48.32: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:48.37: [22468]: --> [7:CONNECT]
>Mar 26 12:21:50.16: [22468]: --> [7:CONNECT]
>Mar 26 12:21:50.60: [22468]: --> [2:OK]
>Mar 26 12:21:50.60: [22468]: DELAY 75 ms
>Mar 26 12:21:50.69: [22468]: <-- [10:AT+FTM=48\r]
>Mar 26 12:21:50.76: [22468]: --> [7:CONNECT]
>Mar 26 12:21:53.19: [22468]: --> [2:]
>Mar 26 12:21:53.19: [22468]: --> [2:OK]
>Mar 26 12:21:53.19: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:21:56.29: [22468]: --> [0:]
>Mar 26 12:21:56.29: [22468]: MODEM <Empty line>
>Mar 26 12:21:56.35: [22468]: --> [2:OK]
>Mar 26 12:21:56.35: [22468]: DELAY 1500 ms
>Mar 26 12:21:57.86: [22468]: SEND training at v.27ter fallback mode 2400
bit/s
>Mar 26 12:21:57.86: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:21:57.91: [22468]: --> [7:CONNECT]
>Mar 26 12:21:59.70: [22468]: --> [7:CONNECT]
>Mar 26 12:22:00.14: [22468]: --> [2:OK]
>Mar 26 12:22:00.14: [22468]: DELAY 75 ms
>Mar 26 12:22:00.23: [22468]: <-- [10:AT+FTM=24\r]
>Mar 26 12:22:00.31: [22468]: --> [7:CONNECT]
>Mar 26 12:22:02.98: [22468]: --> [2:OK]
>Mar 26 12:22:02.98: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:22:06.08: [22468]: --> [0:]
>Mar 26 12:22:06.08: [22468]: MODEM <Empty line>
>Mar 26 12:22:06.14: [22468]: --> [2:OK]
>Mar 26 12:22:06.14: [22468]: DELAY 1500 ms
>Mar 26 12:22:07.65: [22468]: SEND training at v.27ter fallback mode 2400
bit/s
>Mar 26 12:22:07.65: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:22:07.70: [22468]: --> [7:CONNECT]
>Mar 26 12:22:09.49: [22468]: --> [7:CONNECT]
>Mar 26 12:22:09.93: [22468]: --> [2:OK]
>Mar 26 12:22:09.93: [22468]: DELAY 75 ms
>Mar 26 12:22:10.02: [22468]: <-- [10:AT+FTM=24\r]
>Mar 26 12:22:10.10: [22468]: --> [7:CONNECT]
>Mar 26 12:22:12.78: [22468]: --> [2:OK]
>Mar 26 12:22:12.78: [22468]: <-- [9:AT+FRH=3\r]
>Mar 26 12:22:15.88: [22468]: --> [0:]
>Mar 26 12:22:15.88: [22468]: MODEM <Empty line>
>Mar 26 12:22:15.94: [22468]: --> [2:OK]
>Mar 26 12:22:15.94: [22468]: DELAY 1500 ms
>Mar 26 12:22:17.45: [22468]: TRAINING failed
>Mar 26 12:22:17.45: [22468]: <-- [9:AT+FTH=3\r]
>Mar 26 12:22:17.50: [22468]: --> [7:CONNECT]
>Mar 26 12:22:18.82: [22468]: --> [2:OK]
>Mar 26 12:22:18.82: [22468]: SEND FAILED: Failure to train remote modem at
2400 bps or minimum speed; too many attempts to dial
>Mar 26 12:22:18.82: [22468]: <-- [5:ATH0\r]
>Mar 26 12:22:19.52: [22468]: --> [2:OK]
>Mar 26 12:22:19.52: [22468]: SESSION END

One MUCH worse thing is this :
Mar 26 14:08:19.64: [29972]: --> [7:CONNECT]
>Mar 26 14:08:19.91: [29972]: --> [2:OK]
>Mar 26 14:08:19.91: [29972]: REMOTE best rate 9600 bit/s
>Mar 26 14:08:19.91: [29972]: REMOTE max page width 1728 pixels in 215 mm
>Mar 26 14:08:19.91: [29972]: REMOTE max unlimited page length
>Mar 26 14:08:19.91: [29972]: REMOTE best vres 7.7 line/mm
>Mar 26 14:08:19.91: [29972]: REMOTE best format 2-D MMR
>Mar 26 14:08:19.91: [29972]: REMOTE supports T.30 Annex A, ECM
>Mar 26 14:08:19.91: [29972]: REMOTE best 20 ms/scanline
>Mar 26 14:08:19.91: [29972]: USE 9600 bit/s
>Mar 26 14:08:19.91: [29972]: USE 20 ms/scanline
>Mar 26 14:08:19.91: [29972]: SEND file "docq/doc537.ps;41"
>Mar 26 14:08:19.91: [29972]: USE page width 1728 pixels in 215 mm
>Mar 26 14:08:19.92: [29972]: USE unlimited page length
>Mar 26 14:08:19.92: [29972]: USE 7.7 line/mm
>Mar 26 14:08:19.92: [29972]: USE 2-D MR
>Mar 26 14:08:19.92: [29972]: SEND training at v.29 9600 bit/s
>Mar 26 14:08:19.92: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:08:19.97: [29972]: --> [7:CONNECT]
>Mar 26 14:08:21.75: [29972]: --> [7:CONNECT]
>Mar 26 14:08:22.20: [29972]: --> [2:OK]
>Mar 26 14:08:22.20: [29972]: DELAY 75 ms
>Mar 26 14:08:22.29: [29972]: <-- [10:AT+FTM=96\r]
>Mar 26 14:08:22.35: [29972]: --> [7:CONNECT]
>Mar 26 14:08:24.31: [29972]: --> [4:]
>Mar 26 14:08:24.31: [29972]: --> [2:OK]
>Mar 26 14:08:24.31: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:08:24.79: [29972]: --> [7:CONNECT]
>Mar 26 14:08:25.72: [29972]: --> [2:OK]
>Mar 26 14:08:25.72: [29972]: TRAINING succeeded
>Mar 26 14:08:25.72: [29972]: <-- [10:AT+FTM=96\r]
>Mar 26 14:08:25.78: [29972]: --> [7:CONNECT]
>Mar 26 14:08:25.78: [29972]: SEND begin page
>Mar 26 14:09:08.67: [29972]: SENT 54988 bytes of data
>Mar 26 14:09:16.14: [29972]: SENT 8040 bytes of data
>Mar 26 14:09:16.14: [29972]: SEND 2D RTC
>Mar 26 14:09:16.14: [29972]: SEND end page
>Mar 26 14:09:18.77: [29972]: -->
[112:
]
>Mar 26 14:09:18.77: [29972]: --> [2:OK]
>Mar 26 14:09:18.77: [29972]: DELAY 95 ms
>Mar 26 14:09:18.88: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:09:18.88: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:09:18.94: [29972]: --> [7:CONNECT]
>Mar 26 14:09:20.25: [29972]: --> [2:OK]
>Mar 26 14:09:20.25: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:09:20.62: [29972]: --> [7:CONNECT]
>Mar 26 14:09:21.60: [29972]: --> [2:OK]
>Mar 26 14:09:21.60: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:09:21.60: [29972]: SEND training at v.29 9600 bit/s
>Mar 26 14:09:21.60: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:09:21.65: [29972]: --> [7:CONNECT]
>Mar 26 14:09:23.44: [29972]: --> [7:CONNECT]
>Mar 26 14:09:23.87: [29972]: --> [2:OK]
>Mar 26 14:09:23.87: [29972]: DELAY 75 ms
>Mar 26 14:09:23.96: [29972]: <-- [10:AT+FTM=96\r]
>Mar 26 14:09:24.02: [29972]: --> [7:CONNECT]
>Mar 26 14:09:25.98: [29972]: --> [4:]
>Mar 26 14:09:25.98: [29972]: --> [2:OK]
>Mar 26 14:09:25.98: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:09:26.49: [29972]: --> [7:CONNECT]
>Mar 26 14:09:27.41: [29972]: --> [2:OK]
>Mar 26 14:09:27.41: [29972]: TRAINING succeeded
>Mar 26 14:09:27.41: [29972]: <-- [10:AT+FTM=96\r]
>Mar 26 14:09:27.47: [29972]: --> [7:CONNECT]
>Mar 26 14:09:27.47: [29972]: SEND begin page
>Mar 26 14:10:10.36: [29972]: SENT 54988 bytes of data
>Mar 26 14:10:17.83: [29972]: SENT 8040 bytes of data
>Mar 26 14:10:17.83: [29972]: SEND 2D RTC
>Mar 26 14:10:17.83: [29972]: SEND end page
>Mar 26 14:10:20.47: [29972]: -->
[112:
]
>Mar 26 14:10:20.47: [29972]: --> [2:OK]
>Mar 26 14:10:20.47: [29972]: DELAY 95 ms
>Mar 26 14:10:20.58: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:10:20.58: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:10:20.63: [29972]: --> [7:CONNECT]
>Mar 26 14:10:21.95: [29972]: --> [2:OK]
>Mar 26 14:10:21.95: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:10:22.46: [29972]: --> [7:CONNECT]
>Mar 26 14:10:23.39: [29972]: --> [2:OK]
>Mar 26 14:10:23.39: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:10:23.39: [29972]: SEND training at v.29 7200 bit/s
>Mar 26 14:10:23.39: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:10:23.44: [29972]: --> [7:CONNECT]
>Mar 26 14:10:25.23: [29972]: --> [7:CONNECT]
>Mar 26 14:10:25.66: [29972]: --> [2:OK]
>Mar 26 14:10:25.66: [29972]: DELAY 75 ms
>Mar 26 14:10:25.75: [29972]: <-- [10:AT+FTM=72\r]
>Mar 26 14:10:25.81: [29972]: --> [7:CONNECT]
>Mar 26 14:10:27.77: [29972]: --> [4:]
>Mar 26 14:10:27.77: [29972]: --> [2:OK]
>Mar 26 14:10:27.77: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:10:28.29: [29972]: --> [7:CONNECT]
>Mar 26 14:10:29.20: [29972]: --> [2:OK]
>Mar 26 14:10:29.20: [29972]: TRAINING succeeded
>Mar 26 14:10:29.20: [29972]: <-- [10:AT+FTM=72\r]
>Mar 26 14:10:29.26: [29972]: --> [7:CONNECT]
>Mar 26 14:10:29.26: [29972]: SEND begin page
>Mar 26 14:11:11.66: [29972]: SENT 41247 bytes of data
>Mar 26 14:11:22.26: [29972]: SENT 10125 bytes of data
>Mar 26 14:11:22.26: [29972]: SEND 2D RTC
>Mar 26 14:11:22.26: [29972]: SEND end page
>Mar 26 14:11:26.82: [29972]: -->
[130:
]
>Mar 26 14:11:26.82: [29972]: --> [2:OK]
>Mar 26 14:11:26.82: [29972]: DELAY 95 ms
>Mar 26 14:11:26.93: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:11:26.93: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:11:26.98: [29972]: --> [7:CONNECT]
>Mar 26 14:11:28.30: [29972]: --> [2:OK]
>Mar 26 14:11:28.30: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:11:28.80: [29972]: --> [7:CONNECT]
>Mar 26 14:11:29.72: [29972]: --> [2:OK]
>Mar 26 14:11:29.72: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:11:29.72: [29972]: SEND training at v.29 7200 bit/s
>Mar 26 14:11:29.72: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:11:29.77: [29972]: --> [7:CONNECT]
>Mar 26 14:11:31.56: [29972]: --> [7:CONNECT]
>Mar 26 14:11:32.00: [29972]: --> [2:OK]
>Mar 26 14:11:32.00: [29972]: DELAY 75 ms
>Mar 26 14:11:32.09: [29972]: <-- [10:AT+FTM=72\r]
>Mar 26 14:11:32.15: [29972]: --> [7:CONNECT]
>Mar 26 14:11:34.10: [29972]: --> [4:]
>Mar 26 14:11:34.10: [29972]: --> [2:OK]
>Mar 26 14:11:34.10: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:11:34.61: [29972]: --> [7:CONNECT]
>Mar 26 14:11:35.53: [29972]: --> [2:OK]
>Mar 26 14:11:35.53: [29972]: TRAINING succeeded
>Mar 26 14:11:35.53: [29972]: <-- [10:AT+FTM=72\r]
>Mar 26 14:11:35.59: [29972]: --> [7:CONNECT]
>Mar 26 14:11:35.59: [29972]: SEND begin page
>Mar 26 14:12:17.99: [29972]: SENT 41247 bytes of data
>Mar 26 14:12:28.59: [29972]: SENT 10125 bytes of data
>Mar 26 14:12:28.59: [29972]: SEND 2D RTC
>Mar 26 14:12:28.60: [29972]: SEND end page
>Mar 26 14:12:33.16: [29972]: -->
[130:
]
>Mar 26 14:12:33.16: [29972]: --> [2:OK]
>Mar 26 14:12:33.16: [29972]: DELAY 95 ms
>Mar 26 14:12:33.27: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:12:33.27: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:12:33.32: [29972]: --> [7:CONNECT]
>Mar 26 14:12:34.64: [29972]: --> [2:OK]
>Mar 26 14:12:34.64: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:12:35.18: [29972]: --> [7:CONNECT]
>Mar 26 14:12:36.09: [29972]: --> [2:OK]
>Mar 26 14:12:36.09: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:12:36.09: [29972]: SEND training at v.27ter 4800 bit/s
>Mar 26 14:12:36.09: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:12:36.14: [29972]: --> [7:CONNECT]
>Mar 26 14:12:37.93: [29972]: --> [7:CONNECT]
>Mar 26 14:12:38.36: [29972]: --> [2:OK]
>Mar 26 14:12:38.36: [29972]: DELAY 75 ms
>Mar 26 14:12:38.45: [29972]: <-- [10:AT+FTM=48\r]
>Mar 26 14:12:38.52: [29972]: --> [7:CONNECT]
>Mar 26 14:12:40.95: [29972]: --> [2:]
>Mar 26 14:12:40.95: [29972]: --> [2:OK]
>Mar 26 14:12:40.95: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:12:41.48: [29972]: --> [7:CONNECT]
>Mar 26 14:12:42.39: [29972]: --> [2:OK]
>Mar 26 14:12:42.39: [29972]: TRAINING succeeded
>Mar 26 14:12:42.39: [29972]: <-- [10:AT+FTM=48\r]
>Mar 26 14:12:42.46: [29972]: --> [7:CONNECT]
>Mar 26 14:12:42.46: [29972]: SEND begin page
>Mar 26 14:13:22.86: [29972]: SENT 27473 bytes of data
>Mar 26 14:13:44.41: [29972]: SENT 13227 bytes of data
>Mar 26 14:13:44.41: [29972]: SEND 2D RTC
>Mar 26 14:13:44.41: [29972]: SEND end page
>Mar 26 14:13:51.27: [29972]: -->
[132:
]
>Mar 26 14:13:51.27: [29972]: --> [2:OK]
>Mar 26 14:13:51.27: [29972]: DELAY 95 ms
>Mar 26 14:13:51.38: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:13:51.38: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:13:51.43: [29972]: --> [7:CONNECT]
>Mar 26 14:13:52.75: [29972]: --> [2:OK]
>Mar 26 14:13:52.75: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:13:53.27: [29972]: --> [7:CONNECT]
>Mar 26 14:13:54.16: [29972]: --> [2:OK]
>Mar 26 14:13:54.16: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:13:54.16: [29972]: SEND training at v.27ter 4800 bit/s
>Mar 26 14:13:54.16: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:13:54.22: [29972]: --> [7:CONNECT]
>Mar 26 14:13:56.00: [29972]: --> [7:CONNECT]
>Mar 26 14:13:56.44: [29972]: --> [2:OK]
>Mar 26 14:13:56.44: [29972]: DELAY 75 ms
>Mar 26 14:13:56.53: [29972]: <-- [10:AT+FTM=48\r]
>Mar 26 14:13:56.60: [29972]: --> [7:CONNECT]
>Mar 26 14:13:59.03: [29972]: --> [2:]
>Mar 26 14:13:59.03: [29972]: --> [2:OK]
>Mar 26 14:13:59.03: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:13:59.54: [29972]: --> [7:CONNECT]
>Mar 26 14:14:00.46: [29972]: --> [2:OK]
>Mar 26 14:14:00.46: [29972]: TRAINING succeeded
>Mar 26 14:14:00.46: [29972]: <-- [10:AT+FTM=48\r]
>Mar 26 14:14:00.53: [29972]: --> [7:CONNECT]
>Mar 26 14:14:00.53: [29972]: SEND begin page
>Mar 26 14:14:40.93: [29972]: SENT 27473 bytes of data
>Mar 26 14:15:02.48: [29972]: SENT 13227 bytes of data
>Mar 26 14:15:02.48: [29972]: SEND 2D RTC
>Mar 26 14:15:02.48: [29972]: SEND end page
>Mar 26 14:15:09.34: [29972]: -->
[132:
]
>Mar 26 14:15:09.34: [29972]: --> [2:OK]
>Mar 26 14:15:09.34: [29972]: DELAY 95 ms
>Mar 26 14:15:09.45: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:15:09.45: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:15:09.50: [29972]: --> [7:CONNECT]
>Mar 26 14:15:10.82: [29972]: --> [2:OK]
>Mar 26 14:15:10.82: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:15:11.22: [29972]: --> [7:CONNECT]
>Mar 26 14:15:12.14: [29972]: --> [2:OK]
>Mar 26 14:15:12.14: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:15:12.14: [29972]: SEND training at v.27ter fallback mode 2400
bit/s
>Mar 26 14:15:12.14: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:15:12.20: [29972]: --> [7:CONNECT]
>Mar 26 14:15:13.98: [29972]: --> [7:CONNECT]
>Mar 26 14:15:14.42: [29972]: --> [2:OK]
>Mar 26 14:15:14.42: [29972]: DELAY 75 ms
>Mar 26 14:15:14.51: [29972]: <-- [10:AT+FTM=24\r]
>Mar 26 14:15:14.59: [29972]: --> [7:CONNECT]
>Mar 26 14:15:17.26: [29972]: --> [2:OK]
>Mar 26 14:15:17.26: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:15:17.77: [29972]: --> [7:CONNECT]
>Mar 26 14:15:18.69: [29972]: --> [2:OK]
>Mar 26 14:15:18.69: [29972]: TRAINING succeeded
>Mar 26 14:15:18.69: [29972]: <-- [10:AT+FTM=24\r]
>Mar 26 14:15:18.77: [29972]: --> [7:CONNECT]
>Mar 26 14:15:18.77: [29972]: SEND begin page
>Mar 26 14:15:53.16: [29972]: SENT 13748 bytes of data
>Mar 26 14:16:38.22: [29972]: SENT 13746 bytes of data
>Mar 26 14:16:49.92: [29972]: SENT 3538 bytes of data
>Mar 26 14:16:49.93: [29972]: SEND 2D RTC
>Mar 26 14:16:49.93: [29972]: SEND end page
>Mar 26 14:17:03.47: [29972]: -->
[124:
]
>Mar 26 14:17:03.47: [29972]: --> [2:OK]
>Mar 26 14:17:03.47: [29972]: DELAY 95 ms
>Mar 26 14:17:03.58: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:17:03.58: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:17:03.63: [29972]: --> [7:CONNECT]
>Mar 26 14:17:04.95: [29972]: --> [2:OK]
>Mar 26 14:17:04.95: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:17:05.47: [29972]: --> [7:CONNECT]
>Mar 26 14:17:06.42: [29972]: --> [2:OK]
>Mar 26 14:17:06.42: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:17:06.42: [29972]: SEND training at v.27ter fallback mode 2400
bit/s
>Mar 26 14:17:06.42: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:17:06.47: [29972]: --> [7:CONNECT]
>Mar 26 14:17:08.26: [29972]: --> [7:CONNECT]
>Mar 26 14:17:08.69: [29972]: --> [2:OK]
>Mar 26 14:17:08.69: [29972]: DELAY 75 ms
>Mar 26 14:17:08.78: [29972]: <-- [10:AT+FTM=24\r]
>Mar 26 14:17:08.86: [29972]: --> [7:CONNECT]
>Mar 26 14:17:11.53: [29972]: --> [2:OK]
>Mar 26 14:17:11.53: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:17:12.04: [29972]: --> [7:CONNECT]
>Mar 26 14:17:12.96: [29972]: --> [2:OK]
>Mar 26 14:17:12.96: [29972]: TRAINING succeeded
>Mar 26 14:17:12.96: [29972]: <-- [10:AT+FTM=24\r]
>Mar 26 14:17:13.04: [29972]: --> [7:CONNECT]
>Mar 26 14:17:13.04: [29972]: SEND begin page
>Mar 26 14:17:47.43: [29972]: SENT 13748 bytes of data
>Mar 26 14:18:32.49: [29972]: SENT 13746 bytes of data
>Mar 26 14:18:44.19: [29972]: SENT 3538 bytes of data
>Mar 26 14:18:44.20: [29972]: SEND 2D RTC
>Mar 26 14:18:44.20: [29972]: SEND end page
>Mar 26 14:18:57.73: [29972]: -->
[124:
]
>Mar 26 14:18:57.73: [29972]: --> [2:OK]
>Mar 26 14:18:57.73: [29972]: DELAY 95 ms
>Mar 26 14:18:57.84: [29972]: SEND send EOP (no more pages or documents)
>Mar 26 14:18:57.84: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:18:57.89: [29972]: --> [7:CONNECT]
>Mar 26 14:18:59.21: [29972]: --> [2:OK]
>Mar 26 14:18:59.21: [29972]: <-- [9:AT+FRH=3\r]
>Mar 26 14:18:59.71: [29972]: --> [7:CONNECT]
>Mar 26 14:19:00.62: [29972]: --> [2:OK]
>Mar 26 14:19:00.62: [29972]: SEND recv RTN (retrain negative)
>Mar 26 14:19:00.62: [29972]: <-- [9:AT+FTH=3\r]
>Mar 26 14:19:00.68: [29972]: --> [7:CONNECT]
>Mar 26 14:19:01.99: [29972]: --> [2:OK]
>Mar 26 14:19:01.99: [29972]: SEND FAILED: Unable to transmit page (NAK at
all possible signalling rates); too many attempts to dial
>Mar 26 14:19:01.99: [29972]: <-- [5:ATH0\r]
>Mar 26 14:19:02.70: [29972]: --> [2:OK]
>Mar 26 14:19:02.70: [29972]: SESSION END

He got like 10 pages or so ... :(

Hylafax 4.0pl2-3rh5 (precompiled)
pentium 133 / linux 2.0.36
Modem : v1433vqe (no branding ?!) Class 1 modem

from the config :
ModemType:              Class1          # use this to supply a hint
ModemFlowControl:       RTSCTS
ModemDialCmd:           ATDT0,,%s@
Class1Cmd:                  ATX3+FCLASS=1   # command to enter class 1
Class1TCFResponseDelay: 75              # 75ms delay between recv TCF &
response
Class1SendPPMDelay:     75              # 75ms delay before sending PPM
Class1SendTCFDelay:     75              # 75ms delay between sending DCS &
TCF
Class1TrainingRecovery: 1500            # 1.5sec delay after training
failure
Class1RecvAbortOK:      200             # wait 200ms for abort response
Class1FrameOverhead:    4               # 4 byte overhead in recvd HDLC
frames
Class1RecvIdentTimer:   40000           # 35+5secs waiting for ident frames
Class1TCFMaxNonZero:    10              # max 10% of data may be non-zero
Class1TCFMinRun:        1000            # min run is 2/3rds of TCF duration

Any ideas what could cause that ? I got the second logfile more than once,
all calls are local, so line should be good quality.

TIA,
   Michael Glauche