Re: [hylafax-users] Send fax ERRORS: COMREC invalid response received to PPS - No response to PPS repeated 3 times

[Lee Howard <faxguy@xxxxxxxxxxxxxxxx>]

Luigi Carrieri wrote:

> I performed the tests as you suggested and here is the results
> (see log files in attached archive for more details).
>  

Thanks.  I'm going to go through them with you here in detail... and 
hopefully by the end I'll have some ideas as far as how to fix the problem.

> Receiving fax equipments are:
> 06XXXX7608 Lanier 5227
> 06XXXX7586 Lanier 5020 MFD
>  

Okay.  So the tests are with machines of the same manufacturer.  
Interesting that the NSF signal they use indicates "Ricoh" instead of 
Lanier.

> Test 1
> ModemSoftRTFCC: YES
> Class1ECMSupport:	default
>
> echo " " | sendfax -n -F "" -t  1 -T 1 -d 06XXXX7608 (blank page)
> Result OK - log file c000001246
>  

Okay, V.34-Fax in Class 1.0 with MMR compression.  It's a small fax, but 
all looks good there.  It would seem to indicate that HylaFAX's EOFB 
signalling and ECM protocol and also the modem's V.34-Fax behavior is 
basically acceptable to the Lanier 5227 receiver.

> sendfax -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc22pg.pdf (22 pages)
> Result KO - log file c000001256 (COMREC invalid response received to PPS)
> Stopped at page 9
>  

Interesting.

> sendfax -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc14pg.pdf (14 pages)
> Result KO - log file c000001262 (COMREC invalid response received to PPS)
> Stopped at page 2
>  

Again, this is interesting.  So in this last case it printed out 2 
pages, but in the case before it only 9 pages were printed.  It's 
interesting because in the previous case 10 pages were transmitted, and 
the DCN was received after the 10th page of transmit... yet only 9 
printed.  In this last case 2 pages were transmitted and 2 pages were 
printed, and the DCN was received after the 2nd page of transmit.

> echo " " |  sendfax -n -F "" -t  1 -T 1 -d 06XXXX7586 (blank page)
> Result OK - log file c000001264
>  

Okay.  This receiver is similar to the one above, but it does not appear 
to support V.34-Fax.

> sendfax -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc22pg.pdf (22 pages)
> Result KO - log file c000001266 (No response to PPS repeated 3 times)
> Stopped at page 10
>  

This is interesting in that page 10 printed this time, and the receiver 
did not transmit DCN as far as we can tell, but it's very interesting 
that it failed at nearly the same time.

> sendfax -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc14pg.pdf (14 pages)
> Result KO - log file c000001267 (No response to PPS repeated 3 times)
> Stopped at page 2
>  

And this is inversely similar in that 3 pages are transmitted but only 2 
print.

> Test 2
> ModemSoftRTFCC: YES
> Class1ECMSupport:	default
>
> echo " " | sendfax -1 -n -F "" -t 1 -T 1 -d 06XXXX7608 (blank page)
> Result OK - log file c000001269
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc22pg.pdf (22 pages)
> Result OK - log file c000001274
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc14pg.pdf (14 pages)
> Result OK - log file c000001275
>  

The effect of putting the "-1" on there is that it causes faxq (via 
Ghostscript) to format the document with MH compression, but then 
faxsend will convert the document to MMR on-the-fly.  The fact that 
these worked but that two of them failed in the test without "-1" would 
normally lead me to start thinking that there is some problem with the 
TIFF file as produced by Ghostscript ... except that these all use MMR 
compression in the end... so all of the Ghostscript-produced TIFF has 
been through HylaFAX's G3Decoder and G3Decoder.

In theory the actual data being communicated should be exactly the same 
as above.

> echo " " | sendfax -1 -n -F "" -t 1 -T 1 -d 06XXXX7586 (blank page)
> Result OK - log file c000001270
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc22pg.pdf (22 pages)
> Result OK - log file c000001272
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc14pg.pdf (14 pages)
> Result KO - log file c000001276 (Unspecified Transmit Phase C error)
>  

Apr 16 16:10:47.44: [29121]: <-- [11:AT+FTM=146\r]
Apr 16 16:10:47.46: [29121]: --> [7:CONNECT]
....
Apr 16 16:10:58.25: [29121]: --> [5:ERROR]
Apr 16 16:10:58.25: [29121]: <-- [9:AT+FTH=3\r]
Apr 16 16:10:58.25: [29121]: --> [48:^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H]
Apr 16 16:10:58.25: [29121]: <-- [5:ATH0\r]
Apr 16 16:10:58.25: [29121]: --> [5:ERROR]

This, to me, looks like modem malfunction.  I'm not sure if I should 
read more into it than that.

> Test 3
> ModemSoftRTFCC: NO
> Class1ECMSupport:	default
>
> echo " " | sendfax -1 -n -F "" -t 1 -T 1 -d 06XXXX7608 (blank page)
> Result OK - log file c000001277
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc22pg.pdf (22 pages)
> Result OK  - log file c000001279
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7608 /tmp/doc14pg.pdf (14 pages)
> Result OK - log file c000001281
>  

This test is like the one above, but it does not involve RTFCC ... so 
the fax is actually compressed and sent as MH.

> echo " " | sendfax -1 -n -F "" -t 1 -T 1 -d 06XXXX7586 (blank page)
> Result OK - log file c000001278
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc22pg.pdf (22 pages)
> Result KO - log file c000001280 (Unspecified Transmit Phase C error)
>
> sendfax -1 -n -F "" -t  1 -T 1 -d 06XXXX7586 /tmp/doc14pg.pdf (14 pages)
> Result KO - log file c000001282 (Failure to train remote modem at 2400 bps
> or minimum speed)
>  

