HylaFAX The world's most advanced open source fax server

[Date Prev][Date Next][Thread Prev][Thread Next] [Date Index] [Thread Index]

Re: [hylafax-users] RECV frame FCS check failed



I respond myself ...
since I upgrade from hylafax-4.2.3-2fc4 to hylafax-4.3.0-2fc4 I don't have anymore the problem apparently.
"RECV frame FCS check failed" error still appear in logs, but faxgetty doesn't freeze anymore ...


thanks anyway .


procaccia a écrit :
hello

my  hylafax system isn't working anymore .
since last friday, nearly every fax received failed to complete.
my config:
$ rpm -q hylafax
hylafax-4.2.3-2fc4
$ cat /etc/redhat-release
Fedora Core release 4 (Stentz)
$ faxstat -ds
HylaFAX scheduler on hylafax.int-evry.fr: Running
Modem ttyS0 (4949): Running and idle
Modem ttyS1 (4333): Receiving from "0298963739"

I got ttyS0 modem dedicated to send, and ttyS1 to receive. When things goes wrong , ttyS1 keeps saying "Receiving from "...."" and faxgetty seems to freeze !?

here a typical session log:

$ less /var/spool/hylafax/log/c000001699

avr 02 15:33:04.59: [18273]: REMOTE wants 14400 bit/s
avr 02 15:33:04.59: [18273]: REMOTE wants A4 page width (215 mm)
avr 02 15:33:04.59: [18273]: REMOTE wants unlimited page length
avr 02 15:33:04.59: [18273]: REMOTE wants 3.85 line/mm
avr 02 15:33:04.59: [18273]: REMOTE wants 2-D MMR
avr 02 15:33:04.59: [18273]: REMOTE wants T.30 Annex A, 256-byte ECM
avr 02 15:33:04.59: [18273]: RECV training at v.17 14400 bit/s
avr 02 15:33:04.59: [18273]: <-- [11:AT+FRM=145\r]
avr 02 15:33:06.04: [18273]: --> [7:CONNECT]
avr 02 15:33:07.91: [18273]: RECV: TCF 2115 bytes, 2% non-zero, 2063 zero-run
avr 02 15:33:07.91: [18273]: --> [10:NO CARRIER]
avr 02 15:33:07.91: [18273]: <-- [9:AT+FRS=7\r]
avr 02 15:33:08.08: [18273]: --> [2:OK]
avr 02 15:33:08.08: [18273]: TRAINING succeeded
avr 02 15:33:08.09: [18273]: <-- [9:AT+FTH=3\r]
avr 02 15:33:08.25: [18273]: --> [7:CONNECT]
avr 02 15:33:18.82: [18273]: RECV frame FCS check failed


avr 02 15:33:21.05: [18273]: RECV frame FCS check failed
avr 02 15:33:21.22: [18273]: Bad HDLC terminating flag received.

avr 02 15:34:39.31: [18273]: RECV FAX (000001699): recvq/fax000001491.tif from 0
298963739, route to <unspecified>, 0 pages in 2:02
avr 02 15:34:39.31: [18273]: RECV FAX: T.30 T2 timeout, expected signal not rece
ived


avr 02 15:34:40.88: [18273]: RECV FAX (000001699): session with 0298963739 termi
nated abnormally: T.30 T2 timeout, expected signal not received
avr 02 15:34:40.89: [18273]: RECV FAX: bin/faxrcvd "recvq/fax000001491.tif" "tty
S1" "000001699" "T.30 T2 timeout, expected signal not received"
avr 02 15:34:40.89: [18273]: RECV FAX: end
avr 02 15:34:40.89: [18273]: SESSION END


An other test , I send myself a fax from ttyS0 to ttyS1:

$ faxstat -ds
HylaFAX scheduler on hylafax.int-evry.fr: Running
Modem ttyS0 (4949): Sending job 94
Modem ttyS1 (4333): Answering the phone

$ faxstat -ds
HylaFAX scheduler on hylafax.int-evry.fr: Running
Modem ttyS0 (4949): Sending job 94
Modem ttyS1 (4333): Receiving from "MAILFAX-INT-EVRY-OUT"

