[hylafax-users] Send or Receive problem ???

["Roberto Garuti" <roberto.garuti@xxxxxxx>]

A'm having some strange problem on some hylafax machine, and I'm not able to
know if the problem are due to the sender or receiver machine or both.
The problem occur sending faxes from an hylafax machine to another hylafax
machine.
We've many "incomplete" faxes (and this is strange too), and when this
happens, on the receiver machine, the $MSG variable in the file
HYLAFAX_HOME/bin/faxrcvd are '' (blank), so I can't detect incomplete faxes.
What's wrong ?

Attached you will find both sender and receiver transmission logs.

Configs of all my systems are:
LINUX-RH 9.2
hylafax-4.2.1-1rh9
4 USRobotics modem per machine (4 serial).

Thanks.

Roberto

>From fax@xxxxxxxxxxxxxxxxxxxxx  Tue Feb 28 17:42:08 2006
Date: Tue, 28 Feb 2006 17:42:07 +0100
To: FaxMaster@xxxxxxxxxxxxxxxxxxxxx
From: The HylaFAX Receive Agent <fax@xxxxxxxxxxxxxxxxxxxxx>
Subject: facsimile not received

An attempt to receive facsimile on ttyS0 failed because:



    ---- Transcript of session follows ----

Feb 28 17:41:22.46: [32465]: SESSION BEGIN 000000063 0522390542601921
Feb 28 17:41:22.46: [32465]: HylaFAX (tm) Version 4.2.1
Feb 28 17:41:22.46: [32465]: <-- [13:AT+FCLASS=1A\r]
Feb 28 17:41:27.75: [32465]: --> [7:CONNECT]
Feb 28 17:41:27.75: [32465]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyS0'
Feb 28 17:41:27.75: [32465]: RECV FAX: begin
Feb 28 17:41:27.82: [32465]: --> [7:CONNECT]
Feb 28 17:41:28.54: [32465]: --> [7:CONNECT]
Feb 28 17:41:30.72: [32465]: --> [2:OK]
Feb 28 17:41:30.72: [32465]: <-- [9:AT+FRH=3\r]
Feb 28 17:41:31.08: [32465]: --> [7:CONNECT]
Feb 28 17:41:32.65: [32465]: --> [2:OK]
Feb 28 17:41:32.65: [32465]: REMOTE TSI "Coop. Ceramica d'Imo"
Feb 28 17:41:32.65: [32465]: <-- [9:AT+FRH=3\r]
Feb 28 17:41:32.67: [32465]: --> [7:CONNECT]
Feb 28 17:41:32.94: [32465]: --> [2:OK]
Feb 28 17:41:32.94: [32465]: REMOTE wants 14400 bit/s
Feb 28 17:41:32.94: [32465]: REMOTE wants A4 page width (215 mm)
Feb 28 17:41:32.94: [32465]: REMOTE wants unlimited page length
Feb 28 17:41:32.94: [32465]: REMOTE wants 7.7 line/mm
Feb 28 17:41:32.94: [32465]: REMOTE wants 2-D MMR
Feb 28 17:41:32.94: [32465]: REMOTE wants T.30 Annex A, 256-byte ECM
Feb 28 17:41:32.94: [32465]: RECV training at v.17 14400 bit/s
Feb 28 17:41:32.94: [32465]: <-- [11:AT+FRM=145\r]
Feb 28 17:41:34.53: [32465]: --> [7:CONNECT]
Feb 28 17:41:36.09: [32465]: RECV: TCF 2811 bytes, 3% non-zero, 2699 zero-run
Feb 28 17:41:36.10: [32465]: --> [10:NO CARRIER]
Feb 28 17:41:36.10: [32465]: DELAY 75 ms
Feb 28 17:41:36.18: [32465]: TRAINING succeeded
Feb 28 17:41:36.18: [32465]: <-- [9:AT+FTH=3\r]
Feb 28 17:41:36.38: [32465]: --> [7:CONNECT]
Feb 28 17:41:37.56: [32465]: --> [2:OK]
Feb 28 17:41:37.56: [32465]: <-- [11:AT+FRM=146\r]
Feb 28 17:41:38.14: [32465]: --> [7:CONNECT]
Feb 28 17:41:38.43: [32465]: RECV received frame number 0
Feb 28 17:41:38.59: [32465]: RECV received frame number 1
Feb 28 17:41:38.74: [32465]: RECV received frame number 2
Feb 28 17:41:38.95: [32465]: RECV received frame number 3
Feb 28 17:41:39.09: [32465]: RECV received frame number 4
Feb 28 17:41:39.23: [32465]: RECV received frame number 5
Feb 28 17:41:39.38: [32465]: RECV received frame number 6
Feb 28 17:41:39.52: [32465]: RECV received frame number 7
Feb 28 17:41:39.66: [32465]: RECV received frame number 8
Feb 28 17:41:39.81: [32465]: RECV received frame number 9
Feb 28 17:41:39.96: [32465]: RECV received frame number 10
Feb 28 17:41:40.10: [32465]: RECV received frame number 11
Feb 28 17:41:40.24: [32465]: RECV received frame number 12
Feb 28 17:41:40.39: [32465]: RECV received frame number 13
Feb 28 17:41:40.54: [32465]: RECV received frame number 14
Feb 28 17:41:40.76: [32465]: RECV received frame number 15
Feb 28 17:41:40.90: [32465]: RECV received frame number 16
Feb 28 17:41:41.05: [32465]: RECV received frame number 17
Feb 28 17:41:41.20: [32465]: RECV received frame number 18
Feb 28 17:41:41.35: [32465]: RECV received frame number 19
Feb 28 17:41:41.51: [32465]: RECV received frame number 20
Feb 28 17:41:41.65: [32465]: RECV received frame number 21
Feb 28 17:41:41.79: [32465]: RECV received frame number 22
Feb 28 17:41:41.93: [32465]: RECV received frame number 23
Feb 28 17:41:42.07: [32465]: RECV received frame number 24
Feb 28 17:41:42.21: [32465]: RECV received frame number 25
Feb 28 17:41:42.36: [32465]: RECV received frame number 26
Feb 28 17:41:42.51: [32465]: RECV received frame number 27
Feb 28 17:41:42.66: [32465]: RECV received frame number 28
Feb 28 17:41:42.81: [32465]: RECV received frame number 29
Feb 28 17:41:42.96: [32465]: RECV received frame number 30
Feb 28 17:41:43.10: [32465]: RECV received frame number 31
Feb 28 17:41:43.31: [32465]: RECV received frame number 32
Feb 28 17:41:43.45: [32465]: RECV received frame number 33
Feb 28 17:41:43.59: [32465]: RECV received frame number 34
Feb 28 17:41:43.74: [32465]: RECV received frame number 35
Feb 28 17:41:43.90: [32465]: RECV received frame number 36
Feb 28 17:41:44.04: [32465]: RECV received frame number 37
Feb 28 17:41:44.20: [32465]: RECV received frame number 38
Feb 28 17:41:44.34: [32465]: RECV received frame number 39
Feb 28 17:41:44.48: [32465]: RECV received frame number 40
Feb 28 17:41:44.62: [32465]: RECV received frame number 41
Feb 28 17:41:44.77: [32465]: RECV received frame number 42
Feb 28 17:41:44.91: [32465]: RECV received frame number 43
Feb 28 17:41:45.12: [32465]: RECV received frame number 44
Feb 28 17:41:45.26: [32465]: RECV received frame number 45
Feb 28 17:41:45.41: [32465]: RECV received frame number 46
Feb 28 17:41:45.57: [32465]: RECV received frame number 47
Feb 28 17:41:45.71: [32465]: RECV received frame number 48
Feb 28 17:41:45.85: [32465]: RECV received frame number 49
Feb 28 17:41:45.99: [32465]: RECV received frame number 50
Feb 28 17:41:46.13: [32465]: RECV received frame number 51
Feb 28 17:41:46.27: [32465]: RECV received frame number 52
Feb 28 17:41:46.42: [32465]: RECV received frame number 53
Feb 28 17:41:46.57: [32465]: RECV received frame number 54
Feb 28 17:41:46.72: [32465]: RECV received frame number 55
Feb 28 17:41:46.86: [32465]: RECV received frame number 56
Feb 28 17:41:47.08: [32465]: RECV received frame number 57
Feb 28 17:41:47.16: [32465]: RECV received frame number 58
Feb 28 17:41:47.32: [32465]: RECV received frame number 59
Feb 28 17:41:47.32: [32465]: RECV received RCP frame
Feb 28 17:41:47.40: [32465]: --> [10:NO CARRIER]
Feb 28 17:41:47.40: [32465]: <-- [9:AT+FRH=3\r]
Feb 28 17:41:47.88: [32465]: --> [7:CONNECT]
Feb 28 17:41:48.88: [32465]: --> [2:OK]
Feb 28 17:41:48.88: [32465]: RECV recv PPS (partial page signal)
Feb 28 17:41:48.88: [32465]: RECV recv EOM (more documents)
Feb 28 17:41:48.88: [32465]: RECV received 60 frames of block 1 of page 1
Feb 28 17:41:48.97: [32465]: RECV: 15189 bytes of data, 2292 total lines
Feb 28 17:41:48.98: [32465]: DELAY 70 ms
Feb 28 17:41:49.04: [32465]: <-- [9:AT+FTH=3\r]
Feb 28 17:41:49.24: [32465]: --> [7:CONNECT]
Feb 28 17:41:50.42: [32465]: --> [2:OK]
Feb 28 17:41:50.42: [32465]: RECV send MCF (message confirmation)
Feb 28 17:41:50.42: [32465]: RECV FAX (000000063): from Coop. Ceramica d'Imo, page 1 in 0:14, INF, 7.7 line/mm, 2-D MMR, 14400 bit/s
Feb 28 17:41:50.42: [32465]: RECV FAX (000000063): recvq/fax000000021.tif from Coop. Ceramica d'Imo, route to <unspecified>, 1 pages in 0:23
Feb 28 17:41:50.42: [32465]: DELAY 7000 ms
Feb 28 17:41:57.42: [32465]: <-- [9:AT+FTH=3\r]
Feb 28 17:41:57.46: [32465]: --> [7:CONNECT]
Feb 28 17:41:57.62: [32465]: --> [7:CONNECT]
Feb 28 17:41:58.34: [32465]: --> [7:CONNECT]
Feb 28 17:42:00.53: [32465]: --> [2:OK]
Feb 28 17:42:00.53: [32465]: <-- [9:AT+FRH=3\r]
Feb 28 17:42:00.68: [32465]: --> [7:CONNECT]
Feb 28 17:42:01.24: [32465]: --> [2:OK]
Feb 28 17:42:01.24: [32465]: DELAY 1500 ms
Feb 28 17:42:02.74: [32465]: <-- [9:AT+FTH=3\r]
Feb 28 17:42:02.94: [32465]: --> [7:CONNECT]
Feb 28 17:42:03.10: [32465]: --> [7:CONNECT]
Feb 28 17:42:03.82: [32465]: --> [7:CONNECT]
Feb 28 17:42:06.01: [32465]: --> [2:OK]
Feb 28 17:42:06.01: [32465]: <-- [9:AT+FRH=3\r]
Feb 28 17:42:06.19: [32465]: --> [7:CONNECT]
Feb 28 17:42:06.35: [32465]: --> [2:OK]
Feb 28 17:42:06.35: [32465]: RECV FAX: RSPREC error/got DCN
Feb 28 17:42:06.35: [32465]: <-- [9:AT+FTH=3\r]
Feb 28 17:42:06.55: [32465]: --> [7:CONNECT]
Feb 28 17:42:07.73: [32465]: --> [2:OK]
Feb 28 17:42:07.73: [32465]: RECV FAX: bin/faxrcvd "recvq/fax000000021.tif" "ttyS0" "000000063" "" "" ""
Feb 28 17:42:07.75: [32465]: RECV FAX: bin/faxrcvd "recvq/fax000000022.tif" "ttyS0" "000000063" "" "" ""
Feb 28 17:42:07.77: [32465]: RECV FAX: end
Feb 28 17:42:07.77: [32465]: SESSION END

