I have a working (well, almost :D) setup of Trixbox CE 2.4 with IAXmodems running on the same machine, using SLIN codec. My Hylafax + Avantfax is on another machine (virtual machine located on a physical machine different from Trixbox) communicating by interceptty. We receive faxes on ISDN lines, my Trixbox machine is equipped with Sangoma A500D card.
Problem is, that 4 of 5 received faxes get corrupted. It looks like they get squisshed badly.
Feb 26 11:06:54.26: [17018]: SESSION BEGIN 000000060 48914843712
Feb 26 11:06:54.26: [17018]: HylaFAX (tm) Version 4.4.4
Feb 26 11:06:54.26: [17018]: CallID: "616568500" "MAKRO 616568500" "<NONE>" "s"
Feb 26 11:06:54.26: [17018]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
Feb 26 11:06:54.26: [17018]: <-- [4:ATA\r]
Feb 26 11:06:56.46: [17018]: --> [7:CONNECT]
Feb 26 11:06:56.46: [17018]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX02'
Feb 26 11:06:56.46: [17018]: STATE CHANGE: ANSWERING -> RECEIVING
Feb 26 11:06:56.46: [17018]: RECV FAX: begin
Feb 26 11:06:56.46: [17018]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 2C 74 2C
74 2C>
Feb 26 11:06:56.46: [17018]: <-- data [32]
Feb 26 11:06:56.46: [17018]: <-- data [2]
Feb 26 11:06:56.95: [17018]: --> [7:CONNECT]
Feb 26 11:06:56.95: [17018]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04 04 04 04 04 04 04 04 04 04 04>
Feb 26 11:06:56.95: [17018]: <-- data [23]
Feb 26 11:06:56.95: [17018]: <-- data [2]
Feb 26 11:06:57.55: [17018]: --> [7:CONNECT]
Feb 26 11:06:57.55: [17018]: <-- HDLC<13:FF C8 01 00 77 5F 23 01 FB C1 01 01 18>
Feb 26 11:06:57.55: [17018]: <-- data [13]
Feb 26 11:06:57.55: [17018]: <-- data [2]
Feb 26 11:06:58.04: [17018]: --> [2:OK]
Feb 26 11:06:58.04: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:06:58.43: [17018]: --> [7:CONNECT]
Feb 26 11:06:59.24: [17018]: --> HDLC<25:FF C0 C2 0C 0C AC 1C 6C AC 6C 04 04 04 04 04 04 04 04 04 04 04 04 04 B6 B1>
Feb 26 11:06:59.24: [17018]: --> [2:OK]
Feb 26 11:06:59.24: [17018]: REMOTE TSI "6568500"
Feb 26 11:06:59.24: [17018]: RECV recv TSI (sender id)
Feb 26 11:06:59.24: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:06:59.42: [17018]: --> [7:CONNECT]
Feb 26 11:06:59.42: [17018]: --> HDLC<9:FF C8 C1 00 61 1F 00 3E CD>
Feb 26 11:06:59.46: [17018]: --> [2:OK]
Feb 26 11:06:59.46: [17018]: REMOTE wants 9600 bit/s
Feb 26 11:06:59.46: [17018]: REMOTE wants A4 page width (215 mm)
Feb 26 11:06:59.46: [17018]: REMOTE wants unlimited page length
Feb 26 11:06:59.46: [17018]: REMOTE wants 3.85 line/mm
Feb 26 11:06:59.46: [17018]: REMOTE wants 2-D MR
Feb 26 11:06:59.46: [17018]: RECV recv DCS (command signal)
Feb 26 11:06:59.46: [17018]: RECV training at v.29 9600 bit/s
Feb 26 11:06:59.46: [17018]: MODEM set XON/XOFF/DRAIN: input ignored, output generated
Feb 26 11:06:59.46: [17018]: <-- [10:AT+FRM=96\r]
Feb 26 11:06:59.83: [17018]: --> [7:CONNECT]
Feb 26 11:07:00.71: [17018]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 26 11:07:00.71: [17018]: RECV: TCF 1832 bytes, 1% non-zero, 1806 zero-run
Feb 26 11:07:00.71: [17018]: --> [10:NO CARRIER]
Feb 26 11:07:00.71: [17018]: <-- [9:AT+FRS=7\r]
Feb 26 11:07:00.74: [17018]: --> [2:OK]
Feb 26 11:07:00.74: [17018]: TRAINING succeeded
Feb 26 11:07:00.74: [17018]: <-- [9:AT+FTH=3\r]
Feb 26 11:07:00.75: [17018]: --> [7:CONNECT]
Feb 26 11:07:00.75: [17018]: <-- HDLC<3:FF C8 21>
Feb 26 11:07:00.75: [17018]: <-- data [3]
Feb 26 11:07:00.75: [17018]: <-- data [2]
Feb 26 11:07:01.29: [17018]: --> [2:OK]
Feb 26 11:07:01.29: [17018]: <-- [10:AT+FRM=96\r]
Feb 26 11:07:01.91: [17018]: --> [7:CONNECT]
Feb 26 11:07:01.91: [17018]: MODEM input buffering enabled
Feb 26 11:07:01.91: [17018]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 26 11:07:01.91: [17018]: RECV: begin page
Feb 26 11:07:02.33: [17018]: RECV/CQ: Bad 1D pixel count, row 0, got 2273, expected 1728
Feb 26 11:07:02.66: [17018]: RECV/CQ: Invalid BlackTable code word, row 2, x 1683
Feb 26 11:07:02.66: [17018]: RECV/CQ: Bad 1D pixel count, row 2, got 1683, expected 1728
Feb 26 11:07:02.87: [17018]: RECV/CQ: Invalid WhiteTable code word, row 3, x 1446
Feb 26 11:07:02.87: [17018]: RECV/CQ: Bad 1D pixel count, row 3, got 1446, expected 1728
Feb 26 11:07:02.87: [17018]: RECV/CQ: Bad 1D pixel count, row 4, got 2012, expected 1728
Feb 26 11:07:03.28: [17018]: RECV/CQ: Bad 2D pixel count, row 5, got 1778, expected 1728
Feb 26 11:07:03.81: [17018]: RECV/CQ: Bad 1D pixel count, row 6, got 2552, expected 1728
Feb 26 11:07:04.03: [17018]: RECV/CQ: Bad 1D pixel count, row 7, got 1874, expected 1728
Feb 26 11:07:04.03: [17018]: RECV/CQ: Bad 1D pixel count, row 8, got 1794, expected 1728
Feb 26 11:07:04.34: [17018]: RECV/CQ: Bad 2D pixel count, row 9, got 1729, expected 1728
Feb 26 11:07:04.56: [17018]: RECV/CQ: Bad 1D pixel count, row 10, got 1825, expected 1728
Feb 26 11:07:04.86: [17018]: RECV/CQ: Bad 1D pixel count, row 11, got 2901, expected 1728
Feb 26 11:07:04.86: [17018]: RECV/CQ: Bad 1D pixel count, row 12, got 2097, expected 1728
Feb 26 11:07:05.40: [17018]: RECV/CQ: Invalid EOL code word, row 13, x 139
Feb 26 11:07:05.40: [17018]: RECV/CQ: Bad 2D pixel count, row 13, got 139, expected 1728
Feb 26 11:07:05.40: [17018]: RECV/CQ: Bad 1D pixel count, row 14, got 2162, expected 1728
Feb 26 11:07:05.50: [17018]: RECV/CQ: Bad 2D pixel count, row 16, got 1737, expected 1728
Feb 26 11:07:05.81: [17018]: RECV/CQ: Bad 2D pixel count, row 17, got 2575, expected 1728
Feb 26 11:07:06.02: [17018]: RECV/CQ: Bad 2D pixel count, row 19, got 1729, expected 1728
Feb 26 11:07:06.55: [17018]: RECV/CQ: Bad 1D pixel count, row 22, got 2269, expected 1728
Feb 26 11:07:06.77: [17018]: RECV/CQ: Bad 1D pixel count, row 23, got 2432, expected 1728
Feb 26 11:07:07.08: [17018]: RECV/CQ: Bad 1D pixel count, row 25, got 1795, expected 1728
Feb 26 11:07:07.37: [17018]: RECV/CQ: Bad 1D pixel count, row 26, got 2965, expected 1728
Feb 26 11:07:08.88: [17018]: RECV/CQ: Bad 1D pixel count, row 30, got 1768, expected 1728
Feb 26 11:07:09.36: [17018]: RECV/CQ: Bad 1D pixel count, row 31, got 1737, expected 1728
Feb 26 11:07:09.68: [17018]: RECV/CQ: Bad 1D pixel count, row 32, got 2654, expected 1728
Feb 26 11:07:09.84: [17018]: RECV/CQ: Bad 1D pixel count, row 33, got 1731, expected 1728
Feb 26 11:07:10.21: [17018]: RECV/CQ: Invalid 2D code word, row 34, x 1512
Feb 26 11:07:10.21: [17018]: RECV/CQ: Bad 2D pixel count, row 34, got 1512, expected 1728
Feb 26 11:07:11.05: [17018]: RECV/CQ: Bad 2D pixel count, row 36, got 2071, expected 1728
Feb 26 11:07:11.36: [17018]: RECV/CQ: Bad 1D pixel count, row 38, got 2072, expected 1728
Feb 26 11:07:11.36: [17018]: RECV/CQ: Invalid BlackTable code word, row 39, x 1056
Feb 26 11:07:11.36: [17018]: RECV/CQ: Bad 1D pixel count, row 39, got 1056, expected 1728
Feb 26 11:07:11.48: [17018]: RECV/CQ: Bad 2D pixel count, row 40, got 1729, expected 1728
Feb 26 11:07:11.79: [17018]: RECV/CQ: Bad 1D pixel count, row 41, got 1734, expected 1728
Feb 26 11:07:12.23: [17018]: RECV/CQ: Bad 1D pixel count, row 42, got 1729, expected 1728
Feb 26 11:07:12.39: [17018]: RECV/CQ: Bad 1D pixel count, row 43, got 1730, expected 1728
Feb 26 11:07:12.58: [17018]: RECV/CQ: Bad 1D pixel count, row 44, got 3856, expected 1728
Feb 26 11:07:12.85: [17018]: RECV/CQ: Bad 1D pixel count, row 45, got 2668, expected 1728
Feb 26 11:07:12.96: [17018]: RECV/CQ: Invalid EOL code word, row 46, x 387
Feb 26 11:07:12.96: [17018]: RECV/CQ: Bad 2D pixel count, row 46, got 387, expected 1728
Feb 26 11:07:12.96: [17018]: RECV/CQ: Bad 1D pixel count, row 47, got 2124, expected 1728
Feb 26 11:07:13.06: [17018]: RECV/CQ: Bad 2D pixel count, row 48, got 3122, expected 1728
Feb 26 11:07:13.27: [17018]: RECV/CQ: Bad 1D pixel count, row 49, got 1900, expected 1728
Feb 26 11:07:13.27: [17018]: RECV/CQ: Invalid BlackTable code word, row 50, x 106
Feb 26 11:07:13.27: [17018]: RECV/CQ: Bad 2D pixel count, row 50, got 106, expected 1728
Feb 26 11:07:13.48: [17018]: RECV/CQ: Invalid WhiteTable code word, row 52, x 178
Feb 26 11:07:13.48: [17018]: RECV/CQ: Bad 1D pixel count, row 52, got 178, expected 1728
Feb 26 11:07:13.59: [17018]: RECV/CQ: Bad 1D pixel count, row 53, got 1729, expected 1728
Feb 26 11:07:13.69: [17018]: RECV/CQ: Bad 2D pixel count, row 54, got 3267, expected 1728
Feb 26 11:07:13.90: [17018]: RECV/CQ: Invalid WhiteTable code word, row 55, x 753
Feb 26 11:07:13.90: [17018]: RECV/CQ: Bad 1D pixel count, row 55, got 753, expected 1728
Feb 26 11:07:14.32: [17018]: RECV/CQ: Bad 1D pixel count, row 57, got 3378, expected 1728
Feb 26 11:07:14.43: [17018]: RECV/CQ: Invalid 2D code word, row 58, x 206
Feb 26 11:07:14.43: [17018]: RECV/CQ: Bad 2D pixel count, row 58, got 206, expected 1728
Feb 26 11:07:14.59: [17018]: RECV/CQ: Bad 1D pixel count, row 59, got 1990, expected 1728
Feb 26 11:07:15.01: [17018]: RECV/CQ: Bad 1D pixel count, row 60, got 3114, expected 1728
Feb 26 11:07:15.65: [17018]: RECV/CQ: Bad 1D pixel count, row 61, got 1891, expected 1728
Feb 26 11:07:15.96: [17018]: RECV/CQ: Invalid 2D code word, row 62, x 157
Feb 26 11:07:15.96: [17018]: RECV/CQ: Bad 2D pixel count, row 62, got 157, expected 1728
Feb 26 11:07:16.17: [17018]: RECV/CQ: Bad 2D pixel count, row 63, got 1729, expected 1728
Feb 26 11:07:16.49: [17018]: RECV/CQ: Bad 2D pixel count, row 64, got 1735, expected 1728
Feb 26 11:07:17.02: [17018]: RECV/CQ: Bad 2D pixel count, row 66, got 1745, expected 1728
Feb 26 11:07:17.13: [17018]: RECV/CQ: Adjusting for trailing noise (1 run)
Feb 26 11:07:17.13: [17018]: RECV: 66 total lines, 52 bad lines, 13 consecutive bad lines
Feb 26 11:07:17.13: [17018]: RECV: REJECT page quality, 21% good lines (95% required)
Feb 26 11:07:17.13: [17018]: RECV: end page
Feb 26 11:07:17.13: [17018]: --> [10:NO CARRIER]
Feb 26 11:07:17.13: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:07:17.31: [17018]: --> [7:CONNECT]
Feb 26 11:07:18.07: [17018]: --> HDLC<5:FF C8 F4 CC 66>
Feb 26 11:07:18.07: [17018]: --> [2:OK]
Feb 26 11:07:18.07: [17018]: RECV recv EOP (no more pages or documents)
Feb 26 11:07:18.07: [17018]: <-- [9:AT+FRS=7\r]
Feb 26 11:07:18.17: [17018]: --> [2:OK]
Feb 26 11:07:18.18: [17018]: <-- [9:AT+FTH=3\r]
Feb 26 11:07:18.28: [17018]: --> [7:CONNECT]
Feb 26 11:07:18.28: [17018]: RECV send RTN (retrain negative)
Feb 26 11:07:18.28: [17018]: RECV FAX (000000060): from 6568500, page 1 in 0:21, INF, 3.85 line/mm, 2-D MR, 9600 bit/s
Feb 26 11:07:18.28: [17018]: <-- HDLC<3:FF C8 32>
Feb 26 11:07:18.28: [17018]: <-- data [3]
Feb 26 11:07:18.28: [17018]: <-- data [2]
Feb 26 11:07:18.83: [17018]: --> [2:OK]
Feb 26 11:07:18.83: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:07:19.21: [17018]: --> [7:CONNECT]
Feb 26 11:07:19.81: [17018]: --> HDLC<5:FF C8 DF 59 6F>
Feb 26 11:07:19.81: [17018]: --> [2:OK]
Feb 26 11:07:19.81: [17018]: RECV recv DCN (disconnect)
Feb 26 11:07:19.81: [17018]: RECV FAX (000000060): recvq/fax000000046.tif from 6568500, route to <unspecified>, 1 pages in 0:23
Feb 26 11:07:19.81: [17018]: RECV FAX: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.81: [17018]: RECV FAX (000000060): session with 6568500 terminated abnormally: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.81: [17018]: RECV FAX: bin/faxrcvd.php "recvq/fax000000046.tif" "ttyIAX02" "000000060" "RSPREC error/got DCN (send
er abort)" "616568500" "MAKRO 616568500" "<NONE>" "s"
Feb 26 11:07:19.82: [17018]: RECV FAX: end
Feb 26 11:07:19.82: [17018]: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.82: [17018]: SESSION END
or another one:
Feb 20 14:15:36.37: [ 3197]: SESSION BEGIN 000000052 48914843712
Feb 20 14:15:36.37: [ 3197]: HylaFAX (tm) Version 4.4.4
Feb 20 14:15:36.37: [ 3197]: CallID: "774480540" "774480540" "<NONE>" "s"
Feb 20 14:15:36.37: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
Feb 20 14:15:36.37: [ 3197]: <-- [4:ATA\r]
Feb 20 14:15:38.47: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:38.47: [ 3197]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX01'
Feb 20 14:15:38.47: [ 3197]: STATE CHANGE: ANSWERING -> RECEIVING
Feb 20 14:15:38.47: [ 3197]: RECV FAX: begin
Feb 20 14:15:38.47: [ 3197]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 2C 74 2C
74 2C>
Feb 20 14:15:38.47: [ 3197]: <-- data [32]
Feb 20 14:15:38.47: [ 3197]: <-- data [2]
Feb 20 14:15:38.95: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:38.95: [ 3197]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04 04 04 04 04 04 04 04 04 04 04>
Feb 20 14:15:38.95: [ 3197]: <-- data [23]
Feb 20 14:15:38.95: [ 3197]: <-- data [2]
Feb 20 14:15:39.54: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:39.54: [ 3197]: <-- HDLC<13:FF C8 01 00 77 5F 23 01 FB C1 01 01 18>
Feb 20 14:15:39.54: [ 3197]: <-- data [13]
Feb 20 14:15:39.54: [ 3197]: <-- data [2]
Feb 20 14:15:39.83: [ 3197]: --> [2:OK]
Feb 20 14:15:39.83: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:40.40: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:41.04: [ 3197]: --> HDLC<25:FF C0 C2 0C 0C 04 2C 0C 04 6C CC 2C 04 EC EC 04 1C 2C D4 04 04 04 04 E2 3E>
Feb 20 14:15:41.04: [ 3197]: --> [2:OK]
Feb 20 14:15:41.04: [ 3197]: REMOTE TSI "+48 77 436 04 00"
Feb 20 14:15:41.04: [ 3197]: RECV recv TSI (sender id)
Feb 20 14:15:41.04: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:41.21: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:41.21: [ 3197]: --> HDLC<9:FF C8 C1 00 45 1F 22 60 EB>
Feb 20 14:15:41.25: [ 3197]: --> [2:OK]
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 14400 bit/s
Feb 20 14:15:41.25: [ 3197]: REMOTE wants A4 page width (215 mm)
Feb 20 14:15:41.25: [ 3197]: REMOTE wants unlimited page length
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 3.85 line/mm
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 2-D MMR
Feb 20 14:15:41.25: [ 3197]: REMOTE wants T.30 Annex A, 256-byte ECM
Feb 20 14:15:41.25: [ 3197]: RECV recv DCS (command signal)
Feb 20 14:15:41.25: [ 3197]: RECV training at v.17 14400 bit/s
Feb 20 14:15:41.25: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output generated
Feb 20 14:15:41.25: [ 3197]: <-- [11:AT+FRM=145\r]
Feb 20 14:15:42.37: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:43.20: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:43.20: [ 3197]: RECV: TCF 2802 bytes, 1% non-zero, 2754 zero-run
Feb 20 14:15:43.20: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:43.20: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:43.22: [ 3197]: --> [2:OK]
Feb 20 14:15:43.22: [ 3197]: TRAINING succeeded
Feb 20 14:15:43.22: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:43.24: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:43.24: [ 3197]: <-- HDLC<3:FF C8 21>
Feb 20 14:15:43.24: [ 3197]: <-- data [3]
Feb 20 14:15:43.24: [ 3197]: <-- data [2]
Feb 20 14:15:43.78: [ 3197]: --> [2:OK]
Feb 20 14:15:43.78: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:44.39: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:44.39: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:44.39: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 20 14:15:44.63: [ 3197]: RECV received frame number 0
Feb 20 14:15:44.69: [ 3197]: RECV received frame number 1
Feb 20 14:15:45.56: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.94: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.08: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.15: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.16: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.23: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.23: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.23: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.30: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.44: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.44: [ 3197]: HDLC frame with bad address field 0x9f
Feb 20 14:15:46.44: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.44: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.51: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.51: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.51: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.64: [ 3197]: HDLC frame with bad address field 0xda
Feb 20 14:15:46.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.78: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.92: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.92: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.08: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:47.08: [ 3197]: HDLC frame with bad address field 0xc6
Feb 20 14:15:47.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.09: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xc0
Feb 20 14:15:47.23: [ 3197]: RECV received frame number 5
Feb 20 14:15:47.51: [ 3197]: RECV received frame number 6
Feb 20 14:15:47.68: [ 3197]: RECV received frame number 7
Feb 20 14:15:47.90: [ 3197]: RECV received frame number 8
Feb 20 14:15:48.05: [ 3197]: RECV received frame number 9
Feb 20 14:15:48.27: [ 3197]: RECV received frame number 10
Feb 20 14:15:48.48: [ 3197]: RECV received frame number 11
Feb 20 14:15:48.70: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xc0
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:48.77: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:48.85: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:49.08: [ 3197]: RECV received frame number 13
Feb 20 14:15:49.48: [ 3197]: RECV received frame number 14
Feb 20 14:15:49.70: [ 3197]: RECV received frame number 15
Feb 20 14:15:49.99: [ 3197]: RECV received frame number 16
Feb 20 14:15:50.13: [ 3197]: RECV received frame number 17
Feb 20 14:15:50.13: [ 3197]: RECV received RCP frame
Feb 20 14:15:50.13: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:50.13: [ 3197]: MODEM input buffering disabled
Feb 20 14:15:50.15: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:50.15: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:50.32: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:50.86: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 88 43 22>
Feb 20 14:15:50.89: [ 3197]: --> [2:OK]
Feb 20 14:15:50.89: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:50.89: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:50.89: [ 3197]: RECV received 18 frames of block 1 of page 1
Feb 20 14:15:50.89: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:50.94: [ 3197]: --> [2:OK]
Feb 20 14:15:50.94: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:50.95: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:50.95: [ 3197]: <-- HDLC<35:FF C8 3D 38 08 3F FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF
FF FF FF FF FF>
Feb 20 14:15:50.95: [ 3197]: <-- data [36]
Feb 20 14:15:50.95: [ 3197]: <-- data [2]
Feb 20 14:15:52.22: [ 3197]: --> [2:OK]
Feb 20 14:15:52.22: [ 3197]: RECV send PPR (partial page request)
Feb 20 14:15:52.22: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:53.15: [ 3197]: --> [6:+FRH:3]
Feb 20 14:15:53.15: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:53.86: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 C0 8A EE>
Feb 20 14:15:53.90: [ 3197]: --> [2:OK]
Feb 20 14:15:53.90: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:53.90: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:53.90: [ 3197]: RECV received 4 frames of block 1 of page 1
Feb 20 14:15:53.90: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:53.93: [ 3197]: --> [2:OK]
Feb 20 14:15:53.93: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:53.94: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:53.94: [ 3197]: <-- HDLC<35:FF C8 3D 38 08 3F FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF
FF FF FF FF FF>
Feb 20 14:15:53.94: [ 3197]: <-- data [36]
Feb 20 14:15:53.94: [ 3197]: <-- data [2]
Feb 20 14:15:55.22: [ 3197]: --> [2:OK]
Feb 20 14:15:55.22: [ 3197]: RECV send PPR (partial page request)
Feb 20 14:15:55.22: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:55.60: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:55.60: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:55.60: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 20 14:15:55.82: [ 3197]: RECV received frame number 2
Feb 20 14:15:55.89: [ 3197]: RECV received frame number 3
Feb 20 14:15:55.96: [ 3197]: RECV received frame number 4
Feb 20 14:15:56.03: [ 3197]: RECV received frame number 12
Feb 20 14:15:56.03: [ 3197]: RECV received RCP frame
Feb 20 14:15:56.03: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:56.03: [ 3197]: MODEM input buffering disabled
Feb 20 14:15:56.06: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:56.06: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:56.17: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:56.85: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 C0 8A EE>
Feb 20 14:15:56.93: [ 3197]: --> [2:OK]
Feb 20 14:15:56.93: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:56.93: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:56.93: [ 3197]: RECV received 4 frames of block 1 of page 1
Feb 20 14:15:56.94: [ 3197]: RECV/CQ: Adjusting for EOFB at row 574
Feb 20 14:15:56.94: [ 3197]: RECV: 4411 bytes of data, 574 total lines
Feb 20 14:15:56.94: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:56.94: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:56.99: [ 3197]: --> [2:OK]
Feb 20 14:15:56.99: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:57.01: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:57.01: [ 3197]: <-- HDLC<3:FF C8 31>
Feb 20 14:15:57.01: [ 3197]: <-- data [3]
Feb 20 14:15:57.01: [ 3197]: <-- data [2]
Feb 20 14:15:57.59: [ 3197]: --> [2:OK]
Feb 20 14:15:57.59: [ 3197]: RECV send MCF (message confirmation)
Feb 20 14:15:57.60: [ 3197]: RECV FAX (000000052): from +48 77 436 04 00, page 1 in 0:18, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
Feb 20 14:15:57.60: [ 3197]: RECV FAX (000000052): recvq/fax000000038.tif from +48 77 436 04 00, route to <unspecified>, 1 pages i
n 0:19
Feb 20 14:15:57.60: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:57.90: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:58.42: [ 3197]: --> HDLC<5:FF C8 DF 59 6F>
Feb 20 14:15:58.46: [ 3197]: --> [2:OK]
Feb 20 14:15:58.46: [ 3197]: RECV recv DCN (disconnect)
Feb 20 14:15:58.46: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:58.46: [ 3197]: RECV FAX: bin/faxrcvd.php "recvq/fax000000038.tif" "ttyIAX01" "000000052" "" "774480540" "774480540"
"<NONE>" "s"
Feb 20 14:15:58.47: [ 3197]: RECV FAX: end
Feb 20 14:15:58.47: [ 3197]: SESSION END
Any ideas?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Then again... I was too eager with my assumptions.
It turns out (at least that's what Sangoma support says), that zttest results are not meaningfull for Sangoma A500D. I will have to find another reason, why some (like 60%) of incoming faxes fail.
I have checked, that sending faxes between my IAXmodems works fine. I do not understand, why faxes received over ISDN BRI -> Sangoma A500D -> Asterisk would fail. If I understand right, there is no possibility of weak signall issue. The only thing I could imagine as a cause of my problems is timing.
Could anyone explain me, how IAXmodem is synchronized with A500D and Asterisk? Do I get timing from ISDN line or A500D has its own timer?
My setup is:
Core2Duo
Intel chipset MB
1Gig ram
raid 1 setup with 2 IDE drives
Sangoma A500D PCI card with 3 BRI modules, latest drivers
100Mbit ethernet for WAN
1000Mbit ethernet for LAN
Trixbox 2.4 CE
Another thought: dual cores causing some problems?
Looking forward to any replies...
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Problem solved. I have found out, that running ztcfg -vvv from CLI helps. I don't really understand the mechanism, but it seems that zaptel dummy device is unable to get stable clock source during system startup. If I run it later, my zttest results are fine. What worries me is the fact, that sometimes it takes two ztcfg runs before zttest starts showing 99.99% results.
I have a working (well, almost :D) setup of Trixbox CE 2.4 with IAXmodems running on the same machine, using SLIN codec. My Hylafax + Avantfax is on another machine (virtual machine located on a physical machine different from Trixbox) communicating by interceptty. We receive faxes on ISDN lines, my Trixbox machine is equipped with Sangoma A500D card.
Problem is, that 4 of 5 received faxes get corrupted. It looks like they get squisshed badly.
Feb 26 11:06:54.26: [17018]: SESSION BEGIN 000000060 48914843712
Feb 26 11:06:54.26: [17018]: HylaFAX (tm) Version 4.4.4
Feb 26 11:06:54.26: [17018]: CallID: "616568500" "MAKRO 616568500" "<NONE>" "s"
Feb 26 11:06:54.26: [17018]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
Feb 26 11:06:54.26: [17018]: <-- [4:ATA\r]
Feb 26 11:06:56.46: [17018]: --> [7:CONNECT]
Feb 26 11:06:56.46: [17018]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX02'
Feb 26 11:06:56.46: [17018]: STATE CHANGE: ANSWERING -> RECEIVING
Feb 26 11:06:56.46: [17018]: RECV FAX: begin
Feb 26 11:06:56.46: [17018]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 2C 74 2C
74 2C>
Feb 26 11:06:56.46: [17018]: <-- data [32]
Feb 26 11:06:56.46: [17018]: <-- data [2]
Feb 26 11:06:56.95: [17018]: --> [7:CONNECT]
Feb 26 11:06:56.95: [17018]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04 04 04 04 04 04 04 04 04 04 04>
Feb 26 11:06:56.95: [17018]: <-- data [23]
Feb 26 11:06:56.95: [17018]: <-- data [2]
Feb 26 11:06:57.55: [17018]: --> [7:CONNECT]
Feb 26 11:06:57.55: [17018]: <-- HDLC<13:FF C8 01 00 77 5F 23 01 FB C1 01 01 18>
Feb 26 11:06:57.55: [17018]: <-- data [13]
Feb 26 11:06:57.55: [17018]: <-- data [2]
Feb 26 11:06:58.04: [17018]: --> [2:OK]
Feb 26 11:06:58.04: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:06:58.43: [17018]: --> [7:CONNECT]
Feb 26 11:06:59.24: [17018]: --> HDLC<25:FF C0 C2 0C 0C AC 1C 6C AC 6C 04 04 04 04 04 04 04 04 04 04 04 04 04 B6 B1>
Feb 26 11:06:59.24: [17018]: --> [2:OK]
Feb 26 11:06:59.24: [17018]: REMOTE TSI "6568500"
Feb 26 11:06:59.24: [17018]: RECV recv TSI (sender id)
Feb 26 11:06:59.24: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:06:59.42: [17018]: --> [7:CONNECT]
Feb 26 11:06:59.42: [17018]: --> HDLC<9:FF C8 C1 00 61 1F 00 3E CD>
Feb 26 11:06:59.46: [17018]: --> [2:OK]
Feb 26 11:06:59.46: [17018]: REMOTE wants 9600 bit/s
Feb 26 11:06:59.46: [17018]: REMOTE wants A4 page width (215 mm)
Feb 26 11:06:59.46: [17018]: REMOTE wants unlimited page length
Feb 26 11:06:59.46: [17018]: REMOTE wants 3.85 line/mm
Feb 26 11:06:59.46: [17018]: REMOTE wants 2-D MR
Feb 26 11:06:59.46: [17018]: RECV recv DCS (command signal)
Feb 26 11:06:59.46: [17018]: RECV training at v.29 9600 bit/s
Feb 26 11:06:59.46: [17018]: MODEM set XON/XOFF/DRAIN: input ignored, output generated
Feb 26 11:06:59.46: [17018]: <-- [10:AT+FRM=96\r]
Feb 26 11:06:59.83: [17018]: --> [7:CONNECT]
Feb 26 11:07:00.71: [17018]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 26 11:07:00.71: [17018]: RECV: TCF 1832 bytes, 1% non-zero, 1806 zero-run
Feb 26 11:07:00.71: [17018]: --> [10:NO CARRIER]
Feb 26 11:07:00.71: [17018]: <-- [9:AT+FRS=7\r]
Feb 26 11:07:00.74: [17018]: --> [2:OK]
Feb 26 11:07:00.74: [17018]: TRAINING succeeded
Feb 26 11:07:00.74: [17018]: <-- [9:AT+FTH=3\r]
Feb 26 11:07:00.75: [17018]: --> [7:CONNECT]
Feb 26 11:07:00.75: [17018]: <-- HDLC<3:FF C8 21>
Feb 26 11:07:00.75: [17018]: <-- data [3]
Feb 26 11:07:00.75: [17018]: <-- data [2]
Feb 26 11:07:01.29: [17018]: --> [2:OK]
Feb 26 11:07:01.29: [17018]: <-- [10:AT+FRM=96\r]
Feb 26 11:07:01.91: [17018]: --> [7:CONNECT]
Feb 26 11:07:01.91: [17018]: MODEM input buffering enabled
Feb 26 11:07:01.91: [17018]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 26 11:07:01.91: [17018]: RECV: begin page
Feb 26 11:07:02.33: [17018]: RECV/CQ: Bad 1D pixel count, row 0, got 2273, expected 1728
Feb 26 11:07:02.66: [17018]: RECV/CQ: Invalid BlackTable code word, row 2, x 1683
Feb 26 11:07:02.66: [17018]: RECV/CQ: Bad 1D pixel count, row 2, got 1683, expected 1728
Feb 26 11:07:02.87: [17018]: RECV/CQ: Invalid WhiteTable code word, row 3, x 1446
Feb 26 11:07:02.87: [17018]: RECV/CQ: Bad 1D pixel count, row 3, got 1446, expected 1728
Feb 26 11:07:02.87: [17018]: RECV/CQ: Bad 1D pixel count, row 4, got 2012, expected 1728
Feb 26 11:07:03.28: [17018]: RECV/CQ: Bad 2D pixel count, row 5, got 1778, expected 1728
Feb 26 11:07:03.81: [17018]: RECV/CQ: Bad 1D pixel count, row 6, got 2552, expected 1728
Feb 26 11:07:04.03: [17018]: RECV/CQ: Bad 1D pixel count, row 7, got 1874, expected 1728
Feb 26 11:07:04.03: [17018]: RECV/CQ: Bad 1D pixel count, row 8, got 1794, expected 1728
Feb 26 11:07:04.34: [17018]: RECV/CQ: Bad 2D pixel count, row 9, got 1729, expected 1728
Feb 26 11:07:04.56: [17018]: RECV/CQ: Bad 1D pixel count, row 10, got 1825, expected 1728
Feb 26 11:07:04.86: [17018]: RECV/CQ: Bad 1D pixel count, row 11, got 2901, expected 1728
Feb 26 11:07:04.86: [17018]: RECV/CQ: Bad 1D pixel count, row 12, got 2097, expected 1728
Feb 26 11:07:05.40: [17018]: RECV/CQ: Invalid EOL code word, row 13, x 139
Feb 26 11:07:05.40: [17018]: RECV/CQ: Bad 2D pixel count, row 13, got 139, expected 1728
Feb 26 11:07:05.40: [17018]: RECV/CQ: Bad 1D pixel count, row 14, got 2162, expected 1728
Feb 26 11:07:05.50: [17018]: RECV/CQ: Bad 2D pixel count, row 16, got 1737, expected 1728
Feb 26 11:07:05.81: [17018]: RECV/CQ: Bad 2D pixel count, row 17, got 2575, expected 1728
Feb 26 11:07:06.02: [17018]: RECV/CQ: Bad 2D pixel count, row 19, got 1729, expected 1728
Feb 26 11:07:06.55: [17018]: RECV/CQ: Bad 1D pixel count, row 22, got 2269, expected 1728
Feb 26 11:07:06.77: [17018]: RECV/CQ: Bad 1D pixel count, row 23, got 2432, expected 1728
Feb 26 11:07:07.08: [17018]: RECV/CQ: Bad 1D pixel count, row 25, got 1795, expected 1728
Feb 26 11:07:07.37: [17018]: RECV/CQ: Bad 1D pixel count, row 26, got 2965, expected 1728
Feb 26 11:07:08.88: [17018]: RECV/CQ: Bad 1D pixel count, row 30, got 1768, expected 1728
Feb 26 11:07:09.36: [17018]: RECV/CQ: Bad 1D pixel count, row 31, got 1737, expected 1728
Feb 26 11:07:09.68: [17018]: RECV/CQ: Bad 1D pixel count, row 32, got 2654, expected 1728
Feb 26 11:07:09.84: [17018]: RECV/CQ: Bad 1D pixel count, row 33, got 1731, expected 1728
Feb 26 11:07:10.21: [17018]: RECV/CQ: Invalid 2D code word, row 34, x 1512
Feb 26 11:07:10.21: [17018]: RECV/CQ: Bad 2D pixel count, row 34, got 1512, expected 1728
Feb 26 11:07:11.05: [17018]: RECV/CQ: Bad 2D pixel count, row 36, got 2071, expected 1728
Feb 26 11:07:11.36: [17018]: RECV/CQ: Bad 1D pixel count, row 38, got 2072, expected 1728
Feb 26 11:07:11.36: [17018]: RECV/CQ: Invalid BlackTable code word, row 39, x 1056
Feb 26 11:07:11.36: [17018]: RECV/CQ: Bad 1D pixel count, row 39, got 1056, expected 1728
Feb 26 11:07:11.48: [17018]: RECV/CQ: Bad 2D pixel count, row 40, got 1729, expected 1728
Feb 26 11:07:11.79: [17018]: RECV/CQ: Bad 1D pixel count, row 41, got 1734, expected 1728
Feb 26 11:07:12.23: [17018]: RECV/CQ: Bad 1D pixel count, row 42, got 1729, expected 1728
Feb 26 11:07:12.39: [17018]: RECV/CQ: Bad 1D pixel count, row 43, got 1730, expected 1728
Feb 26 11:07:12.58: [17018]: RECV/CQ: Bad 1D pixel count, row 44, got 3856, expected 1728
Feb 26 11:07:12.85: [17018]: RECV/CQ: Bad 1D pixel count, row 45, got 2668, expected 1728
Feb 26 11:07:12.96: [17018]: RECV/CQ: Invalid EOL code word, row 46, x 387
Feb 26 11:07:12.96: [17018]: RECV/CQ: Bad 2D pixel count, row 46, got 387, expected 1728
Feb 26 11:07:12.96: [17018]: RECV/CQ: Bad 1D pixel count, row 47, got 2124, expected 1728
Feb 26 11:07:13.06: [17018]: RECV/CQ: Bad 2D pixel count, row 48, got 3122, expected 1728
Feb 26 11:07:13.27: [17018]: RECV/CQ: Bad 1D pixel count, row 49, got 1900, expected 1728
Feb 26 11:07:13.27: [17018]: RECV/CQ: Invalid BlackTable code word, row 50, x 106
Feb 26 11:07:13.27: [17018]: RECV/CQ: Bad 2D pixel count, row 50, got 106, expected 1728
Feb 26 11:07:13.48: [17018]: RECV/CQ: Invalid WhiteTable code word, row 52, x 178
Feb 26 11:07:13.48: [17018]: RECV/CQ: Bad 1D pixel count, row 52, got 178, expected 1728
Feb 26 11:07:13.59: [17018]: RECV/CQ: Bad 1D pixel count, row 53, got 1729, expected 1728
Feb 26 11:07:13.69: [17018]: RECV/CQ: Bad 2D pixel count, row 54, got 3267, expected 1728
Feb 26 11:07:13.90: [17018]: RECV/CQ: Invalid WhiteTable code word, row 55, x 753
Feb 26 11:07:13.90: [17018]: RECV/CQ: Bad 1D pixel count, row 55, got 753, expected 1728
Feb 26 11:07:14.32: [17018]: RECV/CQ: Bad 1D pixel count, row 57, got 3378, expected 1728
Feb 26 11:07:14.43: [17018]: RECV/CQ: Invalid 2D code word, row 58, x 206
Feb 26 11:07:14.43: [17018]: RECV/CQ: Bad 2D pixel count, row 58, got 206, expected 1728
Feb 26 11:07:14.59: [17018]: RECV/CQ: Bad 1D pixel count, row 59, got 1990, expected 1728
Feb 26 11:07:15.01: [17018]: RECV/CQ: Bad 1D pixel count, row 60, got 3114, expected 1728
Feb 26 11:07:15.65: [17018]: RECV/CQ: Bad 1D pixel count, row 61, got 1891, expected 1728
Feb 26 11:07:15.96: [17018]: RECV/CQ: Invalid 2D code word, row 62, x 157
Feb 26 11:07:15.96: [17018]: RECV/CQ: Bad 2D pixel count, row 62, got 157, expected 1728
Feb 26 11:07:16.17: [17018]: RECV/CQ: Bad 2D pixel count, row 63, got 1729, expected 1728
Feb 26 11:07:16.49: [17018]: RECV/CQ: Bad 2D pixel count, row 64, got 1735, expected 1728
Feb 26 11:07:17.02: [17018]: RECV/CQ: Bad 2D pixel count, row 66, got 1745, expected 1728
Feb 26 11:07:17.13: [17018]: RECV/CQ: Adjusting for trailing noise (1 run)
Feb 26 11:07:17.13: [17018]: RECV: 66 total lines, 52 bad lines, 13 consecutive bad lines
Feb 26 11:07:17.13: [17018]: RECV: REJECT page quality, 21% good lines (95% required)
Feb 26 11:07:17.13: [17018]: RECV: end page
Feb 26 11:07:17.13: [17018]: --> [10:NO CARRIER]
Feb 26 11:07:17.13: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:07:17.31: [17018]: --> [7:CONNECT]
Feb 26 11:07:18.07: [17018]: --> HDLC<5:FF C8 F4 CC 66>
Feb 26 11:07:18.07: [17018]: --> [2:OK]
Feb 26 11:07:18.07: [17018]: RECV recv EOP (no more pages or documents)
Feb 26 11:07:18.07: [17018]: <-- [9:AT+FRS=7\r]
Feb 26 11:07:18.17: [17018]: --> [2:OK]
Feb 26 11:07:18.18: [17018]: <-- [9:AT+FTH=3\r]
Feb 26 11:07:18.28: [17018]: --> [7:CONNECT]
Feb 26 11:07:18.28: [17018]: RECV send RTN (retrain negative)
Feb 26 11:07:18.28: [17018]: RECV FAX (000000060): from 6568500, page 1 in 0:21, INF, 3.85 line/mm, 2-D MR, 9600 bit/s
Feb 26 11:07:18.28: [17018]: <-- HDLC<3:FF C8 32>
Feb 26 11:07:18.28: [17018]: <-- data [3]
Feb 26 11:07:18.28: [17018]: <-- data [2]
Feb 26 11:07:18.83: [17018]: --> [2:OK]
Feb 26 11:07:18.83: [17018]: <-- [9:AT+FRH=3\r]
Feb 26 11:07:19.21: [17018]: --> [7:CONNECT]
Feb 26 11:07:19.81: [17018]: --> HDLC<5:FF C8 DF 59 6F>
Feb 26 11:07:19.81: [17018]: --> [2:OK]
Feb 26 11:07:19.81: [17018]: RECV recv DCN (disconnect)
Feb 26 11:07:19.81: [17018]: RECV FAX (000000060): recvq/fax000000046.tif from 6568500, route to <unspecified>, 1 pages in 0:23
Feb 26 11:07:19.81: [17018]: RECV FAX: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.81: [17018]: RECV FAX (000000060): session with 6568500 terminated abnormally: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.81: [17018]: RECV FAX: bin/faxrcvd.php "recvq/fax000000046.tif" "ttyIAX02" "000000060" "RSPREC error/got DCN (send
er abort)" "616568500" "MAKRO 616568500" "<NONE>" "s"
Feb 26 11:07:19.82: [17018]: RECV FAX: end
Feb 26 11:07:19.82: [17018]: RSPREC error/got DCN (sender abort)
Feb 26 11:07:19.82: [17018]: SESSION END
or another one:
Feb 20 14:15:36.37: [ 3197]: SESSION BEGIN 000000052 48914843712
Feb 20 14:15:36.37: [ 3197]: HylaFAX (tm) Version 4.4.4
Feb 20 14:15:36.37: [ 3197]: CallID: "774480540" "774480540" "<NONE>" "s"
Feb 20 14:15:36.37: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output disabled
Feb 20 14:15:36.37: [ 3197]: <-- [4:ATA\r]
Feb 20 14:15:38.47: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:38.47: [ 3197]: ANSWER: FAX CONNECTION DEVICE '/dev/ttyIAX01'
Feb 20 14:15:38.47: [ 3197]: STATE CHANGE: ANSWERING -> RECEIVING
Feb 20 14:15:38.47: [ 3197]: RECV FAX: begin
Feb 20 14:15:38.47: [ 3197]: <-- HDLC<32:FF C0 04 B5 00 AA 12 9E 36 86 62 82 1A 04 14 2E B6 94 04 6A A6 4E CE 96 F6 76 04 2C 74 2C
74 2C>
Feb 20 14:15:38.47: [ 3197]: <-- data [32]
Feb 20 14:15:38.47: [ 3197]: <-- data [2]
Feb 20 14:15:38.95: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:38.95: [ 3197]: <-- HDLC<23:FF C0 02 B6 A6 26 F6 B6 1A 82 92 04 04 04 04 04 04 04 04 04 04 04 04>
Feb 20 14:15:38.95: [ 3197]: <-- data [23]
Feb 20 14:15:38.95: [ 3197]: <-- data [2]
Feb 20 14:15:39.54: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:39.54: [ 3197]: <-- HDLC<13:FF C8 01 00 77 5F 23 01 FB C1 01 01 18>
Feb 20 14:15:39.54: [ 3197]: <-- data [13]
Feb 20 14:15:39.54: [ 3197]: <-- data [2]
Feb 20 14:15:39.83: [ 3197]: --> [2:OK]
Feb 20 14:15:39.83: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:40.40: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:41.04: [ 3197]: --> HDLC<25:FF C0 C2 0C 0C 04 2C 0C 04 6C CC 2C 04 EC EC 04 1C 2C D4 04 04 04 04 E2 3E>
Feb 20 14:15:41.04: [ 3197]: --> [2:OK]
Feb 20 14:15:41.04: [ 3197]: REMOTE TSI "+48 77 436 04 00"
Feb 20 14:15:41.04: [ 3197]: RECV recv TSI (sender id)
Feb 20 14:15:41.04: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:41.21: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:41.21: [ 3197]: --> HDLC<9:FF C8 C1 00 45 1F 22 60 EB>
Feb 20 14:15:41.25: [ 3197]: --> [2:OK]
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 14400 bit/s
Feb 20 14:15:41.25: [ 3197]: REMOTE wants A4 page width (215 mm)
Feb 20 14:15:41.25: [ 3197]: REMOTE wants unlimited page length
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 3.85 line/mm
Feb 20 14:15:41.25: [ 3197]: REMOTE wants 2-D MMR
Feb 20 14:15:41.25: [ 3197]: REMOTE wants T.30 Annex A, 256-byte ECM
Feb 20 14:15:41.25: [ 3197]: RECV recv DCS (command signal)
Feb 20 14:15:41.25: [ 3197]: RECV training at v.17 14400 bit/s
Feb 20 14:15:41.25: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output generated
Feb 20 14:15:41.25: [ 3197]: <-- [11:AT+FRM=145\r]
Feb 20 14:15:42.37: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:43.20: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:43.20: [ 3197]: RECV: TCF 2802 bytes, 1% non-zero, 2754 zero-run
Feb 20 14:15:43.20: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:43.20: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:43.22: [ 3197]: --> [2:OK]
Feb 20 14:15:43.22: [ 3197]: TRAINING succeeded
Feb 20 14:15:43.22: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:43.24: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:43.24: [ 3197]: <-- HDLC<3:FF C8 21>
Feb 20 14:15:43.24: [ 3197]: <-- data [3]
Feb 20 14:15:43.24: [ 3197]: <-- data [2]
Feb 20 14:15:43.78: [ 3197]: --> [2:OK]
Feb 20 14:15:43.78: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:44.39: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:44.39: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:44.39: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 20 14:15:44.63: [ 3197]: RECV received frame number 0
Feb 20 14:15:44.69: [ 3197]: RECV received frame number 1
Feb 20 14:15:45.56: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.71: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0x80
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.79: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.86: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:45.86: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.93: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:45.94: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.08: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.15: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.16: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.16: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.23: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.23: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.23: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.30: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.30: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.37: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.44: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.44: [ 3197]: HDLC frame with bad address field 0x9f
Feb 20 14:15:46.44: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.44: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.51: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.51: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:46.51: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.64: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:46.64: [ 3197]: HDLC frame with bad address field 0xda
Feb 20 14:15:46.64: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.78: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.92: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:46.92: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:46.92: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xe0
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.01: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.08: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf0
Feb 20 14:15:47.08: [ 3197]: HDLC frame with bad address field 0xc6
Feb 20 14:15:47.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.08: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:47.09: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xc0
Feb 20 14:15:47.23: [ 3197]: RECV received frame number 5
Feb 20 14:15:47.51: [ 3197]: RECV received frame number 6
Feb 20 14:15:47.68: [ 3197]: RECV received frame number 7
Feb 20 14:15:47.90: [ 3197]: RECV received frame number 8
Feb 20 14:15:48.05: [ 3197]: RECV received frame number 9
Feb 20 14:15:48.27: [ 3197]: RECV received frame number 10
Feb 20 14:15:48.48: [ 3197]: RECV received frame number 11
Feb 20 14:15:48.70: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xc0
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xf8
Feb 20 14:15:48.77: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:48.77: [ 3197]: HDLC frame not byte-oriented. Trailing byte: 0xfc
Feb 20 14:15:48.85: [ 3197]: Bad HDLC terminating flag received.
Feb 20 14:15:49.08: [ 3197]: RECV received frame number 13
Feb 20 14:15:49.48: [ 3197]: RECV received frame number 14
Feb 20 14:15:49.70: [ 3197]: RECV received frame number 15
Feb 20 14:15:49.99: [ 3197]: RECV received frame number 16
Feb 20 14:15:50.13: [ 3197]: RECV received frame number 17
Feb 20 14:15:50.13: [ 3197]: RECV received RCP frame
Feb 20 14:15:50.13: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:50.13: [ 3197]: MODEM input buffering disabled
Feb 20 14:15:50.15: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:50.15: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:50.32: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:50.86: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 88 43 22>
Feb 20 14:15:50.89: [ 3197]: --> [2:OK]
Feb 20 14:15:50.89: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:50.89: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:50.89: [ 3197]: RECV received 18 frames of block 1 of page 1
Feb 20 14:15:50.89: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:50.94: [ 3197]: --> [2:OK]
Feb 20 14:15:50.94: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:50.95: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:50.95: [ 3197]: <-- HDLC<35:FF C8 3D 38 08 3F FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF
FF FF FF FF FF>
Feb 20 14:15:50.95: [ 3197]: <-- data [36]
Feb 20 14:15:50.95: [ 3197]: <-- data [2]
Feb 20 14:15:52.22: [ 3197]: --> [2:OK]
Feb 20 14:15:52.22: [ 3197]: RECV send PPR (partial page request)
Feb 20 14:15:52.22: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:53.15: [ 3197]: --> [6:+FRH:3]
Feb 20 14:15:53.15: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:53.86: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 C0 8A EE>
Feb 20 14:15:53.90: [ 3197]: --> [2:OK]
Feb 20 14:15:53.90: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:53.90: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:53.90: [ 3197]: RECV received 4 frames of block 1 of page 1
Feb 20 14:15:53.90: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:53.93: [ 3197]: --> [2:OK]
Feb 20 14:15:53.93: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:53.94: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:53.94: [ 3197]: <-- HDLC<35:FF C8 3D 38 08 3F FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF
FF FF FF FF FF>
Feb 20 14:15:53.94: [ 3197]: <-- data [36]
Feb 20 14:15:53.94: [ 3197]: <-- data [2]
Feb 20 14:15:55.22: [ 3197]: --> [2:OK]
Feb 20 14:15:55.22: [ 3197]: RECV send PPR (partial page request)
Feb 20 14:15:55.22: [ 3197]: <-- [11:AT+FRM=146\r]
Feb 20 14:15:55.60: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:55.60: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:55.60: [ 3197]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
Feb 20 14:15:55.82: [ 3197]: RECV received frame number 2
Feb 20 14:15:55.89: [ 3197]: RECV received frame number 3
Feb 20 14:15:55.96: [ 3197]: RECV received frame number 4
Feb 20 14:15:56.03: [ 3197]: RECV received frame number 12
Feb 20 14:15:56.03: [ 3197]: RECV received RCP frame
Feb 20 14:15:56.03: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:56.03: [ 3197]: MODEM input buffering disabled
Feb 20 14:15:56.06: [ 3197]: --> [10:NO CARRIER]
Feb 20 14:15:56.06: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:56.17: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:56.85: [ 3197]: --> HDLC<9:FF C8 FD F4 00 00 C0 8A EE>
Feb 20 14:15:56.93: [ 3197]: --> [2:OK]
Feb 20 14:15:56.93: [ 3197]: RECV recv PPS (partial page signal)
Feb 20 14:15:56.93: [ 3197]: RECV recv EOP (no more pages or documents)
Feb 20 14:15:56.93: [ 3197]: RECV received 4 frames of block 1 of page 1
Feb 20 14:15:56.94: [ 3197]: RECV/CQ: Adjusting for EOFB at row 574
Feb 20 14:15:56.94: [ 3197]: RECV: 4411 bytes of data, 574 total lines
Feb 20 14:15:56.94: [ 3197]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
Feb 20 14:15:56.94: [ 3197]: <-- [9:AT+FRS=7\r]
Feb 20 14:15:56.99: [ 3197]: --> [2:OK]
Feb 20 14:15:56.99: [ 3197]: <-- [9:AT+FTH=3\r]
Feb 20 14:15:57.01: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:57.01: [ 3197]: <-- HDLC<3:FF C8 31>
Feb 20 14:15:57.01: [ 3197]: <-- data [3]
Feb 20 14:15:57.01: [ 3197]: <-- data [2]
Feb 20 14:15:57.59: [ 3197]: --> [2:OK]
Feb 20 14:15:57.59: [ 3197]: RECV send MCF (message confirmation)
Feb 20 14:15:57.60: [ 3197]: RECV FAX (000000052): from +48 77 436 04 00, page 1 in 0:18, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
Feb 20 14:15:57.60: [ 3197]: RECV FAX (000000052): recvq/fax000000038.tif from +48 77 436 04 00, route to <unspecified>, 1 pages i
n 0:19
Feb 20 14:15:57.60: [ 3197]: <-- [9:AT+FRH=3\r]
Feb 20 14:15:57.90: [ 3197]: --> [7:CONNECT]
Feb 20 14:15:58.42: [ 3197]: --> HDLC<5:FF C8 DF 59 6F>
Feb 20 14:15:58.46: [ 3197]: --> [2:OK]
Feb 20 14:15:58.46: [ 3197]: RECV recv DCN (disconnect)
Feb 20 14:15:58.46: [ 3197]: MODEM input buffering enabled
Feb 20 14:15:58.46: [ 3197]: RECV FAX: bin/faxrcvd.php "recvq/fax000000038.tif" "ttyIAX01" "000000052" "" "774480540" "774480540"
"<NONE>" "s"
Feb 20 14:15:58.47: [ 3197]: RECV FAX: end
Feb 20 14:15:58.47: [ 3197]: SESSION END
Any ideas?
Moderator is asked to remove this topic. I have traced problems with channel jitter (ZTTEST showing 99.96% and lower) so my question is not valid now.
Thanks for following up on this. I will leave it here for others to see as it may help them with the same problems.
Then again... I was too eager with my assumptions.
It turns out (at least that's what Sangoma support says), that zttest results are not meaningfull for Sangoma A500D. I will have to find another reason, why some (like 60%) of incoming faxes fail.
I have checked, that sending faxes between my IAXmodems works fine. I do not understand, why faxes received over ISDN BRI -> Sangoma A500D -> Asterisk would fail. If I understand right, there is no possibility of weak signall issue. The only thing I could imagine as a cause of my problems is timing.
Could anyone explain me, how IAXmodem is synchronized with A500D and Asterisk? Do I get timing from ISDN line or A500D has its own timer?
My setup is:
Core2Duo
Intel chipset MB
1Gig ram
raid 1 setup with 2 IDE drives
Sangoma A500D PCI card with 3 BRI modules, latest drivers
100Mbit ethernet for WAN
1000Mbit ethernet for LAN
Trixbox 2.4 CE
Another thought: dual cores causing some problems?
Looking forward to any replies...
zttest is meaningful, but not entirely meaningful. It has meaning, but not nearly as much as we would like it to have.
Make an audio recording of a fax call using the "record" feature (see README). Then send the recording to to me at faxguy@howardsilvan.com.
Problem solved. I have found out, that running ztcfg -vvv from CLI helps. I don't really understand the mechanism, but it seems that zaptel dummy device is unable to get stable clock source during system startup. If I run it later, my zttest results are fine. What worries me is the fact, that sometimes it takes two ztcfg runs before zttest starts showing 99.99% results.
My current zttest results are:
Opened pseudo zap interface, measuring accuracy...
99.999123% 99.995895% 99.998924% 99.998245% 99.998833% 99.998146% 99.904297%
99.900093% 99.997070% 99.998344% 99.998047% 99.998055% 99.998344% 99.998146% 99.997940%
99.998245% 99.997467% 99.998245% 99.998344% 99.998047% 99.997665% 99.998146% 99.998154%
99.998245% 99.997559% 99.998138% 99.998154% 99.998344% 99.998245% 99.998047% 99.998436%
99.998245% 99.997757% 99.998344% 99.998924% 99.997162% 99.997856% 99.998245% 99.998436%
99.998245% 99.997368% 99.998047% 99.910843% 99.907516% 99.998138% 99.998436% 99.997749%
99.998436% 99.997559% 99.998138% 99.998344% 99.997940% 99.998238% 99.998344%
--- Results after 54 passes ---
Best: 99.999 -- Worst: 99.900 -- Average: 99.991246, Difference: 99.998092
IAXmodem now works like a charm and I am finally happy with Hyla and Avanfax.
Now if only fax detection worked better :)