full logs:
[vserver-root@hylafax /var/spool/hylafax/log]
$ cat c000001708
Apr 02 18:06:29.07: [10464]: SESSION BEGIN 000001708 33014333
Apr 02 18:06:29.07: [10464]: HylaFAX (tm) Version 4.2.3
Apr 02 18:06:29.07: [10464]: SEND FAX: JOB 94 DEST 4333 COMMID 000001708 DEVICE '/dev/ttyS0' FROM 'procaccia <jehan.procaccia@xxxxxxxxxxx>' USER uucp
Apr 02 18:06:29.07: [10464]: <-- [12:AT+FCLASS=1\r]
Apr 02 18:06:29.09: [10464]: --> [2:OK]
Apr 02 18:06:29.12: [10464]: DIAL 4333
Apr 02 18:06:29.12: [10464]: <-- [9:ATDT4333\r]
Apr 02 18:06:41.44: [10464]: --> [7:CONNECT]
Apr 02 18:06:43.44: [10464]: --> [2:OK]
Apr 02 18:06:43.44: [10464]: 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 33"
Apr 02 18:06:43.44: [10464]: NSF remote fax equipment: HylaFAX
Apr 02 18:06:43.44: [10464]: NSF remote station ID: "HylaFAX (tm) Version 4.2.3"
Apr 02 18:06:43.44: [10464]: <-- [9:AT+FRH=3\r]
Apr 02 18:06:43.46: [10464]: --> [7:CONNECT]
Apr 02 18:06:44.39: [10464]: --> [2:OK]
Apr 02 18:06:44.39: [10464]: REMOTE CSI "MAILFAX-INT-EVRY-INT"
Apr 02 18:06:44.39: [10464]: <-- [9:AT+FRH=3\r]
Apr 02 18:06:44.57: [10464]: --> [7:CONNECT]
Apr 02 18:06:45.13: [10464]: --> [2:OK]
Apr 02 18:06:45.13: [10464]: REMOTE best rate 14400 bit/s
Apr 02 18:06:45.13: [10464]: REMOTE max A3 page width (303 mm)
Apr 02 18:06:45.13: [10464]: REMOTE max unlimited page length
Apr 02 18:06:45.13: [10464]: REMOTE best vres R16 x 15.4 line/mm
Apr 02 18:06:45.13: [10464]: REMOTE format support: MH, MR, MMR
Apr 02 18:06:45.13: [10464]: REMOTE supports T.30 Annex A, 256-byte ECM
Apr 02 18:06:45.13: [10464]: REMOTE best 0 ms/scanline
Apr 02 18:06:45.13: [10464]: USE 14400 bit/s
Apr 02 18:06:45.13: [10464]: USE error correction mode
Apr 02 18:06:45.13: [10464]: SEND file "docq/cover94;c1"
Apr 02 18:06:45.13: [10464]: USE A4 page width (215 mm)
Apr 02 18:06:45.13: [10464]: USE unlimited page length
Apr 02 18:06:45.13: [10464]: USE 7.7 line/mm
Apr 02 18:06:45.13: [10464]: USE 2-D MMR
Apr 02 18:06:45.13: [10464]: USE 0 ms/scanline
Apr 02 18:06:45.13: [10464]: SEND training at v.17 14400 bit/s
Apr 02 18:06:45.13: [10464]: <-- [9:AT+FRS=7\r]
Apr 02 18:06:45.26: [10464]: --> [2:OK]
Apr 02 18:06:45.26: [10464]: <-- [9:AT+FTH=3\r]
Apr 02 18:06:45.31: [10464]: --> [7:CONNECT]
Apr 02 18:06:45.31: [10464]: <-- data [23]
Apr 02 18:06:45.31: [10464]: <-- data [2]
Apr 02 18:06:47.10: [10464]: --> [7:CONNECT]
Apr 02 18:06:47.10: [10464]: <-- data [7]
Apr 02 18:06:47.10: [10464]: <-- data [2]
Apr 02 18:06:47.56: [10464]: --> [2:OK]
Apr 02 18:06:47.56: [10464]: <-- [9:AT+FTS=7\r]
Apr 02 18:06:47.65: [10464]: --> [2:OK]
Apr 02 18:06:47.65: [10464]: <-- [11:AT+FTM=145\r]
Apr 02 18:06:47.68: [10464]: --> [7:CONNECT]
Apr 02 18:06:47.68: [10464]: <-- data [1024]
Apr 02 18:06:47.68: [10464]: <-- data [1024]
Apr 02 18:06:47.68: [10464]: <-- data [652]
Apr 02 18:06:47.68: [10464]: <-- data [2]
Apr 02 18:06:50.80: [10464]: --> [2:OK]
Apr 02 18:06:50.80: [10464]: <-- [9:AT+FRH=3\r]
Apr 02 18:06:51.82: [10464]: --> [7:CONNECT]
Apr 02 18:06:52.77: [10464]: --> [2:OK]
Apr 02 18:06:52.77: [10464]: TRAINING succeeded
Apr 02 18:06:52.77: [10464]: SEND begin page
Apr 02 18:06:52.79: [10464]: SEND EOFB
Apr 02 18:06:52.79: [10464]: SEND send frame number 0
Apr 02 18:06:52.79: [10464]: SEND send frame number 1
Apr 02 18:06:52.79: [10464]: SEND send frame number 2
Apr 02 18:06:52.79: [10464]: SEND send frame number 3
Apr 02 18:06:52.79: [10464]: SEND send frame number 4
Apr 02 18:06:52.79: [10464]: SEND send frame number 5
Apr 02 18:06:52.79: [10464]: SEND send frame number 6
Apr 02 18:06:52.79: [10464]: SEND send frame number 7
Apr 02 18:06:52.80: [10464]: SEND send frame number 8
Apr 02 18:06:52.80: [10464]: SEND send frame number 9
Apr 02 18:06:52.80: [10464]: SEND send frame number 10
Apr 02 18:06:52.80: [10464]: SEND send frame number 11
Apr 02 18:06:52.80: [10464]: SEND send frame number 12
Apr 02 18:06:52.80: [10464]: SEND send frame number 13
Apr 02 18:06:52.80: [10464]: SEND send frame number 14
Apr 02 18:06:52.80: [10464]: SEND send frame number 15
Apr 02 18:06:52.80: [10464]: SEND send frame number 16
Apr 02 18:06:52.80: [10464]: SEND send frame number 17
Apr 02 18:06:52.80: [10464]: SEND send frame number 18
Apr 02 18:06:52.80: [10464]: SEND send frame number 19
Apr 02 18:06:52.80: [10464]: SEND send frame number 20
Apr 02 18:06:52.80: [10464]: SEND send frame number 21
Apr 02 18:06:52.80: [10464]: SEND send frame number 22
Apr 02 18:06:52.80: [10464]: SEND send frame number 23
Apr 02 18:06:52.80: [10464]: SEND send frame number 24
Apr 02 18:06:52.80: [10464]: SEND send frame number 25
Apr 02 18:06:52.80: [10464]: SEND send frame number 26
Apr 02 18:06:52.80: [10464]: SEND send frame number 27
Apr 02 18:06:52.80: [10464]: SEND send frame number 28
Apr 02 18:06:52.80: [10464]: SEND send frame number 29
Apr 02 18:06:52.80: [10464]: SEND send frame number 30
Apr 02 18:06:52.80: [10464]: SEND send frame number 31
Apr 02 18:06:52.80: [10464]: SEND send frame number 32
Apr 02 18:06:52.80: [10464]: SEND send frame number 33
Apr 02 18:06:52.80: [10464]: SEND send frame number 34
Apr 02 18:06:52.80: [10464]: DELAY 200 ms
Apr 02 18:06:53.00: [10464]: <-- [11:AT+FTM=146\r]
Apr 02 18:06:53.04: [10464]: --> [7:CONNECT]
Apr 02 18:06:53.04: [10464]: <-- data [1025]
Apr 02 18:06:53.04: [10464]: <-- data [1028]
Apr 02 18:06:53.04: [10464]: <-- data [1027]
Apr 02 18:06:53.04: [10464]: <-- data [1026]
Apr 02 18:06:53.04: [10464]: <-- data [1033]
Apr 02 18:06:55.04: [10464]: <-- data [1030]
Apr 02 18:06:55.04: [10464]: <-- data [1032]
Apr 02 18:06:55.04: [10464]: <-- data [1032]
Apr 02 18:06:57.03: [10464]: <-- data [1029]
Apr 02 18:06:57.03: [10464]: <-- data [702]
Apr 02 18:06:57.03: [10464]: <-- data [2]
Apr 02 18:06:59.18: [10464]: --> [2:OK]
Apr 02 18:06:59.18: [10464]: <-- [9:AT+FTS=7\r]
Apr 02 18:06:59.76: [10464]: --> [2:OK]
Apr 02 18:06:59.76: [10464]: <-- [9:AT+FTH=3\r]
Apr 02 18:06:59.80: [10464]: --> [7:CONNECT]
Apr 02 18:06:59.80: [10464]: <-- data [7]
Apr 02 18:06:59.80: [10464]: <-- data [2]
Apr 02 18:07:01.23: [10464]: --> [2:OK]
Apr 02 18:07:01.23: [10464]: SEND send PPS (partial page signal)
Apr 02 18:07:01.23: [10464]: SEND send MPS (more pages, same document)
Apr 02 18:07:01.23: [10464]: <-- [9:AT+FRH=3\r]
Apr 02 18:07:02.14: [10464]: --> [7:CONNECT]
Apr 02 18:07:04.45: [10464]: --> [2:OK]
Apr 02 18:07:04.45: [10464]: SEND recv PPR (partial page request)
Apr 02 18:07:04.45: [10464]: <-- [9:AT+FRS=7\r]
Apr 02 18:07:04.57: [10464]: --> [2:OK]
Apr 02 18:07:04.57: [10464]: SEND send frame number 1
Apr 02 18:07:04.57: [10464]: SEND send frame number 2
Apr 02 18:07:04.57: [10464]: SEND send frame number 3
Apr 02 18:07:04.57: [10464]: SEND send frame number 4
Apr 02 18:07:04.57: [10464]: SEND send frame number 5
Apr 02 18:07:04.57: [10464]: SEND send frame number 9
Apr 02 18:07:04.57: [10464]: SEND send frame number 10
Apr 02 18:07:04.57: [10464]: SEND send frame number 11
Apr 02 18:07:04.57: [10464]: SEND send frame number 13
Apr 02 18:07:04.57: [10464]: SEND send frame number 14
Apr 02 18:07:04.57: [10464]: SEND send frame number 15
Apr 02 18:07:04.57: [10464]: SEND send frame number 16
Apr 02 18:07:04.57: [10464]: SEND send frame number 17
Apr 02 18:07:04.57: [10464]: SEND send frame number 18
Apr 02 18:07:04.57: [10464]: SEND send frame number 19
Apr 02 18:07:04.57: [10464]: SEND send frame number 22
Apr 02 18:07:04.57: [10464]: SEND send frame number 23
Apr 02 18:07:04.57: [10464]: SEND send frame number 25
Apr 02 18:07:04.57: [10464]: SEND send frame number 26
Apr 02 18:07:04.57: [10464]: SEND send frame number 27
Apr 02 18:07:04.57: [10464]: SEND send frame number 28
Apr 02 18:07:04.57: [10464]: SEND send frame number 29
Apr 02 18:07:04.57: [10464]: SEND send frame number 30
Apr 02 18:07:04.57: [10464]: SEND send frame number 32
Apr 02 18:07:04.57: [10464]: SEND send frame number 33
Apr 02 18:07:04.58: [10464]: SEND send frame number 34
Apr 02 18:07:04.58: [10464]: DELAY 200 ms
Apr 02 18:07:04.82: [10464]: <-- [11:AT+FTM=146\r]
Apr 02 18:07:04.95: [10464]: --> [7:CONNECT]
Apr 02 18:07:04.95: [10464]: <-- data [1028]
Apr 02 18:07:04.95: [10464]: <-- data [1026]
Apr 02 18:07:04.95: [10464]: <-- data [1028]
Apr 02 18:07:04.95: [10464]: <-- data [1026]
Apr 02 18:07:04.95: [10464]: <-- data [1031]
Apr 02 18:07:06.95: [10464]: <-- data [1041]
Apr 02 18:07:06.95: [10464]: <-- data [1031]
Apr 02 18:07:06.95: [10464]: <-- data [285]
Apr 02 18:07:06.95: [10464]: <-- data [2]
Apr 02 18:07:09.35: [10464]: --> [2:OK]
Apr 02 18:07:09.35: [10464]: <-- [9:AT+FTS=7\r]
Apr 02 18:07:09.44: [10464]: --> [2:OK]
Apr 02 18:07:09.44: [10464]: <-- [9:AT+FTH=3\r]
Apr 02 18:07:09.53: [10464]: --> [7:CONNECT]
Apr 02 18:07:09.53: [10464]: <-- data [7]
Apr 02 18:07:09.53: [10464]: <-- data [2]
Apr 02 18:07:10.91: [10464]: --> [2:OK]
Apr 02 18:07:10.91: [10464]: SEND send PPS (partial page signal)
Apr 02 18:07:10.91: [10464]: SEND send MPS (more pages, same document)
Apr 02 18:07:10.91: [10464]: <-- [9:AT+FRH=3\r]
Apr 02 18:07:14.02: [10464]: --> [0:]
Apr 02 18:07:14.02: [10464]: MODEM <Empty line>
Apr 02 18:07:14.02: [10464]: <-- data [1]
Apr 02 18:07:14.22: [10464]: MODEM <Timeout>
Apr 02 18:07:14.22: [10464]: <-- [9:AT+FTH=3\r]
Apr 02 18:07:14.48: [10464]: --> [2:OK]
Apr 02 18:07:14.48: [10464]: No response to PPS repeated 3 times.
Apr 02 18:07:14.48: [10464]: SEND end page
Apr 02 18:07:14.48: [10464]: <-- [9:AT+FTH=3\r]
Apr 02 18:07:14.48: [10464]: --> [7:CONNECT]
Apr 02 18:07:14.48: [10464]: <-- data [3]
Apr 02 18:07:14.48: [10464]: <-- data [2]
Apr 02 18:07:15.83: [10464]: --> [2:OK]
Apr 02 18:07:15.83: [10464]: <-- [5:ATH0\r]
Apr 02 18:07:17.37: [10464]: --> [2:OK]
Apr 02 18:07:17.37: [10464]: SESSION END