feb 28 17:16:43.26: [27583]: SESSION BEGIN 000008373 3905420542601921
feb 28 17:16:43.26: [27583]: HylaFAX (tm) Version 4.2.1
feb 28 17:16:43.26: [27583]: SEND FAX: JOB 7000 DEST 0542601921 COMMID 000008373 DEVICE '/dev/ttyS5'
feb 28 17:16:43.26: [27583]: <-- [12:AT+FCLASS=1\r]
feb 28 17:16:43.50: [27583]: --> [2:OK]
feb 28 17:16:43.50: [27583]: DIAL 0542601921
feb 28 17:16:43.50: [27583]: <-- [17:ATDT0,0542601921\r]
feb 28 17:17:01.84: [27583]: --> [7:CONNECT]
feb 28 17:17:03.46: [27583]: --> [2:OK]
feb 28 17:17:03.46: [27583]: REMOTE NSF "B5 00 AA 48 79 6C 61 46 41 58 20 28 74 6D 29 20 56 65 72 73 69 6F 6E 20 34 2E 32 2E 31"
feb 28 17:17:03.46: [27583]: NSF remote fax equipment: HylaFAX
feb 28 17:17:03.46: [27583]: NSF remote station ID: "HylaFAX (tm) Version 4.2.1"
feb 28 17:17:03.46: [27583]: <-- [9:AT+FRH=3\r]
feb 28 17:17:03.48: [27583]: --> [7:CONNECT]
feb 28 17:17:04.18: [27583]: --> [2:OK]
feb 28 17:17:04.18: [27583]: REMOTE CSI "OMEGA SPA - 0"
feb 28 17:17:04.18: [27583]: <-- [9:AT+FRH=3\r]
feb 28 17:17:04.20: [27583]: --> [7:CONNECT]
feb 28 17:17:04.55: [27583]: --> [2:OK]
feb 28 17:17:04.55: [27583]: REMOTE best rate 14400 bit/s
feb 28 17:17:04.55: [27583]: REMOTE max A3 page width (303 mm)
feb 28 17:17:04.55: [27583]: REMOTE max unlimited page length
feb 28 17:17:04.55: [27583]: REMOTE best vres R16 x 15.4 line/mm
feb 28 17:17:04.55: [27583]: REMOTE best format 2-D MMR
feb 28 17:17:04.55: [27583]: REMOTE supports T.30 Annex A, 256-byte ECM
feb 28 17:17:04.55: [27583]: REMOTE best 0 ms/scanline
feb 28 17:17:04.55: [27583]: USE 14400 bit/s
feb 28 17:17:04.55: [27583]: USE error correction mode
feb 28 17:17:04.55: [27583]: USE 0 ms/scanline
feb 28 17:17:04.55: [27583]: SEND file "docq/doc10143.tif;c1"
feb 28 17:17:04.55: [27583]: USE A4 page width (215 mm)
feb 28 17:17:04.55: [27583]: USE unlimited page length
feb 28 17:17:04.55: [27583]: USE 7.7 line/mm
feb 28 17:17:04.55: [27583]: USE 2-D MMR
feb 28 17:17:04.55: [27583]: SEND training at v.17 14400 bit/s
feb 28 17:17:04.55: [27583]: <-- [9:AT+FTH=3\r]
feb 28 17:17:04.75: [27583]: --> [7:CONNECT]
feb 28 17:17:04.75: [27583]: <-- data [23]
feb 28 17:17:04.75: [27583]: <-- data [2]
feb 28 17:17:04.78: [27583]: --> [7:CONNECT]
feb 28 17:17:04.78: [27583]: <-- data [7]
feb 28 17:17:04.78: [27583]: <-- data [2]
feb 28 17:17:06.75: [27583]: --> [2:OK]
feb 28 17:17:06.75: [27583]: <-- [9:AT+FTS=7\r]
feb 28 17:17:06.83: [27583]: --> [2:OK]
feb 28 17:17:06.83: [27583]: <-- [11:AT+FTM=145\r]
feb 28 17:17:08.31: [27583]: --> [7:CONNECT]
feb 28 17:17:08.31: [27583]: <-- data [1024]
feb 28 17:17:08.31: [27583]: <-- data [1024]
feb 28 17:17:08.31: [27583]: <-- data [652]
feb 28 17:17:08.31: [27583]: <-- data [2]
feb 28 17:17:09.84: [27583]: --> [2:OK]
feb 28 17:17:09.84: [27583]: <-- [9:AT+FRS=1\r]
feb 28 17:17:09.87: [27583]: --> [2:OK]
feb 28 17:17:09.87: [27583]: <-- [9:AT+FRH=3\r]
feb 28 17:17:10.54: [27583]: --> [7:CONNECT]
feb 28 17:17:11.39: [27583]: --> [2:OK]
feb 28 17:17:11.39: [27583]: TRAINING succeeded
feb 28 17:17:11.39: [27583]: SEND begin page
feb 28 17:17:11.41: [27583]: SEND EOFB
feb 28 17:17:11.41: [27583]: SEND send frame number 0
feb 28 17:17:11.41: [27583]: SEND send frame number 1
feb 28 17:17:11.41: [27583]: SEND send frame number 2
feb 28 17:17:11.41: [27583]: SEND send frame number 3
feb 28 17:17:11.41: [27583]: SEND send frame number 4
feb 28 17:17:11.41: [27583]: SEND send frame number 5
feb 28 17:17:11.41: [27583]: SEND send frame number 6
feb 28 17:17:11.41: [27583]: SEND send frame number 7
feb 28 17:17:11.41: [27583]: SEND send frame number 8
feb 28 17:17:11.41: [27583]: SEND send frame number 9
feb 28 17:17:11.41: [27583]: SEND send frame number 10
feb 28 17:17:11.41: [27583]: SEND send frame number 11
feb 28 17:17:11.41: [27583]: SEND send frame number 12
feb 28 17:17:11.41: [27583]: SEND send frame number 13
feb 28 17:17:11.41: [27583]: SEND send frame number 14
feb 28 17:17:11.41: [27583]: SEND send frame number 15
feb 28 17:17:11.41: [27583]: SEND send frame number 16
feb 28 17:17:11.41: [27583]: SEND send frame number 17
feb 28 17:17:11.41: [27583]: SEND send frame number 18
feb 28 17:17:11.41: [27583]: SEND send frame number 19
feb 28 17:17:11.41: [27583]: SEND send frame number 20
feb 28 17:17:11.41: [27583]: SEND send frame number 21
feb 28 17:17:11.41: [27583]: SEND send frame number 22
feb 28 17:17:11.41: [27583]: SEND send frame number 23
feb 28 17:17:11.41: [27583]: SEND send frame number 24
feb 28 17:17:11.41: [27583]: SEND send frame number 25
feb 28 17:17:11.41: [27583]: SEND send frame number 26
feb 28 17:17:11.41: [27583]: SEND send frame number 27
feb 28 17:17:11.41: [27583]: SEND send frame number 28
feb 28 17:17:11.41: [27583]: SEND send frame number 29
feb 28 17:17:11.41: [27583]: SEND send frame number 30
feb 28 17:17:11.41: [27583]: SEND send frame number 31
feb 28 17:17:11.41: [27583]: SEND send frame number 32
feb 28 17:17:11.41: [27583]: SEND send frame number 33
feb 28 17:17:11.41: [27583]: SEND send frame number 34
feb 28 17:17:11.41: [27583]: SEND send frame number 35
feb 28 17:17:11.41: [27583]: SEND send frame number 36
feb 28 17:17:11.41: [27583]: SEND send frame number 37
feb 28 17:17:11.41: [27583]: SEND send frame number 38
feb 28 17:17:11.41: [27583]: SEND send frame number 39
feb 28 17:17:11.41: [27583]: SEND send frame number 40
feb 28 17:17:11.41: [27583]: SEND send frame number 41
feb 28 17:17:11.41: [27583]: SEND send frame number 42
feb 28 17:17:11.41: [27583]: SEND send frame number 43
feb 28 17:17:11.41: [27583]: SEND send frame number 44
feb 28 17:17:11.41: [27583]: SEND send frame number 45
feb 28 17:17:11.41: [27583]: SEND send frame number 46
feb 28 17:17:11.41: [27583]: SEND send frame number 47
feb 28 17:17:11.41: [27583]: SEND send frame number 48
feb 28 17:17:11.41: [27583]: DELAY 200 ms
feb 28 17:17:11.61: [27583]: <-- [11:AT+FTM=146\r]
feb 28 17:17:11.87: [27583]: --> [7:CONNECT]
feb 28 17:17:11.87: [27583]: <-- data [1028]
feb 28 17:17:11.87: [27583]: <-- data [1028]
feb 28 17:17:11.87: [27583]: <-- data [1031]
feb 28 17:17:11.87: [27583]: <-- data [1034]
feb 28 17:17:13.87: [27583]: <-- data [1032]
feb 28 17:17:13.87: [27583]: <-- data [1029]
feb 28 17:17:13.87: [27583]: <-- data [1031]
feb 28 17:17:13.87: [27583]: <-- data [1027]
feb 28 17:17:15.87: [27583]: <-- data [1040]
feb 28 17:17:15.87: [27583]: <-- data [1033]
feb 28 17:17:15.87: [27583]: <-- data [1028]
feb 28 17:17:15.87: [27583]: <-- data [1029]
feb 28 17:17:17.87: [27583]: <-- data [1033]
feb 28 17:17:17.87: [27583]: <-- data [471]
feb 28 17:17:17.87: [27583]: <-- data [2]
feb 28 17:17:19.56: [27583]: --> [2:OK]
feb 28 17:17:19.56: [27583]: <-- [9:AT+FTS=9\r]
feb 28 17:17:19.67: [27583]: --> [2:OK]
feb 28 17:17:19.67: [27583]: <-- [9:AT+FTH=3\r]
feb 28 17:17:19.83: [27583]: --> [7:CONNECT]
feb 28 17:17:19.83: [27583]: <-- data [7]
feb 28 17:17:19.83: [27583]: <-- data [2]
feb 28 17:17:21.11: [27583]: --> [2:OK]
feb 28 17:17:21.11: [27583]: SEND send PPS (partial page signal)
feb 28 17:17:21.11: [27583]: SEND send EOP (no more pages or documents)
feb 28 17:17:21.11: [27583]: <-- [9:AT+FRH=3\r]
feb 28 17:17:21.73: [27583]: --> [7:CONNECT]
feb 28 17:17:22.63: [27583]: --> [2:OK]
feb 28 17:17:22.63: [27583]: SEND recv MCF (message confirmation)
feb 28 17:17:22.63: [27583]: DELAY 70 ms
feb 28 17:17:22.70: [27583]: SEND end page
feb 28 17:17:22.70: [27583]: SEND FAX (000008373): FROM pradelli@xxxxxxxxxxxxxxxx"" TO 0542601921 (page 2 of 2 sent in 0:18)
feb 28 17:17:22.70: [27583]: SEND FAX (000008373): FROM pradelli@xxxxxxxxxxxxxxxx"" TO 0542601921 (docq/doc10143.tif;c1 sent in 0:18)
feb 28 17:17:23.71: [27583]: <-- [9:AT+FTH=3\r]
feb 28 17:17:23.91: [27583]: --> [7:CONNECT]
feb 28 17:17:23.91: [27583]: <-- data [3]
feb 28 17:17:23.91: [27583]: <-- data [2]
feb 28 17:17:25.09: [27583]: --> [2:OK]
feb 28 17:17:25.09: [27583]: <-- [5:ATH0\r]
feb 28 17:17:25.33: [27583]: --> [2:OK]
feb 28 17:17:25.33: [27583]: SESSION END