[hylafax-users] TRAINING failed

["Giedrius Augys" <voipas@xxxxxxxxx>]

Hi,

  I've newest hylafax and IAXmodem versions. But I can't to send faxes to some numbers. I've attached you hylafax log .
Thanks for your help.

--
Pagarbiai / Best Regards,
Giedrius Augys

Aug 21 00:36:41.96: [29166]: SESSION BEGIN 000003703 +180037052044612
Aug 21 00:36:41.96: [29166]: HylaFAX (tm) Version 5.2.7
Aug 21 00:36:41.96: [29166]: SEND FAX: JOB 586 DEST 37052044612 COMMID 000003703 DEVICE '/dev/ttyIAX0' FROM 'giedrius.augys <giedrius.augys@xxxxxxxxxxx>' USER root
Aug 21 00:36:41.96: [29166]: STATE CHANGE: RUNNING -> SENDING
Aug 21 00:36:41.96: [29166]: <-- [12:AT+FCLASS=1\r]
Aug 21 00:36:41.96: [29166]: --> [2:OK]
Aug 21 00:36:41.98: [29166]: DIAL 37052044612
Aug 21 00:36:41.98: [29166]: <-- [18:ATX3DT37052044612\r]
Aug 21 00:36:56.82: [29166]: --> [7:CONNECT]
Aug 21 00:36:58.04: [29166]: --> HDLC<19:FF C0 04 00 00 88 01 00 51 12 00 00 00 01 01 01 00 36 AA>
Aug 21 00:36:58.04: [29166]: --> [2:OK]
Aug 21 00:36:58.04: [29166]: REMOTE NSF "00 00 11 80 00 8A 48 00 00 00 80 80 80 00"
Aug 21 00:36:58.04: [29166]: NSF remote fax equipment: Canon Laser Class 2060
Aug 21 00:36:58.04: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:36:58.74: [29166]: --> [7:CONNECT]
Aug 21 00:36:58.74: [29166]: --> HDLC<25:FF C0 02 4C 8C 6C 2C 2C EC 4C 04 AC 04 0C EC CC D4 04 04 04 04 04 04 1E 8D>
Aug 21 00:36:58.74: [29166]: --> [2:OK]
Aug 21 00:36:58.74: [29166]: REMOTE CSI "+370 5 2744612"
Aug 21 00:36:58.74: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:36:59.18: [29166]: --> [7:CONNECT]
Aug 21 00:36:59.18: [29166]: --> HDLC<15:FF C8 01 00 73 51 23 01 A9 01 01 01 04 3F D8>
Aug 21 00:36:59.22: [29166]: --> [2:OK]
Aug 21 00:36:59.22: [29166]: REMOTE best rate 9600 bit/s
Aug 21 00:36:59.22: [29166]: REMOTE max A3 page width (303 mm)
Aug 21 00:36:59.22: [29166]: REMOTE max unlimited page length
Aug 21 00:36:59.22: [29166]: REMOTE best vres R16 x 15.4 line/mm
Aug 21 00:36:59.22: [29166]: REMOTE format support: MH, MR, MMR, JBIG
Aug 21 00:36:59.22: [29166]: REMOTE supports T.30 Annex A, 256-byte ECM
Aug 21 00:36:59.22: [29166]: REMOTE best 20 ms/scanline
Aug 21 00:36:59.22: [29166]: USE 9600 bit/s
Aug 21 00:36:59.22: [29166]: USE error correction mode
Aug 21 00:36:59.22: [29166]: SEND file "docq/doc735.pdf;f1"
Aug 21 00:36:59.22: [29166]: USE A4 page width (215 mm)
Aug 21 00:36:59.22: [29166]: USE unlimited page length
Aug 21 00:36:59.22: [29166]: USE 7.7 line/mm
Aug 21 00:36:59.22: [29166]: USE 2-D MMR
Aug 21 00:36:59.22: [29166]: USE 0 ms/scanline
Aug 21 00:36:59.22: [29166]: SEND training at v.29 9600 bit/s
Aug 21 00:36:59.22: [29166]: <-- [9:AT+FRS=7\r]
Aug 21 00:36:59.30: [29166]: --> [2:OK]
Aug 21 00:36:59.30: [29166]: <-- [9:AT+FTH=3\r]
Aug 21 00:36:59.32: [29166]: --> [7:CONNECT]
Aug 21 00:36:59.32: [29166]: <-- HDLC<23:FF C0 C2 CC 4C AC 0C EC CC D4 04 76 F6 66 86 96 26 A6 B2 04 C2 CA 52>
Aug 21 00:36:59.32: [29166]: <-- data [23]
Aug 21 00:36:59.32: [29166]: <-- data [2]
Aug 21 00:37:00.86: [29166]: --> [7:CONNECT]
Aug 21 00:37:00.86: [29166]: <-- HDLC<7:FF C8 C1 00 62 1F 22>
Aug 21 00:37:00.86: [29166]: <-- data [7]
Aug 21 00:37:00.86: [29166]: <-- data [2]
Aug 21 00:37:01.26: [29166]: --> [2:OK]
Aug 21 00:37:01.26: [29166]: <-- [9:AT+FTS=7\r]
Aug 21 00:37:01.36: [29166]: --> [2:OK]
Aug 21 00:37:01.36: [29166]: <-- [10:AT+FTM=96\r]
Aug 21 00:37:01.38: [29166]: --> [7:CONNECT]
Aug 21 00:37:01.38: [29166]: DELAY 400 ms
Aug 21 00:37:01.78: [29166]: <-- data [1024]
Aug 21 00:37:01.78: [29166]: <-- data [776]
Aug 21 00:37:01.78: [29166]: <-- data [2]
Aug 21 00:37:03.34: [29166]: --> [2:OK]
Aug 21 00:37:03.34: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:37:03.58: [29166]: --> [7:CONNECT]
Aug 21 00:37:13.58: [29166]: MODEM TIMEOUT: receiving HDLC frame data
Aug 21 00:37:13.58: [29166]: <-- data [1]
Aug 21 00:37:13.59: [29166]: --> [2:]
Aug 21 00:37:13.59: [29166]: --> [2:OK]
Aug 21 00:37:13.59: [29166]: <-- [9:AT+FRS=7\r]
Aug 21 00:37:14.79: [29166]: --> [2:OK]
Aug 21 00:37:14.79: [29166]: SEND training at v.29 7200 bit/s
Aug 21 00:37:14.79: [29166]: <-- [9:AT+FTH=3\r]
Aug 21 00:37:14.81: [29166]: --> [7:CONNECT]
Aug 21 00:37:14.81: [29166]: <-- HDLC<23:FF C0 C2 CC 4C AC 0C EC CC D4 04 76 F6 66 86 96 26 A6 B2 04 C2 CA 52>
Aug 21 00:37:14.81: [29166]: <-- data [23]
Aug 21 00:37:14.81: [29166]: <-- data [2]
Aug 21 00:37:16.35: [29166]: --> [7:CONNECT]
Aug 21 00:37:16.35: [29166]: <-- HDLC<7:FF C8 C1 00 72 1F 22>
Aug 21 00:37:16.35: [29166]: <-- data [7]
Aug 21 00:37:16.35: [29166]: <-- data [2]
Aug 21 00:37:16.75: [29166]: --> [2:OK]
Aug 21 00:37:16.75: [29166]: <-- [9:AT+FTS=7\r]
Aug 21 00:37:16.85: [29166]: --> [2:OK]
Aug 21 00:37:16.85: [29166]: <-- [10:AT+FTM=72\r]
Aug 21 00:37:16.87: [29166]: --> [7:CONNECT]
Aug 21 00:37:16.87: [29166]: DELAY 400 ms
Aug 21 00:37:17.27: [29166]: <-- data [1024]
Aug 21 00:37:17.27: [29166]: <-- data [326]
Aug 21 00:37:17.27: [29166]: <-- data [2]
Aug 21 00:37:18.83: [29166]: --> [2:OK]
Aug 21 00:37:18.83: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:37:21.93: [29166]: --> [0:]
Aug 21 00:37:21.93: [29166]: MODEM <Empty line>
Aug 21 00:37:21.93: [29166]: MODEM TIMEOUT: waiting for v.21 carrier
Aug 21 00:37:21.93: [29166]: <-- data [1]
Aug 21 00:37:21.93: [29166]: --> [2:]
Aug 21 00:37:21.93: [29166]: --> [2:OK]
Aug 21 00:37:21.93: [29166]: <-- [9:AT+FRS=7\r]
Aug 21 00:37:30.25: [29166]: --> [2:OK]
Aug 21 00:37:30.25: [29166]: SEND training at v.27ter 4800 bit/s
Aug 21 00:37:30.25: [29166]: <-- [9:AT+FTH=3\r]
Aug 21 00:37:30.27: [29166]: --> [7:CONNECT]
Aug 21 00:37:30.27: [29166]: <-- HDLC<23:FF C0 C2 CC 4C AC 0C EC CC D4 04 76 F6 66 86 96 26 A6 B2 04 C2 CA 52>
Aug 21 00:37:30.27: [29166]: <-- data [23]
Aug 21 00:37:30.27: [29166]: <-- data [2]
Aug 21 00:37:31.81: [29166]: --> [7:CONNECT]
Aug 21 00:37:31.81: [29166]: <-- HDLC<7:FF C8 C1 00 52 1F 22>
Aug 21 00:37:31.81: [29166]: <-- data [7]
Aug 21 00:37:31.81: [29166]: <-- data [2]
Aug 21 00:37:32.21: [29166]: --> [2:OK]
Aug 21 00:37:32.21: [29166]: <-- [9:AT+FTS=7\r]
Aug 21 00:37:32.31: [29166]: --> [2:OK]
Aug 21 00:37:32.31: [29166]: <-- [10:AT+FTM=48\r]
Aug 21 00:37:32.33: [29166]: --> [7:CONNECT]
Aug 21 00:37:32.33: [29166]: DELAY 400 ms
Aug 21 00:37:32.73: [29166]: <-- data [900]
Aug 21 00:37:32.73: [29166]: <-- data [2]
Aug 21 00:37:34.61: [29166]: --> [2:OK]
Aug 21 00:37:34.61: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:37:34.89: [29166]: --> [7:CONNECT]
Aug 21 00:37:44.89: [29166]: MODEM TIMEOUT: receiving HDLC frame data
Aug 21 00:37:44.89: [29166]: <-- data [1]
Aug 21 00:37:44.90: [29166]: --> [2:]
Aug 21 00:37:44.90: [29166]: --> [2:OK]
Aug 21 00:37:44.90: [29166]: <-- [9:AT+FRS=7\r]
Aug 21 00:37:46.08: [29166]: --> [2:OK]
Aug 21 00:37:46.08: [29166]: SEND training at v.27ter fallback mode 2400 bit/s
Aug 21 00:37:46.08: [29166]: <-- [9:AT+FTH=3\r]
Aug 21 00:37:46.10: [29166]: --> [7:CONNECT]
Aug 21 00:37:46.10: [29166]: <-- HDLC<23:FF C0 C2 CC 4C AC 0C EC CC D4 04 76 F6 66 86 96 26 A6 B2 04 C2 CA 52>
Aug 21 00:37:46.10: [29166]: <-- data [23]
Aug 21 00:37:46.10: [29166]: <-- data [2]
Aug 21 00:37:47.64: [29166]: --> [7:CONNECT]
Aug 21 00:37:47.64: [29166]: <-- HDLC<7:FF C8 C1 00 42 1F 22>
Aug 21 00:37:47.64: [29166]: <-- data [7]
Aug 21 00:37:47.64: [29166]: <-- data [2]
Aug 21 00:37:48.04: [29166]: --> [2:OK]
Aug 21 00:37:48.04: [29166]: <-- [9:AT+FTS=7\r]
Aug 21 00:37:48.14: [29166]: --> [2:OK]
Aug 21 00:37:48.14: [29166]: <-- [10:AT+FTM=24\r]
Aug 21 00:37:48.16: [29166]: --> [7:CONNECT]
Aug 21 00:37:48.16: [29166]: DELAY 400 ms
Aug 21 00:37:48.56: [29166]: <-- data [450]
Aug 21 00:37:48.56: [29166]: <-- data [2]
Aug 21 00:37:50.67: [29166]: --> [2:OK]
Aug 21 00:37:50.68: [29166]: <-- [9:AT+FRH=3\r]
Aug 21 00:37:50.98: [29166]: --> [7:CONNECT]
Aug 21 00:38:00.98: [29166]: MODEM TIMEOUT: receiving HDLC frame data
Aug 21 00:38:00.98: [29166]: <-- data [1]
Aug 21 00:38:00.98: [29166]: --> [2:]
Aug 21 00:38:00.98: [29166]: --> [2:OK]
Aug 21 00:38:00.98: [29166]: <-- [9:AT+FRS=7\r]
Aug 21 00:38:02.16: [29166]: --> [2:OK]
Aug 21 00:38:02.16: [29166]: TRAINING failed
Aug 21 00:38:02.16: [29166]: <-- [9:AT+FTH=3\r]
Aug 21 00:38:02.18: [29166]: --> [7:CONNECT]
Aug 21 00:38:02.18: [29166]: <-- HDLC<3:FF C8 DF>
Aug 21 00:38:02.18: [29166]: <-- data [3]
Aug 21 00:38:02.18: [29166]: <-- data [2]
Aug 21 00:38:03.26: [29166]: --> [2:OK]
Aug 21 00:38:03.26: [29166]: MODEM input buffering enabled
Aug 21 00:38:04.26: [29166]: <-- [5:ATH0\r]
Aug 21 00:38:04.38: [29166]: --> [2:OK]
Aug 21 00:38:04.38: [29166]: MODEM set DTR OFF
Aug 21 00:38:04.38: [29166]: MODEM set baud rate: 0 baud (flow control unchanged)
Aug 21 00:38:04.38: [29166]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Aug 21 00:38:04.38: [29166]: SESSION END