flexfax: HylaFax does not stop sending pages

["Lars Denzer" <ldenzer@omeco.de>]

Hello,

we are running HylaFax on a Linux Box, Kernel 2.2.7 using a Zyxel 2864 ISDN
Modem.

We have problems with several types of fax machines.

One of those is a CANON B200.

If we try to send only one page to this machine,
Hylafax does not stop sending pages and I get the following message in my
logfiles:

Aug 06 20:10:30.27: [30427]: SESSION BEGIN 00000482 089863xxxx
Aug 06 20:10:30.27: [30427]: SEND FAX: JOB 392 DEST 0089863xxxx COMMID
00000482
Aug 06 20:10:30.27: [30427]: DELAY 2600 ms
Aug 06 20:10:32.87: [30427]: <-- [36:AT&B1&N0&S0S18=4S38.3=1E0V1Q0S0=0H0\r]
Aug 06 20:10:32.90: [30427]: --> [2:OK]
Aug 06 20:10:32.90: [30427]: <-- [21:ATS8=2S7=60&H3&D2&C1\r]
Aug 06 20:10:32.92: [30427]: --> [2:OK]
Aug 06 20:10:32.92: [30427]: <-- [12:AT+FCLASS=1\r]
Aug 06 20:10:32.94: [30427]: --> [2:OK]
Aug 06 20:10:32.94: [30427]: <-- [9:AT+FAA=1\r]
Aug 06 20:10:32.95: [30427]: --> [2:OK]
Aug 06 20:10:32.95: [30427]: <-- [5:ATM0\r]
Aug 06 20:10:32.96: [30427]: --> [2:OK]
Aug 06 20:10:32.96: [30427]: <-- [12:AT+FCLASS=1\r]
Aug 06 20:10:33.07: [30427]: --> [2:OK]
Aug 06 20:10:33.07: [30427]: DIAL 0089863xxxx
Aug 06 20:10:33.08: [30427]: <-- [16:ATDT0089863xxxx\r]
Aug 06 20:10:42.54: [30427]: --> [7:CONNECT]
Aug 06 20:10:44.49: [30427]: --> [2:OK]
Aug 06 20:10:44.49: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:10:44.50: [30427]: --> [7:CONNECT]
Aug 06 20:10:45.18: [30427]: --> [2:OK]
Aug 06 20:10:45.18: [30427]: REMOTE CSI "+49 89 863 42 69"
Aug 06 20:10:45.18: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:10:45.19: [30427]: --> [7:CONNECT]
Aug 06 20:10:45.45: [30427]: --> [2:OK]
Aug 06 20:10:45.45: [30427]: REMOTE best rate 9600 bit/s
Aug 06 20:10:45.45: [30427]: REMOTE max page width 1728 pixels in 215 mm
Aug 06 20:10:45.45: [30427]: REMOTE max A4 page length (297 mm)
Aug 06 20:10:45.45: [30427]: REMOTE best vres 7.7 line/mm
Aug 06 20:10:45.45: [30427]: REMOTE best format 2-D MR
Aug 06 20:10:45.45: [30427]: REMOTE best 20 ms/scanline
Aug 06 20:10:45.45: [30427]: USE 9600 bit/s
Aug 06 20:10:45.45: [30427]: USE 20 ms/scanline
Aug 06 20:10:45.45: [30427]: SEND file "docq/doc393.ps;00"
Aug 06 20:10:45.46: [30427]: USE page width 1728 pixels in 215 mm
Aug 06 20:10:45.46: [30427]: USE A4 page length (297 mm)
Aug 06 20:10:45.46: [30427]: USE 3.85 line/mm
Aug 06 20:10:45.46: [30427]: USE 1-D MR
Aug 06 20:10:45.46: [30427]: SEND training at v.29 9600 bit/s
Aug 06 20:10:45.46: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:10:45.49: [30427]: --> [7:CONNECT]
Aug 06 20:10:45.49: [30427]: <-- data [23]
Aug 06 20:10:45.49: [30427]: <-- data [2]
Aug 06 20:10:47.18: [30427]: --> [7:CONNECT]
Aug 06 20:10:47.18: [30427]: <-- data [6]
Aug 06 20:10:47.18: [30427]: <-- data [2]
Aug 06 20:10:47.49: [30427]: --> [2:OK]
Aug 06 20:10:47.49: [30427]: DELAY 75 ms
Aug 06 20:10:47.58: [30427]: <-- [10:AT+FTM=96\r]
Aug 06 20:10:47.62: [30427]: --> [7:CONNECT]
Aug 06 20:10:47.62: [30427]: <-- data [1024]
Aug 06 20:10:47.62: [30427]: <-- data [776]
Aug 06 20:10:47.62: [30427]: <-- data [2]
Aug 06 20:10:49.65: [30427]: --> [2:OK]
Aug 06 20:10:49.65: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:10:49.91: [30427]: --> [7:CONNECT]
Aug 06 20:10:50.91: [30427]: --> [2:OK]
Aug 06 20:10:50.91: [30427]: TRAINING succeeded
Aug 06 20:10:50.91: [30427]: <-- [10:AT+FTM=96\r]
Aug 06 20:10:50.95: [30427]: --> [7:CONNECT]
Aug 06 20:10:50.95: [30427]: SEND begin page
Aug 06 20:10:50.96: [30427]: <-- data [1025]
Aug 06 20:10:50.96: [30427]: <-- data [1024]
Aug 06 20:10:50.96: [30427]: <-- data [1024]
Aug 06 20:10:50.96: [30427]: <-- data [1026]
Aug 06 20:10:50.96: [30427]: <-- data [1025]
Aug 06 20:10:51.95: [30427]: <-- data [1028]
Aug 06 20:10:51.96: [30427]: <-- data [1032]
Aug 06 20:10:51.96: [30427]: <-- data [1029]
Aug 06 20:10:52.85: [30427]: <-- data [1024]
Aug 06 20:10:53.81: [30427]: <-- data [1024]
Aug 06 20:10:54.76: [30427]: <-- data [1024]
Aug 06 20:10:55.72: [30427]: <-- data [1026]
Aug 06 20:10:55.72: [30427]: <-- data [1026]
Aug 06 20:10:56.68: [30427]: <-- data [1026]
Aug 06 20:10:57.64: [30427]: <-- data [1025]
Aug 06 20:10:58.60: [30427]: <-- data [1028]
Aug 06 20:10:59.56: [30427]: <-- data [1024]
Aug 06 20:11:00.51: [30427]: <-- data [1026]
Aug 06 20:11:01.47: [30427]: <-- data [1024]
Aug 06 20:11:02.43: [30427]: <-- data [1025]
Aug 06 20:11:03.39: [30427]: <-- data [1026]
Aug 06 20:11:04.35: [30427]: <-- data [1025]
Aug 06 20:11:04.35: [30427]: <-- data [1024]
Aug 06 20:11:05.31: [30427]: <-- data [1024]
Aug 06 20:11:06.27: [30427]: <-- data [1024]
Aug 06 20:11:07.22: [30427]: <-- data [1024]
Aug 06 20:11:08.18: [30427]: <-- data [868]
Aug 06 20:11:09.14: [30427]: SENT 27492 bytes of data
Aug 06 20:11:09.14: [30427]: <-- data [1024]
Aug 06 20:11:10.10: [30427]: <-- data [1024]
Aug 06 20:11:10.10: [30427]: <-- data [1024]
Aug 06 20:11:11.06: [30427]: <-- data [1024]
Aug 06 20:11:12.02: [30427]: <-- data [1024]
Aug 06 20:11:12.98: [30427]: <-- data [1024]
Aug 06 20:11:13.94: [30427]: <-- data [1024]
Aug 06 20:11:14.90: [30427]: <-- data [128]
Aug 06 20:11:14.90: [30427]: SENT 7296 bytes of data
Aug 06 20:11:14.90: [30427]: SEND 1D RTC
Aug 06 20:11:14.90: [30427]: <-- data [29]
Aug 06 20:11:14.90: [30427]: <-- data [2]
Aug 06 20:11:14.90: [30427]: SEND end page
Aug 06 20:11:20.49: [30427]: -->
[54:]
Aug 06 20:11:20.49: [30427]: --> [2:OK]
Aug 06 20:11:20.49: [30427]: DELAY 95 ms
Aug 06 20:11:20.60: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:11:20.60: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:11:20.64: [30427]: --> [7:CONNECT]
Aug 06 20:11:20.64: [30427]: <-- data [3]
Aug 06 20:11:20.64: [30427]: <-- data [2]
Aug 06 20:11:21.85: [30427]: --> [2:OK]
Aug 06 20:11:21.85: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:11:22.11: [30427]: --> [7:CONNECT]
Aug 06 20:11:23.11: [30427]: --> [2:OK]
Aug 06 20:11:23.11: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:11:23.11: [30427]: SEND training at v.29 9600 bit/s
Aug 06 20:11:23.11: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:11:23.15: [30427]: --> [7:CONNECT]
Aug 06 20:11:23.15: [30427]: <-- data [23]
Aug 06 20:11:23.15: [30427]: <-- data [2]
Aug 06 20:11:24.84: [30427]: --> [7:CONNECT]
Aug 06 20:11:24.84: [30427]: <-- data [6]
Aug 06 20:11:24.84: [30427]: <-- data [2]
Aug 06 20:11:25.14: [30427]: --> [2:OK]
Aug 06 20:11:25.14: [30427]: DELAY 75 ms
Aug 06 20:11:25.23: [30427]: <-- [10:AT+FTM=96\r]
Aug 06 20:11:25.27: [30427]: --> [7:CONNECT]
Aug 06 20:11:25.27: [30427]: <-- data [1024]
Aug 06 20:11:25.27: [30427]: <-- data [776]
Aug 06 20:11:25.27: [30427]: <-- data [2]
Aug 06 20:11:27.30: [30427]: --> [2:OK]
Aug 06 20:11:27.30: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:11:27.56: [30427]: --> [7:CONNECT]
Aug 06 20:11:28.56: [30427]: --> [2:OK]
Aug 06 20:11:28.56: [30427]: TRAINING succeeded
Aug 06 20:11:28.56: [30427]: <-- [10:AT+FTM=96\r]
Aug 06 20:11:28.60: [30427]: --> [7:CONNECT]
Aug 06 20:11:28.60: [30427]: SEND begin page
Aug 06 20:11:28.61: [30427]: <-- data [1025]
Aug 06 20:11:28.61: [30427]: <-- data [1024]
Aug 06 20:11:28.61: [30427]: <-- data [1024]
Aug 06 20:11:28.61: [30427]: <-- data [1026]
Aug 06 20:11:28.61: [30427]: <-- data [1025]
Aug 06 20:11:29.60: [30427]: <-- data [1028]
Aug 06 20:11:29.60: [30427]: <-- data [1032]
Aug 06 20:11:29.60: [30427]: <-- data [1029]
Aug 06 20:11:30.50: [30427]: <-- data [1024]
Aug 06 20:11:31.46: [30427]: <-- data [1024]
Aug 06 20:11:32.41: [30427]: <-- data [1024]
Aug 06 20:11:33.37: [30427]: <-- data [1026]
Aug 06 20:11:33.37: [30427]: <-- data [1026]
Aug 06 20:11:34.33: [30427]: <-- data [1026]
Aug 06 20:11:35.29: [30427]: <-- data [1025]
Aug 06 20:11:36.25: [30427]: <-- data [1028]
Aug 06 20:11:37.21: [30427]: <-- data [1024]
Aug 06 20:11:38.16: [30427]: <-- data [1026]
Aug 06 20:11:39.12: [30427]: <-- data [1024]
Aug 06 20:11:40.08: [30427]: <-- data [1025]
Aug 06 20:11:41.04: [30427]: <-- data [1026]
Aug 06 20:11:42.00: [30427]: <-- data [1025]
Aug 06 20:11:42.00: [30427]: <-- data [1024]
Aug 06 20:11:42.96: [30427]: <-- data [1024]
Aug 06 20:11:43.92: [30427]: <-- data [1024]
Aug 06 20:11:44.87: [30427]: <-- data [1024]
Aug 06 20:11:45.83: [30427]: <-- data [868]
Aug 06 20:11:46.79: [30427]: SENT 27492 bytes of data
Aug 06 20:11:46.79: [30427]: <-- data [1024]
Aug 06 20:11:47.75: [30427]: <-- data [1024]
Aug 06 20:11:47.75: [30427]: <-- data [1024]
Aug 06 20:11:48.71: [30427]: <-- data [1024]
Aug 06 20:11:49.67: [30427]: <-- data [1024]
Aug 06 20:11:50.63: [30427]: <-- data [1024]
Aug 06 20:11:51.59: [30427]: <-- data [1024]
Aug 06 20:11:52.55: [30427]: <-- data [128]
Aug 06 20:11:52.55: [30427]: SENT 7296 bytes of data
Aug 06 20:11:52.55: [30427]: SEND 1D RTC
Aug 06 20:11:52.55: [30427]: <-- data [29]
Aug 06 20:11:52.55: [30427]: <-- data [2]
Aug 06 20:11:52.55: [30427]: SEND end page
Aug 06 20:11:58.14: [30427]: -->
[54:]
Aug 06 20:11:58.14: [30427]: --> [2:OK]
Aug 06 20:11:58.14: [30427]: DELAY 95 ms
Aug 06 20:11:58.25: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:11:58.25: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:11:58.29: [30427]: --> [7:CONNECT]
Aug 06 20:11:58.29: [30427]: <-- data [3]
Aug 06 20:11:58.29: [30427]: <-- data [2]
Aug 06 20:11:59.50: [30427]: --> [2:OK]
Aug 06 20:11:59.50: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:11:59.76: [30427]: --> [7:CONNECT]
Aug 06 20:12:00.75: [30427]: --> [2:OK]
Aug 06 20:12:00.75: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:12:00.75: [30427]: SEND training at v.29 7200 bit/s
Aug 06 20:12:00.75: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:12:00.79: [30427]: --> [7:CONNECT]
Aug 06 20:12:00.79: [30427]: <-- data [23]
Aug 06 20:12:00.79: [30427]: <-- data [2]
Aug 06 20:12:02.48: [30427]: --> [7:CONNECT]
Aug 06 20:12:02.48: [30427]: <-- data [6]
Aug 06 20:12:02.48: [30427]: <-- data [2]
Aug 06 20:12:02.78: [30427]: --> [2:OK]
Aug 06 20:12:02.78: [30427]: DELAY 75 ms
Aug 06 20:12:02.87: [30427]: <-- [10:AT+FTM=72\r]
Aug 06 20:12:02.91: [30427]: --> [7:CONNECT]
Aug 06 20:12:02.91: [30427]: <-- data [1024]
Aug 06 20:12:02.91: [30427]: <-- data [326]
Aug 06 20:12:02.91: [30427]: <-- data [2]
Aug 06 20:12:04.94: [30427]: --> [2:OK]
Aug 06 20:12:04.94: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:12:05.21: [30427]: --> [7:CONNECT]
Aug 06 20:12:06.21: [30427]: --> [2:OK]
Aug 06 20:12:06.21: [30427]: TRAINING succeeded
Aug 06 20:12:06.21: [30427]: <-- [10:AT+FTM=72\r]
Aug 06 20:12:06.25: [30427]: --> [7:CONNECT]
Aug 06 20:12:06.25: [30427]: SEND begin page
Aug 06 20:12:06.26: [30427]: <-- data [1025]
Aug 06 20:12:06.26: [30427]: <-- data [1024]
Aug 06 20:12:06.26: [30427]: <-- data [1026]
Aug 06 20:12:06.26: [30427]: <-- data [1025]
Aug 06 20:12:06.26: [30427]: <-- data [1031]
Aug 06 20:12:07.25: [30427]: <-- data [1032]
Aug 06 20:12:07.25: [30427]: <-- data [1026]
Aug 06 20:12:07.25: [30427]: <-- data [1024]
Aug 06 20:12:08.29: [30427]: <-- data [1024]
Aug 06 20:12:09.44: [30427]: <-- data [1024]
Aug 06 20:12:10.59: [30427]: <-- data [1027]
Aug 06 20:12:11.75: [30427]: <-- data [1027]
Aug 06 20:12:12.90: [30427]: <-- data [1025]
Aug 06 20:12:14.06: [30427]: <-- data [1028]
Aug 06 20:12:15.21: [30427]: <-- data [1024]
Aug 06 20:12:16.36: [30427]: <-- data [1026]
Aug 06 20:12:17.52: [30427]: <-- data [1025]
Aug 06 20:12:18.65: [30427]: <-- data [1026]
Aug 06 20:12:19.80: [30427]: <-- data [1025]
Aug 06 20:12:20.96: [30427]: <-- data [1024]
Aug 06 20:12:22.11: [30427]: <-- data [132]
Aug 06 20:12:22.11: [30427]: SENT 20612 bytes of data
Aug 06 20:12:22.11: [30427]: <-- data [1024]
Aug 06 20:12:23.27: [30427]: <-- data [1024]
Aug 06 20:12:24.42: [30427]: <-- data [1024]
Aug 06 20:12:25.56: [30427]: <-- data [1024]
Aug 06 20:12:26.70: [30427]: <-- data [1024]
Aug 06 20:12:27.85: [30427]: <-- data [1024]
Aug 06 20:12:29.01: [30427]: <-- data [1024]
Aug 06 20:12:30.16: [30427]: <-- data [1004]
Aug 06 20:12:31.32: [30427]: SENT 8172 bytes of data
Aug 06 20:12:31.32: [30427]: SEND 1D RTC
Aug 06 20:12:31.32: [30427]: <-- data [29]
Aug 06 20:12:31.32: [30427]: <-- data [2]
Aug 06 20:12:31.32: [30427]: SEND end page
Aug 06 20:12:38.79: [30427]: -->
[48:]
Aug 06 20:12:38.79: [30427]: --> [2:OK]
Aug 06 20:12:38.79: [30427]: DELAY 95 ms
Aug 06 20:12:38.90: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:12:38.90: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:12:38.94: [30427]: --> [7:CONNECT]
Aug 06 20:12:38.94: [30427]: <-- data [3]
Aug 06 20:12:38.94: [30427]: <-- data [2]
Aug 06 20:12:40.15: [30427]: --> [2:OK]
Aug 06 20:12:40.15: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:12:40.41: [30427]: --> [7:CONNECT]
Aug 06 20:12:41.41: [30427]: --> [2:OK]
Aug 06 20:12:41.41: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:12:41.41: [30427]: SEND training at v.29 7200 bit/s
Aug 06 20:12:41.41: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:12:41.45: [30427]: --> [7:CONNECT]
Aug 06 20:12:41.45: [30427]: <-- data [23]
Aug 06 20:12:41.45: [30427]: <-- data [2]
Aug 06 20:12:43.14: [30427]: --> [7:CONNECT]
Aug 06 20:12:43.14: [30427]: <-- data [6]
Aug 06 20:12:43.14: [30427]: <-- data [2]
Aug 06 20:12:43.44: [30427]: --> [2:OK]
Aug 06 20:12:43.44: [30427]: DELAY 75 ms
Aug 06 20:12:43.53: [30427]: <-- [10:AT+FTM=72\r]
Aug 06 20:12:43.57: [30427]: --> [7:CONNECT]
Aug 06 20:12:43.57: [30427]: <-- data [1024]
Aug 06 20:12:43.57: [30427]: <-- data [326]
Aug 06 20:12:43.57: [30427]: <-- data [2]
Aug 06 20:12:45.60: [30427]: --> [2:OK]
Aug 06 20:12:45.60: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:12:45.86: [30427]: --> [7:CONNECT]
Aug 06 20:12:46.86: [30427]: --> [2:OK]
Aug 06 20:12:46.86: [30427]: TRAINING succeeded
Aug 06 20:12:46.86: [30427]: <-- [10:AT+FTM=72\r]
Aug 06 20:12:46.90: [30427]: --> [7:CONNECT]
Aug 06 20:12:46.90: [30427]: SEND begin page
Aug 06 20:12:46.91: [30427]: <-- data [1025]
Aug 06 20:12:46.91: [30427]: <-- data [1024]
Aug 06 20:12:46.91: [30427]: <-- data [1026]
Aug 06 20:12:46.91: [30427]: <-- data [1025]
Aug 06 20:12:46.91: [30427]: <-- data [1031]
Aug 06 20:12:47.90: [30427]: <-- data [1032]
Aug 06 20:12:47.90: [30427]: <-- data [1026]
Aug 06 20:12:47.90: [30427]: <-- data [1024]
Aug 06 20:12:48.94: [30427]: <-- data [1024]
Aug 06 20:12:50.09: [30427]: <-- data [1024]
Aug 06 20:12:51.24: [30427]: <-- data [1027]
Aug 06 20:12:52.40: [30427]: <-- data [1027]
Aug 06 20:12:53.55: [30427]: <-- data [1025]
Aug 06 20:12:54.71: [30427]: <-- data [1028]
Aug 06 20:12:55.86: [30427]: <-- data [1024]
Aug 06 20:12:57.01: [30427]: <-- data [1026]
Aug 06 20:12:58.17: [30427]: <-- data [1025]
Aug 06 20:12:59.30: [30427]: <-- data [1026]
Aug 06 20:13:00.45: [30427]: <-- data [1025]
Aug 06 20:13:01.61: [30427]: <-- data [1024]
Aug 06 20:13:02.76: [30427]: <-- data [132]
Aug 06 20:13:02.76: [30427]: SENT 20612 bytes of data
Aug 06 20:13:02.76: [30427]: <-- data [1024]
Aug 06 20:13:03.92: [30427]: <-- data [1024]
Aug 06 20:13:05.07: [30427]: <-- data [1024]
Aug 06 20:13:06.21: [30427]: <-- data [1024]
Aug 06 20:13:07.35: [30427]: <-- data [1024]
Aug 06 20:13:08.50: [30427]: <-- data [1024]
Aug 06 20:13:09.66: [30427]: <-- data [1024]
Aug 06 20:13:10.81: [30427]: <-- data [1004]
Aug 06 20:13:11.97: [30427]: SENT 8172 bytes of data
Aug 06 20:13:11.97: [30427]: SEND 1D RTC
Aug 06 20:13:11.97: [30427]: <-- data [29]
Aug 06 20:13:11.97: [30427]: <-- data [2]
Aug 06 20:13:11.97: [30427]: SEND end page
Aug 06 20:13:19.44: [30427]: -->
[48:]
Aug 06 20:13:19.44: [30427]: --> [2:OK]
Aug 06 20:13:19.44: [30427]: DELAY 95 ms
Aug 06 20:13:19.55: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:13:19.55: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:13:19.59: [30427]: --> [7:CONNECT]
Aug 06 20:13:19.59: [30427]: <-- data [3]
Aug 06 20:13:19.59: [30427]: <-- data [2]
Aug 06 20:13:20.80: [30427]: --> [2:OK]
Aug 06 20:13:20.80: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:13:21.06: [30427]: --> [7:CONNECT]
Aug 06 20:13:22.06: [30427]: --> [2:OK]
Aug 06 20:13:22.06: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:13:22.06: [30427]: SEND training at v.27ter 4800 bit/s
Aug 06 20:13:22.06: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:13:22.10: [30427]: --> [7:CONNECT]
Aug 06 20:13:22.10: [30427]: <-- data [23]
Aug 06 20:13:22.10: [30427]: <-- data [2]
Aug 06 20:13:23.79: [30427]: --> [7:CONNECT]
Aug 06 20:13:23.79: [30427]: <-- data [6]
Aug 06 20:13:23.79: [30427]: <-- data [2]
Aug 06 20:13:24.09: [30427]: --> [2:OK]
Aug 06 20:13:24.09: [30427]: DELAY 75 ms
Aug 06 20:13:24.18: [30427]: <-- [10:AT+FTM=48\r]
Aug 06 20:13:24.22: [30427]: --> [7:CONNECT]
Aug 06 20:13:24.22: [30427]: <-- data [900]
Aug 06 20:13:24.22: [30427]: <-- data [2]
Aug 06 20:13:26.77: [30427]: --> [2:OK]
Aug 06 20:13:26.77: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:13:27.02: [30427]: --> [7:CONNECT]
Aug 06 20:13:28.02: [30427]: --> [2:OK]
Aug 06 20:13:28.02: [30427]: TRAINING succeeded
Aug 06 20:13:28.02: [30427]: <-- [10:AT+FTM=48\r]
Aug 06 20:13:28.06: [30427]: --> [7:CONNECT]
Aug 06 20:13:28.06: [30427]: SEND begin page
Aug 06 20:13:28.07: [30427]: <-- data [1025]
Aug 06 20:13:28.07: [30427]: <-- data [1026]
Aug 06 20:13:28.07: [30427]: <-- data [1025]
Aug 06 20:13:28.07: [30427]: <-- data [1035]
Aug 06 20:13:28.07: [30427]: <-- data [1030]
Aug 06 20:13:29.06: [30427]: <-- data [1024]
Aug 06 20:13:29.06: [30427]: <-- data [1024]
Aug 06 20:13:29.06: [30427]: <-- data [1024]
Aug 06 20:13:31.97: [30427]: <-- data [1026]
Aug 06 20:13:33.54: [30427]: <-- data [1028]
Aug 06 20:13:35.11: [30427]: <-- data [1025]
Aug 06 20:13:36.68: [30427]: <-- data [1028]
Aug 06 20:13:38.26: [30427]: <-- data [1024]
Aug 06 20:13:39.82: [30427]: <-- data [351]
Aug 06 20:13:41.39: [30427]: SENT 13663 bytes of data
Aug 06 20:13:41.39: [30427]: <-- data [1026]
Aug 06 20:13:42.97: [30427]: <-- data [1025]
Aug 06 20:13:44.53: [30427]: <-- data [1027]
Aug 06 20:13:46.11: [30427]: <-- data [1024]
Aug 06 20:13:47.67: [30427]: <-- data [1024]
Aug 06 20:13:49.25: [30427]: <-- data [1024]
Aug 06 20:13:50.82: [30427]: <-- data [1024]
Aug 06 20:13:52.39: [30427]: <-- data [1024]
Aug 06 20:13:53.96: [30427]: <-- data [1024]
Aug 06 20:13:55.53: [30427]: <-- data [96]
Aug 06 20:13:55.53: [30427]: SENT 9312 bytes of data
Aug 06 20:13:55.53: [30427]: SEND 1D RTC
Aug 06 20:13:55.53: [30427]: <-- data [29]
Aug 06 20:13:55.53: [30427]: <-- data [2]
Aug 06 20:13:55.53: [30427]: SEND end page
Aug 06 20:14:07.45: [30427]: -->
[42:]
Aug 06 20:14:07.45: [30427]: --> [2:OK]
Aug 06 20:14:07.45: [30427]: DELAY 95 ms
Aug 06 20:14:07.56: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:14:07.56: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:14:07.60: [30427]: --> [7:CONNECT]
Aug 06 20:14:07.60: [30427]: <-- data [3]
Aug 06 20:14:07.60: [30427]: <-- data [2]
Aug 06 20:14:08.81: [30427]: --> [2:OK]
Aug 06 20:14:08.81: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:14:09.05: [30427]: --> [7:CONNECT]
Aug 06 20:14:10.04: [30427]: --> [2:OK]
Aug 06 20:14:10.04: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:14:10.04: [30427]: SEND training at v.27ter 4800 bit/s
Aug 06 20:14:10.04: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:14:10.08: [30427]: --> [7:CONNECT]
Aug 06 20:14:10.08: [30427]: <-- data [23]
Aug 06 20:14:10.08: [30427]: <-- data [2]
Aug 06 20:14:11.77: [30427]: --> [7:CONNECT]
Aug 06 20:14:11.77: [30427]: <-- data [6]
Aug 06 20:14:11.77: [30427]: <-- data [2]
Aug 06 20:14:12.08: [30427]: --> [2:OK]
Aug 06 20:14:12.08: [30427]: DELAY 75 ms
Aug 06 20:14:12.17: [30427]: <-- [10:AT+FTM=48\r]
Aug 06 20:14:12.21: [30427]: --> [7:CONNECT]
Aug 06 20:14:12.21: [30427]: <-- data [900]
Aug 06 20:14:12.21: [30427]: <-- data [2]
Aug 06 20:14:14.76: [30427]: --> [2:OK]
Aug 06 20:14:14.76: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:14:15.00: [30427]: --> [7:CONNECT]
Aug 06 20:14:16.00: [30427]: --> [2:OK]
Aug 06 20:14:16.00: [30427]: TRAINING succeeded
Aug 06 20:14:16.00: [30427]: <-- [10:AT+FTM=48\r]
Aug 06 20:14:16.04: [30427]: --> [7:CONNECT]
Aug 06 20:14:16.04: [30427]: SEND begin page
Aug 06 20:14:16.05: [30427]: <-- data [1025]
Aug 06 20:14:16.05: [30427]: <-- data [1026]
Aug 06 20:14:16.05: [30427]: <-- data [1025]
Aug 06 20:14:16.05: [30427]: <-- data [1035]
Aug 06 20:14:16.05: [30427]: <-- data [1030]
Aug 06 20:14:17.04: [30427]: <-- data [1024]
Aug 06 20:14:17.04: [30427]: <-- data [1024]
Aug 06 20:14:17.04: [30427]: <-- data [1024]
Aug 06 20:14:19.94: [30427]: <-- data [1026]
Aug 06 20:14:21.52: [30427]: <-- data [1028]
Aug 06 20:14:23.09: [30427]: <-- data [1025]
Aug 06 20:14:24.66: [30427]: <-- data [1028]
Aug 06 20:14:26.24: [30427]: <-- data [1024]
Aug 06 20:14:27.80: [30427]: <-- data [351]
Aug 06 20:14:29.37: [30427]: SENT 13663 bytes of data
Aug 06 20:14:29.37: [30427]: <-- data [1026]
Aug 06 20:14:30.94: [30427]: <-- data [1025]
Aug 06 20:14:32.51: [30427]: <-- data [1027]
Aug 06 20:14:34.08: [30427]: <-- data [1024]
Aug 06 20:14:35.65: [30427]: <-- data [1024]
Aug 06 20:14:37.23: [30427]: <-- data [1024]
Aug 06 20:14:38.79: [30427]: <-- data [1024]
Aug 06 20:14:40.37: [30427]: <-- data [1024]
Aug 06 20:14:41.94: [30427]: <-- data [1024]
Aug 06 20:14:43.51: [30427]: <-- data [96]
Aug 06 20:14:43.51: [30427]: SENT 9312 bytes of data
Aug 06 20:14:43.51: [30427]: SEND 1D RTC
Aug 06 20:14:43.51: [30427]: <-- data [29]
Aug 06 20:14:43.51: [30427]: <-- data [2]
Aug 06 20:14:43.51: [30427]: SEND end page
Aug 06 20:14:55.43: [30427]: -->
[42:]
Aug 06 20:14:55.43: [30427]: --> [2:OK]
Aug 06 20:14:55.43: [30427]: DELAY 95 ms
Aug 06 20:14:55.54: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:14:55.54: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:14:55.58: [30427]: --> [7:CONNECT]
Aug 06 20:14:55.58: [30427]: <-- data [3]
Aug 06 20:14:55.58: [30427]: <-- data [2]
Aug 06 20:14:56.79: [30427]: --> [2:OK]
Aug 06 20:14:56.79: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:14:57.06: [30427]: --> [7:CONNECT]
Aug 06 20:14:58.05: [30427]: --> [2:OK]
Aug 06 20:14:58.05: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:14:58.05: [30427]: SEND training at v.27ter fallback mode 2400
bit/s
Aug 06 20:14:58.05: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:14:58.09: [30427]: --> [7:CONNECT]
Aug 06 20:14:58.09: [30427]: <-- data [23]
Aug 06 20:14:58.09: [30427]: <-- data [2]
Aug 06 20:14:59.78: [30427]: --> [7:CONNECT]
Aug 06 20:14:59.78: [30427]: <-- data [6]
Aug 06 20:14:59.78: [30427]: <-- data [2]
Aug 06 20:15:00.07: [30427]: --> [2:OK]
Aug 06 20:15:00.07: [30427]: DELAY 75 ms
Aug 06 20:15:00.16: [30427]: <-- [10:AT+FTM=24\r]
Aug 06 20:15:00.20: [30427]: --> [7:CONNECT]
Aug 06 20:15:00.20: [30427]: <-- data [450]
Aug 06 20:15:00.20: [30427]: <-- data [2]
Aug 06 20:15:03.00: [30427]: --> [2:OK]
Aug 06 20:15:03.00: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:15:03.26: [30427]: --> [7:CONNECT]
Aug 06 20:15:04.26: [30427]: --> [2:OK]
Aug 06 20:15:04.26: [30427]: TRAINING succeeded
Aug 06 20:15:04.26: [30427]: <-- [10:AT+FTM=24\r]
Aug 06 20:15:04.30: [30427]: --> [7:CONNECT]
Aug 06 20:15:04.30: [30427]: SEND begin page
Aug 06 20:15:04.31: [30427]: <-- data [1026]
Aug 06 20:15:04.31: [30427]: <-- data [1026]
Aug 06 20:15:04.31: [30427]: <-- data [1035]
Aug 06 20:15:04.31: [30427]: <-- data [1030]
Aug 06 20:15:05.30: [30427]: <-- data [1024]
Aug 06 20:15:05.30: [30427]: <-- data [1024]
Aug 06 20:15:05.30: [30427]: <-- data [613]
Aug 06 20:15:05.30: [30427]: SENT 6757 bytes of data
Aug 06 20:15:05.30: [30427]: <-- data [1027]
Aug 06 20:15:05.31: [30427]: <-- data [1027]
Aug 06 20:15:11.04: [30427]: <-- data [1025]
Aug 06 20:15:16.80: [30427]: <-- data [1028]
Aug 06 20:15:19.67: [30427]: <-- data [1024]
Aug 06 20:15:22.55: [30427]: <-- data [1026]
Aug 06 20:15:25.42: [30427]: <-- data [728]
Aug 06 20:15:28.30: [30427]: SENT 6871 bytes of data
Aug 06 20:15:28.30: [30427]: <-- data [1027]
Aug 06 20:15:31.17: [30427]: <-- data [1024]
Aug 06 20:15:34.05: [30427]: <-- data [1024]
Aug 06 20:15:39.80: [30427]: <-- data [727]
Aug 06 20:15:39.80: [30427]: SENT 3799 bytes of data
Aug 06 20:15:39.80: [30427]: SEND 1D RTC
Aug 06 20:15:39.80: [30427]: <-- data [29]
Aug 06 20:15:39.80: [30427]: <-- data [2]
Aug 06 20:15:39.80: [30427]: SEND end page
Aug 06 20:16:03.79: [30427]: --> [32:]
Aug 06 20:16:03.79: [30427]: --> [2:OK]
Aug 06 20:16:03.79: [30427]: DELAY 95 ms
Aug 06 20:16:03.90: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:16:03.90: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:16:03.94: [30427]: --> [7:CONNECT]
Aug 06 20:16:03.94: [30427]: <-- data [3]
Aug 06 20:16:03.94: [30427]: <-- data [2]
Aug 06 20:16:05.15: [30427]: --> [2:OK]
Aug 06 20:16:05.15: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:16:05.41: [30427]: --> [7:CONNECT]
Aug 06 20:16:06.41: [30427]: --> [2:OK]
Aug 06 20:16:06.41: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:16:06.41: [30427]: SEND training at v.27ter fallback mode 2400
bit/s
Aug 06 20:16:06.41: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:16:06.45: [30427]: --> [7:CONNECT]
Aug 06 20:16:06.45: [30427]: <-- data [23]
Aug 06 20:16:06.45: [30427]: <-- data [2]
Aug 06 20:16:08.14: [30427]: --> [7:CONNECT]
Aug 06 20:16:08.14: [30427]: <-- data [6]
Aug 06 20:16:08.14: [30427]: <-- data [2]
Aug 06 20:16:08.44: [30427]: --> [2:OK]
Aug 06 20:16:08.44: [30427]: DELAY 75 ms
Aug 06 20:16:08.53: [30427]: <-- [10:AT+FTM=24\r]
Aug 06 20:16:08.57: [30427]: --> [7:CONNECT]
Aug 06 20:16:08.57: [30427]: <-- data [450]
Aug 06 20:16:08.57: [30427]: <-- data [2]
Aug 06 20:16:11.37: [30427]: --> [2:OK]
Aug 06 20:16:11.37: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:16:11.63: [30427]: --> [7:CONNECT]
Aug 06 20:16:12.63: [30427]: --> [2:OK]
Aug 06 20:16:12.63: [30427]: TRAINING succeeded
Aug 06 20:16:12.63: [30427]: <-- [10:AT+FTM=24\r]
Aug 06 20:16:12.67: [30427]: --> [7:CONNECT]
Aug 06 20:16:12.67: [30427]: SEND begin page
Aug 06 20:16:12.68: [30427]: <-- data [1026]
Aug 06 20:16:12.68: [30427]: <-- data [1026]
Aug 06 20:16:12.68: [30427]: <-- data [1035]
Aug 06 20:16:12.68: [30427]: <-- data [1030]
Aug 06 20:16:13.67: [30427]: <-- data [1024]
Aug 06 20:16:13.67: [30427]: <-- data [1024]
Aug 06 20:16:13.67: [30427]: <-- data [613]
Aug 06 20:16:13.67: [30427]: SENT 6757 bytes of data
Aug 06 20:16:13.67: [30427]: <-- data [1027]
Aug 06 20:16:13.67: [30427]: <-- data [1027]
Aug 06 20:16:19.41: [30427]: <-- data [1025]
Aug 06 20:16:25.17: [30427]: <-- data [1028]
Aug 06 20:16:28.04: [30427]: <-- data [1024]
Aug 06 20:16:30.92: [30427]: <-- data [1026]
Aug 06 20:16:33.79: [30427]: <-- data [728]
Aug 06 20:16:36.67: [30427]: SENT 6871 bytes of data
Aug 06 20:16:36.67: [30427]: <-- data [1027]
Aug 06 20:16:39.54: [30427]: <-- data [1024]
Aug 06 20:16:42.41: [30427]: <-- data [1024]
Aug 06 20:16:48.16: [30427]: <-- data [727]
Aug 06 20:16:48.16: [30427]: SENT 3799 bytes of data
Aug 06 20:16:48.16: [30427]: SEND 1D RTC
Aug 06 20:16:48.16: [30427]: <-- data [29]
Aug 06 20:16:48.16: [30427]: <-- data [2]
Aug 06 20:16:48.16: [30427]: SEND end page
Aug 06 20:17:12.16: [30427]: --> [32:]
Aug 06 20:17:12.16: [30427]: --> [2:OK]
Aug 06 20:17:12.16: [30427]: DELAY 95 ms
Aug 06 20:17:12.27: [30427]: SEND send EOP (no more pages or documents)
Aug 06 20:17:12.27: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:17:12.31: [30427]: --> [7:CONNECT]
Aug 06 20:17:12.31: [30427]: <-- data [3]
Aug 06 20:17:12.31: [30427]: <-- data [2]
Aug 06 20:17:13.51: [30427]: --> [2:OK]
Aug 06 20:17:13.51: [30427]: <-- [9:AT+FRH=3\r]
Aug 06 20:17:13.75: [30427]: --> [7:CONNECT]
Aug 06 20:17:14.75: [30427]: --> [2:OK]
Aug 06 20:17:14.75: [30427]: SEND recv RTN (retrain negative)
Aug 06 20:17:14.76: [30427]: SEND: Unable to transmit page (NAK at all
possible signalling rates); Giving up after 3 attempts to send same page
"docq/doc393.ps;00", dirnum 0
Aug 06 20:17:14.76: [30427]: <-- [9:AT+FTH=3\r]
Aug 06 20:17:14.80: [30427]: --> [7:CONNECT]
Aug 06 20:17:14.80: [30427]: <-- data [3]
Aug 06 20:17:14.80: [30427]: <-- data [2]
Aug 06 20:17:16.00: [30427]: --> [2:OK]
Aug 06 20:17:16.00: [30427]: <-- [5:ATH0\r]
Aug 06 20:17:16.11: [30427]: --> [2:OK]
Aug 06 20:17:16.11: [30427]: SESSION END

Does anybody know how to fix this problem?

Cheers,
Lars Denzer