Apr 16 16:22:20.57: [30607]: <-- [11:AT+FTM=146\r]
Apr 16 16:22:20.59: [30607]: --> [7:CONNECT]
.....
Apr 16 16:22:37.92: [30607]: --> [5:ERROR]
Apr 16 16:22:37.92: [30607]: <-- [9:AT+FTH=3\r]
Apr 16 16:22:37.92: [30607]: --> [598:^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^ÊERROR^Ê^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H 
^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H^H ^H]

Again, c000001280 looks suspiciously like a modem malfunction.

Apr 16 16:28:37.23: [31234]: <-- [11:AT+FTM=145\r]
Apr 16 16:28:37.24: [31234]: --> [7:CONNECT]
Apr 16 16:28:37.24: [31234]: DELAY 400 ms
Apr 16 16:28:37.64: [31234]: <-- data [1024]
Apr 16 16:28:37.72: [31234]: <-- data [1024]
Apr 16 16:28:37.81: [31234]: <-- data [652]
Apr 16 16:28:45.02: [31234]: <-- data [2]
Apr 16 16:28:45.02: [31234]: --> [5:ERROR]

And again, c000001282 also looks like a modem malfunction.  The only 
time that ERROR should result after AT+FTM=n, CONNECT should be if five 
seconds elapse with no data from the DTE (HylaFAX).  Aha!  Notice the 
timestamps there.  This is 14400 bps.  Notice that it took 7.21 seconds 
to transmit 652 bytes (what should have merely taken ~0.36 second).

And now if I go back and look at c000001280 I notice this:

Apr 16 16:22:29.33: [30607]: <-- data [1025]
Apr 16 16:22:35.87: [30607]: <-- data [1026]

That's 6.54 seconds for 1025 bytes that should have gone through in 
~0.57 second.

And also if I go back and look at c000001276 I notice:

Apr 16 16:10:50.51: [29121]: <-- data [1044]
Apr 16 16:10:57.08: [29121]: <-- data [1039]

So I think that we've found a key indicator of what the problem may 
actually be.  Something is wrong with either the modem itself in 
accepting the serial data, the serial driver for the OS, or the serial 
infrastructure (motherboard serial port if this is an external modem), 
or system latency (like, did the CPU max out at some point here?).  
Essentially something is going wrong in reliably communicating timed 
serial data from the DTE (HylaFAX) to the DCE (modem).

Normally I'd stop here and say to fix that first, since it's such a 
fundamental issue that seems to be problematic.  It would not be good to 
go chasing ghosts with other things.  But I will go through the rest of 
the logs now... but understand that it is entirely possible/plausible to 
conclude that the vast majority of these problems are caused by the same 
thing - only that maybe it's not as easily observable in other cases.

> Test 4
> ModemSoftRTFCC: NO
> Class1ECMSupport:	default
>
> echo " " | sendfax -n -F "" -E -t 1 -T 1 -d 06XXXX7608 (blank page)
> Result KO - log file c000001291 (No carrier detected) 1st try
> Result KO - log file c000001296 (No local dialtone) 2nd try
>
> sendfax -n -F "" -E -t 1 -T 1 -d 06XXXX7608 /tmp/doc22pg.pdf (22 pages)
> Result KO - log file c000001293 (No local dialtone)
>  

These seem to be some kind of telephone network problem on your end.  
Are you using a PBX?

> echo " " | sendfax -n -F "" -E -t 1 -T 1 -d 06XXXX7586 (blank page)
> Result OK - log file c000001288
>
> sendfax -n -F "" -E -t 1 -T 1 -d 06XXXX7586 /tmp/doc22pg.pdf (22 pages)
> Result OK - log file c000001292
>  

It seems that the 7586 machine prefers non-ECM.

> Sending a blank page worked fine for all tests except the 4th with the
> 7608 fax machine.
> Best results seems to be achieved with ModemSoftRTFCC enabled and the "-1"
> sendfax option.

Well, that may simply be lucky.  The underlying problem (the serial 
communication issue) could surface but occasionally and would mess with 
this kind of statistical analysis as to which method is "best".  The 
testing wasn't really designed to find a workaround or a "best" 
scenario... but rather it was designed to test to see if any particular 
aspect of HylaFAX is in error.  If the serial communication problem is 
ever allowing the modem's transmit buffer to underrun then there could 
be problems at that time.

> We use hylafax as a mail-to-fax gateway: how can I
> configure faxmail to use the "-1" option?
>  

faxmail doesn't have an option corresponding to sendfax's "-1" option.  
I could program one in.  You could avoid using faxmail and use a sendfax 
wrapper script in its place, but in the end I think that you need to 
remedy your underlying issue and ignore the impulse to want to chase 
down this "sendfax -1" lead.  The underlying problem needs to be fixed, 
and then the testing needs to be redone.

I would start by trying a different modem... a different brand, a 
different model.  This is an Agere/Lucent modem.  Maybe find some Class 
1 Rockwell/Conexant modem out there and test that one.  Maybe try a USR 
modem in Class 1.  (I said *try* a USR modem - not *use* a USR modem.)  
That would tell you if the problem is with the modem.  It may not be a 
fair comparison, however, if you test with an external serial modem but 
your Agere/Lucent modem is a PCI one.

If the modem isn't the problem then I would watch your system behavior 
over time very, very closely.  Make sure that the CPU usage doesn't 
spike every once in a while.  Make sure that the disk usage doesn't spike.

Lee.


____________________ 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*