[hylafax-users] MODEM TIMEOUT: waiting for v.21 carrier

["Giedrius Augys" <voipas@xxxxxxxxx>]

Can somebody help me to solve the problem. Using telecom line, I can successful sen faxes to this destination, but using hylafax and iaxmodem - I can't. 

This is the log:

Jun 27 11:47:44.96: [11282]: SESSION BEGIN 000001996 +180037052045323
Jun 27 11:47:44.96: [11282]: HylaFAX (tm) Version 5.2.2
Jun 27 11:47:44.96: [11282]: SEND FAX: JOB 266 DEST 37052045323 COMMID 000001996 DEVICE '/dev/ttyIAX12' FROM 'info <info@xxxxxx>' USER root
Jun 27 11:47:44.96: [11282]: STATE CHANGE: RUNNING -> SENDING
Jun 27 11:47:44.96: [11282]: <-- [12:AT+FCLASS=1\r]
Jun 27 11:47:44.96: [11282]: --> [2:OK]
Jun 27 11:47:44.98: [11282]: DIAL 37052045323
Jun 27 11:47:44.98: [11282]: <-- [18:ATX3DT37052045323\r]
Jun 27 11:48:03.16: [11282]: --> [7:CONNECT]
Jun 27 11:48:04.24: [11282]: --> HDLC<13:FF C0 04 B5 00 6C 05 00 00 00 00 1C 75>
Jun 27 11:48:04.24: [11282]: --> [2:OK]
Jun 27 11:48:04.24: [11282]: REMOTE NSF "AD 00 36 A0 00 00 00 00"
Jun 27 11:48:04.24: [11282]: NSF remote fax equipment: HP
Jun 27 11:48:04.24: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:04.94: [11282]: --> [7:CONNECT]
Jun 27 11:48:04.94: [11282]: --> HDLC<25:FF C0 02 CC 4C CC AC 2C 0C 4C AC 1C 04 04 04 04 04 04 04 04 04 04 04 36 09>
Jun 27 11:48:04.94: [11282]: --> [2:OK]
Jun 27 11:48:04.94: [11282]: REMOTE CSI "852045323"
Jun 27 11:48:04.94: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:05.38: [11282]: --> [7:CONNECT]
Jun 27 11:48:05.38: [11282]: --> HDLC<15:FF C8 01 04 77 1F 23 01 49 01 01 19 00 97 91>
Jun 27 11:48:05.50: [11282]: --> [2:OK]
Jun 27 11:48:05.50: [11282]: REMOTE best rate 33600 bit/s
Jun 27 11:48:05.50: [11282]: REMOTE max A4 page width (215 mm)
Jun 27 11:48:05.50: [11282]: REMOTE max unlimited page length
Jun 27 11:48:05.50: [11282]: REMOTE best vres 300 x 300 dpi
Jun 27 11:48:05.50: [11282]: REMOTE format support: MH, MR, MMR, JPEG Full-Color
Jun 27 11:48:05.50: [11282]: REMOTE supports T.30 Annex A, 256-byte ECM
Jun 27 11:48:05.50: [11282]: REMOTE best 0 ms/scanline
Jun 27 11:48:05.50: [11282]: USE 14400 bit/s
Jun 27 11:48:05.50: [11282]: USE error correction mode
Jun 27 11:48:05.50: [11282]: SEND file "docq/doc331.pdf;f1"
Jun 27 11:48:05.50: [11282]: USE A4 page width (215 mm)
Jun 27 11:48:05.50: [11282]: USE unlimited page length
Jun 27 11:48:05.50: [11282]: USE 7.7 line/mm
Jun 27 11:48:05.50: [11282]: USE 2-D MMR
Jun 27 11:48:05.50: [11282]: USE 0 ms/scanline
Jun 27 11:48:05.50: [11282]: SEND training at v.17 14400 bit/s
Jun 27 11:48:05.50: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:48:05.56: [11282]: --> [2:OK]
Jun 27 11:48:05.56: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:48:05.58: [11282]: --> [7:CONNECT]
Jun 27 11:48:05.58: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:48:05.58: [11282]: <-- data [23]
Jun 27 11:48:05.58: [11282]: <-- data [2]
Jun 27 11:48:07.12: [11282]: --> [7:CONNECT]
Jun 27 11:48:07.12: [11282]: <-- HDLC<7:FF C8 C1 00 46 1F 22>
Jun 27 11:48:07.12: [11282]: <-- data [7]
Jun 27 11:48:07.12: [11282]: <-- data [2]
Jun 27 11:48:07.52: [11282]: --> [2:OK]
Jun 27 11:48:07.52: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:48:07.62: [11282]: --> [2:OK]
Jun 27 11:48:07.62: [11282]: <-- [11:AT+FTM=145\r]
Jun 27 11:48:07.64: [11282]: --> [7:CONNECT]
Jun 27 11:48:07.64: [11282]: DELAY 400 ms
Jun 27 11:48:08.04: [11282]: <-- data [1024]
Jun 27 11:48:08.04: [11282]: <-- data [1024]
Jun 27 11:48:08.04: [11282]: <-- data [652]
Jun 27 11:48:08.04: [11282]: <-- data [2]
Jun 27 11:48:10.60: [11282]: --> [2:OK]
Jun 27 11:48:10.60: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:10.86: [11282]: --> [7:CONNECT]
Jun 27 11:48:20.86: [11282]: MODEM TIMEOUT: receiving HDLC frame data
Jun 27 11:48:20.86: [11282]: <-- data [1]
Jun 27 11:48:20.86: [11282]: --> [2:]
Jun 27 11:48:20.86: [11282]: --> [2:OK]
Jun 27 11:48:20.86: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:48:22.02: [11282]: --> [2:OK]
Jun 27 11:48:22.02: [11282]: SEND training at v.17 12000 bit/s
Jun 27 11:48:22.02: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:48:22.04: [11282]: --> [7:CONNECT]
Jun 27 11:48:22.04: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:48:22.04: [11282]: <-- data [23]
Jun 27 11:48:22.04: [11282]: <-- data [2]
Jun 27 11:48:23.58: [11282]: --> [7:CONNECT]
Jun 27 11:48:23.58: [11282]: <-- HDLC<7:FF C8 C1 00 56 1F 22>
Jun 27 11:48:23.58: [11282]: <-- data [7]
Jun 27 11:48:23.58: [11282]: <-- data [2]
Jun 27 11:48:23.98: [11282]: --> [2:OK]
Jun 27 11:48:23.98: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:48:24.08: [11282]: --> [2:OK]
Jun 27 11:48:24.08: [11282]: <-- [11:AT+FTM=121\r]
Jun 27 11:48:24.10: [11282]: --> [7:CONNECT]
Jun 27 11:48:24.10: [11282]: DELAY 400 ms
Jun 27 11:48:24.50: [11282]: <-- data [1024]
Jun 27 11:48:24.50: [11282]: <-- data [1024]
Jun 27 11:48:24.50: [11282]: <-- data [202]
Jun 27 11:48:24.50: [11282]: <-- data [2]
Jun 27 11:48:27.06: [11282]: --> [2:OK]
Jun 27 11:48:27.06: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:27.33: [11282]: --> [7:CONNECT]
Jun 27 11:48:37.33: [11282]: MODEM TIMEOUT: receiving HDLC frame data
Jun 27 11:48:37.33: [11282]: <-- data [1]
Jun 27 11:48:37.33: [11282]: --> [2:]
Jun 27 11:48:37.33: [11282]: --> [2:OK]
Jun 27 11:48:37.33: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:48:38.51: [11282]: --> [2:OK]
Jun 27 11:48:38.51: [11282]: SEND training at v.29 9600 bit/s
Jun 27 11:48:38.51: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:48:38.53: [11282]: --> [7:CONNECT]
Jun 27 11:48:38.53: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:48:38.53: [11282]: <-- data [23]
Jun 27 11:48:38.53: [11282]: <-- data [2]
Jun 27 11:48:40.05: [11282]: --> [7:CONNECT]
Jun 27 11:48:40.05: [11282]: <-- HDLC<7:FF C8 C1 00 62 1F 22>
Jun 27 11:48:40.05: [11282]: <-- data [7]
Jun 27 11:48:40.05: [11282]: <-- data [2]
Jun 27 11:48:40.45: [11282]: --> [2:OK]
Jun 27 11:48:40.45: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:48:40.55: [11282]: --> [2:OK]
Jun 27 11:48:40.55: [11282]: <-- [10:AT+FTM=96\r]
Jun 27 11:48:40.57: [11282]: --> [7:CONNECT]
Jun 27 11:48:40.57: [11282]: DELAY 400 ms
Jun 27 11:48:40.97: [11282]: <-- data [1024]
Jun 27 11:48:40.97: [11282]: <-- data [776]
Jun 27 11:48:40.97: [11282]: <-- data [2]
Jun 27 11:48:42.51: [11282]: --> [2:OK]
Jun 27 11:48:42.51: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:45.61: [11282]: --> [0:]
Jun 27 11:48:45.61: [11282]: MODEM <Empty line>
Jun 27 11:48:45.61: [11282]: MODEM TIMEOUT: waiting for v.21 carrier
Jun 27 11:48:45.61: [11282]: <-- data [1]
Jun 27 11:48:45.63: [11282]: --> [2:OK]
Jun 27 11:48:45.63: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:48:45.65: [11282]: --> [2:OK]
Jun 27 11:48:45.65: [11282]: SEND training at v.29 7200 bit/s
Jun 27 11:48:45.65: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:48:45.67: [11282]: --> [7:CONNECT]
Jun 27 11:48:45.67: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:48:45.67: [11282]: <-- data [23]
Jun 27 11:48:45.67: [11282]: <-- data [2]
Jun 27 11:48:47.21: [11282]: --> [7:CONNECT]
Jun 27 11:48:47.21: [11282]: <-- HDLC<7:FF C8 C1 00 72 1F 22>
Jun 27 11:48:47.21: [11282]: <-- data [7]
Jun 27 11:48:47.21: [11282]: <-- data [2]
Jun 27 11:48:47.61: [11282]: --> [2:OK]
Jun 27 11:48:47.61: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:48:47.71: [11282]: --> [2:OK]
Jun 27 11:48:47.71: [11282]: <-- [10:AT+FTM=72\r]
Jun 27 11:48:47.73: [11282]: --> [7:CONNECT]
Jun 27 11:48:47.73: [11282]: DELAY 400 ms
Jun 27 11:48:48.13: [11282]: <-- data [1024]
Jun 27 11:48:48.13: [11282]: <-- data [326]
Jun 27 11:48:48.13: [11282]: <-- data [2]
Jun 27 11:48:49.67: [11282]: --> [2:OK]
Jun 27 11:48:49.67: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:52.77: [11282]: --> [0:]
Jun 27 11:48:52.77: [11282]: MODEM <Empty line>
Jun 27 11:48:52.77: [11282]: MODEM TIMEOUT: waiting for v.21 carrier
Jun 27 11:48:52.77: [11282]: <-- data [1]
Jun 27 11:48:52.79: [11282]: --> [2:OK]
Jun 27 11:48:52.79: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:48:52.81: [11282]: --> [2:OK]
Jun 27 11:48:52.81: [11282]: SEND training at v.27ter 4800 bit/s
Jun 27 11:48:52.81: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:48:52.83: [11282]: --> [7:CONNECT]
Jun 27 11:48:52.83: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:48:52.83: [11282]: <-- data [23]
Jun 27 11:48:52.83: [11282]: <-- data [2]
Jun 27 11:48:54.37: [11282]: --> [7:CONNECT]
Jun 27 11:48:54.37: [11282]: <-- HDLC<7:FF C8 C1 00 52 1F 22>
Jun 27 11:48:54.37: [11282]: <-- data [7]
Jun 27 11:48:54.37: [11282]: <-- data [2]
Jun 27 11:48:54.77: [11282]: --> [2:OK]
Jun 27 11:48:54.77: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:48:54.87: [11282]: --> [2:OK]
Jun 27 11:48:54.87: [11282]: <-- [10:AT+FTM=48\r]
Jun 27 11:48:54.89: [11282]: --> [7:CONNECT]
Jun 27 11:48:54.89: [11282]: DELAY 400 ms
Jun 27 11:48:55.29: [11282]: <-- data [900]
Jun 27 11:48:55.29: [11282]: <-- data [2]
Jun 27 11:48:57.17: [11282]: --> [2:OK]
Jun 27 11:48:57.17: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:48:57.45: [11282]: --> [7:CONNECT]
Jun 27 11:49:07.45: [11282]: MODEM TIMEOUT: receiving HDLC frame data
Jun 27 11:49:07.45: [11282]: <-- data [1]
Jun 27 11:49:07.45: [11282]: --> [2:]
Jun 27 11:49:07.45: [11282]: --> [2:OK]
Jun 27 11:49:07.45: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:49:08.63: [11282]: --> [2:OK]
Jun 27 11:49:08.63: [11282]: SEND training at v.27ter fallback mode 2400 bit/s
Jun 27 11:49:08.63: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:49:08.65: [11282]: --> [7:CONNECT]
Jun 27 11:49:08.65: [11282]: <-- HDLC<23:FF C0 C2 CE 86 CE D6 86 66 04 34 CE 86 4E 86 D6 96 86 22 04 42 82 AA>
Jun 27 11:49:08.65: [11282]: <-- data [23]
Jun 27 11:49:08.65: [11282]: <-- data [2]
Jun 27 11:49:10.19: [11282]: --> [7:CONNECT]
Jun 27 11:49:10.19: [11282]: <-- HDLC<7:FF C8 C1 00 42 1F 22>
Jun 27 11:49:10.19: [11282]: <-- data [7]
Jun 27 11:49:10.19: [11282]: <-- data [2]
Jun 27 11:49:10.59: [11282]: --> [2:OK]
Jun 27 11:49:10.59: [11282]: <-- [9:AT+FTS=7\r]
Jun 27 11:49:10.69: [11282]: --> [2:OK]
Jun 27 11:49:10.69: [11282]: <-- [10:AT+FTM=24\r]
Jun 27 11:49:10.71: [11282]: --> [7:CONNECT]
Jun 27 11:49:10.71: [11282]: DELAY 400 ms
Jun 27 11:49:11.11: [11282]: <-- data [450]
Jun 27 11:49:11.11: [11282]: <-- data [2]
Jun 27 11:49:13.23: [11282]: --> [2:OK]
Jun 27 11:49:13.23: [11282]: <-- [9:AT+FRH=3\r]
Jun 27 11:49:13.51: [11282]: --> [7:CONNECT]
Jun 27 11:49:23.51: [11282]: MODEM TIMEOUT: receiving HDLC frame data
Jun 27 11:49:23.51: [11282]: <-- data [1]
Jun 27 11:49:23.52: [11282]: --> [2:]
Jun 27 11:49:23.52: [11282]: --> [2:OK]
Jun 27 11:49:23.52: [11282]: <-- [9:AT+FRS=7\r]
Jun 27 11:49:24.70: [11282]: --> [2:OK]
Jun 27 11:49:24.70: [11282]: TRAINING failed
Jun 27 11:49:24.70: [11282]: <-- [9:AT+FTH=3\r]
Jun 27 11:49:24.72: [11282]: --> [7:CONNECT]
Jun 27 11:49:24.72: [11282]: <-- HDLC<3:FF C8 DF>
Jun 27 11:49:24.72: [11282]: <-- data [3]
Jun 27 11:49:24.72: [11282]: <-- data [2]
Jun 27 11:49:25.80: [11282]: --> [2:OK]
Jun 27 11:49:25.80: [11282]: MODEM input buffering enabled
Jun 27 11:49:26.80: [11282]: <-- [5:ATH0\r]
Jun 27 11:49:26.92: [11282]: --> [2:OK]
Jun 27 11:49:26.92: [11282]: MODEM set DTR OFF
Jun 27 11:49:26.92: [11282]: MODEM set baud rate: 0 baud (flow control unchanged)
Jun 27 11:49:26.92: [11282]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Jun 27 11:49:26.92: [11282]: SESSION END


Thanks

-- 
Pagarbiai / Best Regards,
Giedrius Augys