The fax hasn't been rcieved properly
$ faxstat -ds
HylaFAX scheduler on hylafax.int-evry.fr: Running
Modem ttyS0 (4949): Initializing server
Modem ttyS1 (4333): Receiving from "MAILFAX-INT-EVRY-OUT"

JID Pri S Owner Number Pages Dials TTS Status
94 126 R uucp 4333 0:2 1:12 No response to PPS repeat


the ttys1 keeps saying "Receiving from "MAILFAX-INT-EVRY-OUT"" :-(

an hence now it is busy :-(
$ faxstat -ds
HylaFAX scheduler on hylafax.int-evry.fr: Running
Modem ttyS0 (4949): Running and idle
Modem ttyS1 (4333): Receiving from "MAILFAX-INT-EVRY-OUT"

JID  Pri S  Owner Number       Pages Dials     TTS Status
94   125 S   uucp 4333          0:2   2:12   16:11 Busy signal detected

[vserver-root@hylafax /]
$ ps auwx | grep fax
uucp 27193 0.0 0.2 4564 1500 ? Ss 17:53 0:00 /usr/sbin/faxq
uucp 27196 0.0 0.2 4236 1084 ? Ss 17:53 0:00 /usr/sbin/hfaxd -i hylafax
uucp 32477 0.0 0.3 6724 1940 pts/0 S 17:57 0:00 /usr/sbin/faxgetty ttyS0
uucp 32547 0.0 0.3 6720 2028 pts/0 S 17:57 0:00 /usr/sbin/faxgetty ttyS1


Any idea of what went wrong ?

thanks.






____________________ HylaFAX(tm) Users Mailing List _______________________
 To subscribe/unsubscribe, click http://lists.hylafax.org/cgi-bin/lsg2.cgi
On UNIX: mail -s unsubscribe hylafax-users-request@xxxxxxxxxxx < /dev/null
 *To learn about commercial HylaFAX(tm) support, mail sales@xxxxxxxxx*




Project hosted by iFAX Solutions