Re: [hylafax-users] fax log for all black fax

[Dmitry Bely <dbely@mail.ru>]

Lee Howard <faxguy@deanox.com> writes:

> The fax recipient of the fax associated with the following log claimed that
> the faxed page(s) were all black.  I tried the same fax three times, and
> each time he said the pages were black.  I ended up faxing successfully
> with a Canon fax machine manually.
> 
> Faxing to this person isn't critical to my business, but if this log helps
> indicate a protocol bug in HylaFAX...

I don't think that's protocol bug.

> well, that's why I'm posting this.
> The second "<-- data" section seems quite long to me (four minutes!).
> Below the Class 1 log I've listed a Class 2.0 log, which also was from a
> failed fax session (no response to MPS, which reoccurred on all retries).
> Sorry this is long, but I hope it helps with something.

That's OK.

> I'm using RedHat Linux 6.1 with (almost) current CVS HylaFAX.  The modem is
> a US Robotics Sportster 33.6 running in Class 1 mode.  (And for those who
> are keeping track, I seem to have the same number of problem-faxes when
> using Class 1 as I do when using Class 2.0 or Class 2 {when I use a
> Rockwell modem}, although Class 1 is successful with all of my clients'
> machines, so the others aren't really important.  All-in-all, though, the
> failure rate is quite low, on the order of 2-5%, which is comparable to the
> failure rate I had with my manual sheet-fed fax, and comparable to the
> failure rate I have had with other fax software.)
> 
> Thanks.
> 
> Lee.
> 
> Oct 09 15:06:37.41: [ 3931]: SESSION BEGIN 00000972 18173581148
> Oct 09 15:06:37.41: [ 3931]: SEND FAX: JOB 202 DEST 18173581148 COMMID
> 00000972
> Oct 09 15:06:37.41: [ 3931]: MODEM set DTR OFF
> Oct 09 15:06:37.41: [ 3931]: DELAY 2600 ms
> Oct 09 15:06:40.01: [ 3931]: MODEM set DTR ON
> Oct 09 15:06:40.01: [ 3931]: MODEM set baud rate: 38400 baud, input flow
> RTS/CTS, output flow RTS/CTS
> Oct 09 15:06:40.01: [ 3931]: MODEM flush i/o
> Oct 09 15:06:40.01: [ 3931]: <-- [4:ATZ\r]
> Oct 09 15:06:40.14: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.14: [ 3931]: <-- [17:ATE0V1Q0X4S0=0H0\r]
> Oct 09 15:06:40.28: [ 3931]: --> [16:ATE0V1Q0X4S0=0H0]
> Oct 09 15:06:40.28: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.28: [ 3931]: <-- [32:ATS8=2S7=60&H1&I0&R2S13=1&D2&C1\r]
> Oct 09 15:06:40.42: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.42: [ 3931]: <-- [12:AT+FCLASS=1\r]
> Oct 09 15:06:40.56: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.56: [ 3931]: <-- [12:AT&H1&I0&R2\r]
> Oct 09 15:06:40.69: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.69: [ 3931]: <-- [21:AT+FCLASS=0&H1&I0&R2\r]
> Oct 09 15:06:40.83: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.83: [ 3931]: <-- [5:ATM0\r]
> Oct 09 15:06:40.96: [ 3931]: --> [2:OK]
> Oct 09 15:06:40.96: [ 3931]: STATE CHANGE: RUNNING -> SENDING
> Oct 09 15:06:40.96: [ 3931]: MODEM input buffering enabled
> Oct 09 15:06:40.96: [ 3931]: <-- [12:AT+FCLASS=1\r]
> Oct 09 15:06:41.20: [ 3931]: --> [2:OK]
> Oct 09 15:06:41.20: [ 3931]: <-- [12:AT&H1&I0&R2\r]
> Oct 09 15:06:41.43: [ 3931]: --> [2:OK]
> Oct 09 15:06:41.43: [ 3931]: DIAL 18173581148
> Oct 09 15:06:41.43: [ 3931]: <-- [16:ATDT18173581148\r]
> Oct 09 15:06:57.62: [ 3931]: --> [7:CONNECT]
> Oct 09 15:06:57.62: [ 3931]: MODEM input buffering disabled
> Oct 09 15:06:59.09: [ 3931]: --> HDLC<25:FF C0 02 04 04 04 04 04 04 04 04
> 04 04 04 04 04 04 04 04 04 04 04 04 A4 F3>
> Oct 09 15:06:59.09: [ 3931]: --> [2:OK]
> Oct 09 15:06:59.09: [ 3931]: REMOTE CSI ""
> Oct 09 15:06:59.09: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:06:59.10: [ 3931]: --> [7:CONNECT]
> Oct 09 15:06:59.47: [ 3931]: --> HDLC<9:FF C8 01 00 77 1F 22 F8 96>
> Oct 09 15:06:59.47: [ 3931]: --> [2:OK]
> Oct 09 15:06:59.47: [ 3931]: REMOTE best rate 14400 bit/s
> Oct 09 15:06:59.47: [ 3931]: REMOTE max page width 1728 pixels in 215 mm
> Oct 09 15:06:59.47: [ 3931]: REMOTE max unlimited page length 
> Oct 09 15:06:59.47: [ 3931]: REMOTE best vres 7.7 line/mm
> Oct 09 15:06:59.47: [ 3931]: REMOTE best format 2-D MMR
> Oct 09 15:06:59.47: [ 3931]: REMOTE supports T.30 Annex A, ECM
> Oct 09 15:06:59.47: [ 3931]: REMOTE best 0 ms/scanline
> Oct 09 15:06:59.47: [ 3931]: USE 14400 bit/s
> Oct 09 15:06:59.47: [ 3931]: USE 0 ms/scanline
> Oct 09 15:06:59.47: [ 3931]: SEND file "docq/doc202.cover;71"
> Oct 09 15:06:59.47: [ 3931]: USE page width 1728 pixels in 215 mm
> Oct 09 15:06:59.47: [ 3931]: USE unlimited page length 
> Oct 09 15:06:59.47: [ 3931]: USE 7.7 line/mm
> Oct 09 15:06:59.47: [ 3931]: USE 2-D MR
> Oct 09 15:06:59.47: [ 3931]: SEND training at v.17 14400 bit/s
> Oct 09 15:06:59.47: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:06:59.67: [ 3931]: --> [7:CONNECT]
> Oct 09 15:06:59.67: [ 3931]: <-- HDLC<23:FF C0 C2 74 C6 76 92 04 34 1E F6
> 76 86 A6 22 04 04 04 04 04 04 04 04>
> Oct 09 15:06:59.67: [ 3931]: <-- data [23]
> Oct 09 15:06:59.67: [ 3931]: <-- data [2]
> Oct 09 15:06:59.69: [ 3931]: --> [7:CONNECT]
> Oct 09 15:06:59.69: [ 3931]: <-- HDLC<6:FF C8 C1 00 47 1E>
> Oct 09 15:06:59.69: [ 3931]: <-- data [6]
> Oct 09 15:06:59.69: [ 3931]: <-- data [2]
> Oct 09 15:07:01.64: [ 3931]: --> [2:OK]
> Oct 09 15:07:01.64: [ 3931]: DELAY 75 ms
> Oct 09 15:07:01.72: [ 3931]: <-- [11:AT+FTM=145\r]
> Oct 09 15:07:03.20: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:03.20: [ 3931]: <-- data [1024]
> Oct 09 15:07:03.20: [ 3931]: <-- data [1024]
> Oct 09 15:07:03.20: [ 3931]: <-- data [652]
> Oct 09 15:07:03.20: [ 3931]: <-- data [2]
> Oct 09 15:07:04.72: [ 3931]: --> [2:OK]
> Oct 09 15:07:04.72: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:07:05.32: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:06.38: [ 3931]: --> HDLC<5:FF C8 21 57 BE>
> Oct 09 15:07:06.38: [ 3931]: --> [2:OK]
> Oct 09 15:07:06.38: [ 3931]: TRAINING succeeded
> Oct 09 15:07:06.38: [ 3931]: <-- [11:AT+FTM=146\r]
> Oct 09 15:07:06.64: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:06.64: [ 3931]: SEND begin page
> Oct 09 15:07:06.65: [ 3931]: <-- data [1028]
[...]
> Oct 09 15:07:15.11: [ 3931]: <-- data [441]
> Oct 09 15:07:15.11: [ 3931]: SENT 20921 bytes of data

First page was 20 Kbytes of data.

> Oct 09 15:07:15.11: [ 3931]: SEND 2D RTC
> Oct 09 15:07:15.11: [ 3931]: <-- data [30]
> Oct 09 15:07:15.11: [ 3931]: <-- data [2]
> Oct 09 15:07:15.11: [ 3931]: SEND end page
> Oct 09 15:07:18.31: [ 3931]: --> [2:OK]
> Oct 09 15:07:18.31: [ 3931]: DELAY 75 ms
> Oct 09 15:07:18.39: [ 3931]: SEND send MPS (more pages, same document)
> Oct 09 15:07:18.39: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:07:18.54: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:18.54: [ 3931]: <-- HDLC<3:FF C8 F2>
> Oct 09 15:07:18.54: [ 3931]: <-- data [3]
> Oct 09 15:07:18.54: [ 3931]: <-- data [2]
> Oct 09 15:07:19.72: [ 3931]: --> [2:OK]
> Oct 09 15:07:19.72: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:07:20.12: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:21.17: [ 3931]: --> HDLC<5:FF C8 32 75 EC>
> Oct 09 15:07:21.17: [ 3931]: --> [2:OK]
> Oct 09 15:07:21.17: [ 3931]: SEND recv RTN (retrain negative)

The remote did not accepted the page quality...

> Oct 09 15:07:21.17: [ 3931]: SEND training at v.17 12000 bit/s
> Oct 09 15:07:21.17: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:07:21.36: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:21.36: [ 3931]: <-- HDLC<23:FF C0 C2 74 C6 76 92 04 34 1E F6
> 76 86 A6 22 04 04 04 04 04 04 04 04>
> Oct 09 15:07:21.36: [ 3931]: <-- data [23]
> Oct 09 15:07:21.36: [ 3931]: <-- data [2]
> Oct 09 15:07:21.38: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:21.38: [ 3931]: <-- HDLC<6:FF C8 C1 00 57 1E>
> Oct 09 15:07:21.38: [ 3931]: <-- data [6]
> Oct 09 15:07:21.38: [ 3931]: <-- data [2]
> Oct 09 15:07:23.34: [ 3931]: --> [2:OK]
> Oct 09 15:07:23.34: [ 3931]: DELAY 75 ms
> Oct 09 15:07:23.42: [ 3931]: <-- [11:AT+FTM=121\r]
> Oct 09 15:07:24.89: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:24.89: [ 3931]: <-- data [1024]
> Oct 09 15:07:24.89: [ 3931]: <-- data [1024]
> Oct 09 15:07:24.89: [ 3931]: <-- data [202]
> Oct 09 15:07:24.89: [ 3931]: <-- data [2]
> Oct 09 15:07:26.43: [ 3931]: --> [2:OK]
> Oct 09 15:07:26.43: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:07:26.92: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:28.07: [ 3931]: --> HDLC<5:FF C8 22 67 DD>
> Oct 09 15:07:28.07: [ 3931]: --> [2:OK]
> Oct 09 15:07:28.07: [ 3931]: DELAY 1500 ms
> Oct 09 15:07:29.57: [ 3931]: SEND training at v.17 9600 bit/s
> Oct 09 15:07:29.57: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:07:29.76: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:29.76: [ 3931]: <-- HDLC<23:FF C0 C2 74 C6 76 92 04 34 1E F6
> 76 86 A6 22 04 04 04 04 04 04 04 04>
> Oct 09 15:07:29.76: [ 3931]: <-- data [23]
> Oct 09 15:07:29.76: [ 3931]: <-- data [2]
> Oct 09 15:07:29.78: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:29.78: [ 3931]: <-- HDLC<6:FF C8 C1 00 67 1E>
> Oct 09 15:07:29.78: [ 3931]: <-- data [6]
> Oct 09 15:07:29.78: [ 3931]: <-- data [2]
> Oct 09 15:07:31.74: [ 3931]: --> [2:OK]
> Oct 09 15:07:31.74: [ 3931]: DELAY 75 ms
> Oct 09 15:07:31.82: [ 3931]: <-- [10:AT+FTM=97\r]
> Oct 09 15:07:33.29: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:33.29: [ 3931]: <-- data [1024]
> Oct 09 15:07:33.29: [ 3931]: <-- data [776]
> Oct 09 15:07:33.29: [ 3931]: <-- data [2]
> Oct 09 15:07:34.83: [ 3931]: --> [2:OK]
> Oct 09 15:07:34.83: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:07:35.32: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:36.48: [ 3931]: --> HDLC<5:FF C8 22 67 DD>
> Oct 09 15:07:36.48: [ 3931]: --> [2:OK]
> Oct 09 15:07:36.48: [ 3931]: DELAY 1500 ms
> Oct 09 15:07:37.98: [ 3931]: SEND training at v.17 7200 bit/s
> Oct 09 15:07:37.98: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:07:38.17: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:38.17: [ 3931]: <-- HDLC<23:FF C0 C2 74 C6 76 92 04 34 1E F6
> 76 86 A6 22 04 04 04 04 04 04 04 04>
> Oct 09 15:07:38.17: [ 3931]: <-- data [23]
> Oct 09 15:07:38.17: [ 3931]: <-- data [2]
> Oct 09 15:07:38.18: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:38.18: [ 3931]: <-- HDLC<6:FF C8 C1 00 77 1E>
> Oct 09 15:07:38.18: [ 3931]: <-- data [6]
> Oct 09 15:07:38.18: [ 3931]: <-- data [2]
> Oct 09 15:07:40.15: [ 3931]: --> [2:OK]
> Oct 09 15:07:40.15: [ 3931]: DELAY 75 ms
> Oct 09 15:07:40.23: [ 3931]: <-- [10:AT+FTM=73\r]
> Oct 09 15:07:41.70: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:41.70: [ 3931]: <-- data [1024]
> Oct 09 15:07:41.70: [ 3931]: <-- data [326]
> Oct 09 15:07:41.70: [ 3931]: <-- data [2]
> Oct 09 15:07:43.24: [ 3931]: --> [2:OK]
> Oct 09 15:07:43.24: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:07:43.72: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:44.89: [ 3931]: --> HDLC<5:FF C8 21 57 BE>
> Oct 09 15:07:44.89: [ 3931]: --> [2:OK]
> Oct 09 15:07:44.89: [ 3931]: TRAINING succeeded

.. and now we see why. It seems to be that *very* rare case, when RTN means
sudden line quality degradation and is not related to any protocol
bugs. Look, we were able to train at 14400 for the first time, but now only 
training at 7200 has succeeded! Surely something horrible has happened to
the line in the meantime...

> Oct 09 15:07:44.89: [ 3931]: <-- [10:AT+FTM=74\r]
> Oct 09 15:07:45.14: [ 3931]: --> [7:CONNECT]
> Oct 09 15:07:45.14: [ 3931]: SEND begin page
> Oct 09 15:07:45.15: [ 3931]: <-- data [1028]
[...]
> Oct 09 15:08:01.16: [ 3931]: <-- data [441]
> Oct 09 15:08:02.43: [ 3931]: SENT 20921 bytes of data

Sent the same 20 Kbytes of data (first page)

> Oct 09 15:08:02.43: [ 3931]: SEND 2D RTC
> Oct 09 15:08:02.43: [ 3931]: <-- data [30]
> Oct 09 15:08:02.43: [ 3931]: <-- data [2]
> Oct 09 15:08:02.43: [ 3931]: SEND end page
> Oct 09 15:08:08.46: [ 3931]: --> [2:OK]
> Oct 09 15:08:08.46: [ 3931]: DELAY 75 ms
> Oct 09 15:08:08.54: [ 3931]: SEND send MPS (more pages, same document)
> Oct 09 15:08:08.54: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:08:08.69: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:08.69: [ 3931]: <-- HDLC<3:FF C8 F2>
> Oct 09 15:08:08.69: [ 3931]: <-- data [3]
> Oct 09 15:08:08.69: [ 3931]: <-- data [2]
> Oct 09 15:08:09.87: [ 3931]: --> [2:OK]
> Oct 09 15:08:09.87: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:08:10.12: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:11.30: [ 3931]: --> HDLC<5:FF C8 33 65 CD>
> Oct 09 15:08:11.30: [ 3931]: --> [2:OK]
> Oct 09 15:08:11.30: [ 3931]: SEND recv RTP (retrain positive)
> Oct 09 15:08:11.30: [ 3931]: SEND FAX (00000972): FROM amy@deanox.com TO
> 18173581148 (page 1 of 2 sent in 1:12)
> Oct 09 15:08:11.30: [ 3931]: SEND FAX (00000972): FROM amy@deanox.com TO
> 18173581148 (docq/doc202.cover;71 sent in 1:12)
> Oct 09 15:08:11.30: [ 3931]: SEND file "docq/doc312.tif;71"
> Oct 09 15:08:11.31: [ 3931]: USE page width 1728 pixels in 215 mm
> Oct 09 15:08:11.31: [ 3931]: USE unlimited page length 
> Oct 09 15:08:11.31: [ 3931]: USE 7.7 line/mm
> Oct 09 15:08:11.31: [ 3931]: USE 2-D MR
> Oct 09 15:08:11.31: [ 3931]: SEND training at v.17 7200 bit/s
> Oct 09 15:08:11.31: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:08:11.50: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:11.50: [ 3931]: <-- HDLC<23:FF C0 C2 74 C6 76 92 04 34 1E F6
> 76 86 A6 22 04 04 04 04 04 04 04 04>
> Oct 09 15:08:11.50: [ 3931]: <-- data [23]
> Oct 09 15:08:11.50: [ 3931]: <-- data [2]
> Oct 09 15:08:11.51: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:11.51: [ 3931]: <-- HDLC<6:FF C8 C1 00 77 1E>
> Oct 09 15:08:11.51: [ 3931]: <-- data [6]
> Oct 09 15:08:11.51: [ 3931]: <-- data [2]
> Oct 09 15:08:13.48: [ 3931]: --> [2:OK]
> Oct 09 15:08:13.48: [ 3931]: DELAY 75 ms
> Oct 09 15:08:13.56: [ 3931]: <-- [10:AT+FTM=73\r]
> Oct 09 15:08:15.04: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:15.04: [ 3931]: <-- data [1024]
> Oct 09 15:08:15.04: [ 3931]: <-- data [326]
> Oct 09 15:08:15.04: [ 3931]: <-- data [2]
> Oct 09 15:08:16.58: [ 3931]: --> [2:OK]
> Oct 09 15:08:16.58: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:08:17.12: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:18.24: [ 3931]: --> HDLC<5:FF C8 21 57 BE>
> Oct 09 15:08:18.25: [ 3931]: --> [2:OK]
> Oct 09 15:08:18.25: [ 3931]: TRAINING succeeded
> Oct 09 15:08:18.25: [ 3931]: <-- [10:AT+FTM=74\r]
> Oct 09 15:08:18.50: [ 3931]: --> [7:CONNECT]
> Oct 09 15:08:18.50: [ 3931]: SEND begin page
> Oct 09 15:08:18.51: [ 3931]: <-- data [1028]
[...]
> Oct 09 15:12:18.73: [ 3931]: <-- data [563]
> Oct 09 15:12:20.00: [ 3931]: SENT 222771 bytes of data

The second page was above 200 Kbytes! No surprise, that it required more
than 4 minutes to send. But Hylafax itself has nothing to do with it. The
possible reason is that you are trying to send a grayscale image (not a
text). Ghostscript may rasterise it with inacceptable quality (looking
"black" on the other side), and moreover such images are hard to compress
with T.4 algorithms used for fax transmission. That's why we had so much
data to send.

> Oct 09 15:12:20.00: [ 3931]: SEND 2D RTC
> Oct 09 15:12:20.00: [ 3931]: <-- data [30]
> Oct 09 15:12:20.00: [ 3931]: <-- data [2]
> Oct 09 15:12:20.00: [ 3931]: SEND end page
> Oct 09 15:12:26.10: [ 3931]: --> [2:OK]
> Oct 09 15:12:26.10: [ 3931]: DELAY 95 ms
> Oct 09 15:12:26.20: [ 3931]: SEND send EOP (no more pages or documents)
> Oct 09 15:12:26.20: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:12:26.35: [ 3931]: --> [7:CONNECT]
> Oct 09 15:12:26.35: [ 3931]: <-- HDLC<3:FF C8 F4>
> Oct 09 15:12:26.35: [ 3931]: <-- data [3]
> Oct 09 15:12:26.35: [ 3931]: <-- data [2]
> Oct 09 15:12:27.53: [ 3931]: --> [2:OK]
> Oct 09 15:12:27.53: [ 3931]: <-- [9:AT+FRH=3\r]
> Oct 09 15:12:27.92: [ 3931]: --> [7:CONNECT]
> Oct 09 15:12:28.96: [ 3931]: --> HDLC<5:FF C8 31 45 8F>
> Oct 09 15:12:28.96: [ 3931]: --> [2:OK]
> Oct 09 15:12:28.96: [ 3931]: SEND recv MCF (message confirmation)
> Oct 09 15:12:28.96: [ 3931]: SEND FAX (00000972): FROM amy@deanox.com TO
> 18173581148 (page 2 of 2 sent in 4:17)
> Oct 09 15:12:28.96: [ 3931]: SEND FAX (00000972): FROM amy@deanox.com TO
> 18173581148 (docq/doc312.tif;71 sent in 4:17)
> Oct 09 15:12:28.96: [ 3931]: <-- [9:AT+FTH=3\r]
> Oct 09 15:12:29.16: [ 3931]: --> [7:CONNECT]
> Oct 09 15:12:29.16: [ 3931]: <-- HDLC<3:FF C8 DF>
> Oct 09 15:12:29.16: [ 3931]: <-- data [3]
> Oct 09 15:12:29.16: [ 3931]: <-- data [2]
> Oct 09 15:12:30.33: [ 3931]: --> [2:OK]
> Oct 09 15:12:30.33: [ 3931]: MODEM input buffering enabled
> Oct 09 15:12:30.33: [ 3931]: <-- [5:ATH0\r]
> Oct 09 15:12:30.56: [ 3931]: --> [2:OK]
> Oct 09 15:12:30.56: [ 3931]: MODEM set DTR OFF
> Oct 09 15:12:30.56: [ 3931]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
> Oct 09 15:12:30.56: [ 3931]: SESSION END
> 
> (now Class 2.0)
> 
> Oct 15 22:37:01.56: [ 6021]: SESSION BEGIN 00001004 18173581148
> Oct 15 22:37:01.57: [ 6021]: SEND FAX: JOB 206 DEST 18173581148 COMMID
> 00001004
> Oct 15 22:37:01.57: [ 6021]: MODEM set DTR OFF
> Oct 15 22:37:01.57: [ 6021]: DELAY 2600 ms
> Oct 15 22:37:04.16: [ 6021]: MODEM set DTR ON
> Oct 15 22:37:04.16: [ 6021]: MODEM set baud rate: 38400 baud, input flow
> RTS/CTS, output flow RTS/CTS
> Oct 15 22:37:04.16: [ 6021]: MODEM flush i/o
> Oct 15 22:37:04.16: [ 6021]: <-- [4:ATZ\r]
> Oct 15 22:37:04.29: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.29: [ 6021]: <-- [17:ATE0V1Q0X4S0=0H0\r]
> Oct 15 22:37:04.43: [ 6021]: --> [16:ATE0V1Q0X4S0=0H0]
> Oct 15 22:37:04.43: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.43: [ 6021]: <-- [32:ATS8=2S7=60&H1&I0&R2S13=1&D2&C1\r]
> Oct 15 22:37:04.57: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.57: [ 6021]: <-- [14:AT+FCLASS=2.0\r]
> Oct 15 22:37:04.70: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.70: [ 6021]: <-- [9:AT+FLO=2\r]
> Oct 15 22:37:04.83: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.83: [ 6021]: <-- [9:AT+FPP=0\r]
> Oct 15 22:37:04.96: [ 6021]: --> [2:OK]
> Oct 15 22:37:04.96: [ 6021]: <-- [9:AT+FBO=0\r]
> Oct 15 22:37:05.09: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.09: [ 6021]: <-- [10:AT+FCT=30\r]
> Oct 15 22:37:05.22: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.22: [ 6021]: <-- [15:AT+FNR=1,1,1,0\r]
> Oct 15 22:37:05.36: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.36: [ 6021]: <-- [9:AT+FIE=0\r]
> Oct 15 22:37:05.49: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.49: [ 6021]: <-- [3:AT\r]
> Oct 15 22:37:05.62: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.62: [ 6021]: <-- [23:AT+FCC=1,5,2,2,0,0,0,0\r]
> Oct 15 22:37:05.76: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.76: [ 6021]: <-- [5:ATM0\r]
> Oct 15 22:37:05.89: [ 6021]: --> [2:OK]
> Oct 15 22:37:05.89: [ 6021]: STATE CHANGE: RUNNING -> SENDING
> Oct 15 22:37:05.89: [ 6021]: MODEM input buffering enabled
> Oct 15 22:37:05.89: [ 6021]: <-- [14:AT+FCLASS=2.0\r]
> Oct 15 22:37:06.13: [ 6021]: --> [2:OK]
> Oct 15 22:37:06.13: [ 6021]: <-- [9:AT+FLO=2\r]
> Oct 15 22:37:06.36: [ 6021]: --> [2:OK]
> Oct 15 22:37:06.36: [ 6021]: <-- [9:AT+FPP=0\r]
> Oct 15 22:37:06.59: [ 6021]: --> [2:OK]
> Oct 15 22:37:06.59: [ 6021]: <-- [9:AT+FBO=0\r]
> Oct 15 22:37:06.82: [ 6021]: --> [2:OK]
> Oct 15 22:37:06.82: [ 6021]: <-- [10:AT+FCT=30\r]
> Oct 15 22:37:07.05: [ 6021]: --> [2:OK]
> Oct 15 22:37:07.05: [ 6021]: <-- [15:AT+FNR=1,1,1,0\r]
> Oct 15 22:37:07.29: [ 6021]: --> [2:OK]
> Oct 15 22:37:07.29: [ 6021]: <-- [9:AT+FIE=0\r]
> Oct 15 22:37:07.53: [ 6021]: --> [2:OK]
> Oct 15 22:37:07.53: [ 6021]: <-- [3:AT\r]
> Oct 15 22:37:07.76: [ 6021]: --> [2:OK]
> Oct 15 22:37:07.76: [ 6021]: <-- [23:AT+FCC=1,5,2,2,0,0,0,0\r]
> Oct 15 22:37:08.00: [ 6021]: --> [2:OK]
> Oct 15 22:37:08.00: [ 6021]: <-- [22:AT+FLI="Deanox, Inc."\r]
> Oct 15 22:37:08.24: [ 6021]: --> [2:OK]
> Oct 15 22:37:08.25: [ 6021]: DIAL 18173581148
> Oct 15 22:37:08.25: [ 6021]: <-- [16:ATDT18173581148\r]
> Oct 15 22:37:24.12: [ 6021]: --> [4:+FCO]
> Oct 15 22:37:26.25: [ 6021]: --> [27:+FCI:"                    "]
> Oct 15 22:37:26.25: [ 6021]: REMOTE CSI ""
> Oct 15 22:37:26.25: [ 6021]: --> [20:+FIS:1,5,0,2,1,0,0,0]
> Oct 15 22:37:26.25: [ 6021]: --> [2:OK]
> Oct 15 22:37:26.25: [ 6021]: REMOTE best rate 14400 bit/s
> Oct 15 22:37:26.25: [ 6021]: REMOTE max page width 1728 pixels in 215 mm
> Oct 15 22:37:26.25: [ 6021]: REMOTE max unlimited page length 
> Oct 15 22:37:26.25: [ 6021]: REMOTE best vres 7.7 line/mm
> Oct 15 22:37:26.25: [ 6021]: REMOTE best format 2-D MR
> Oct 15 22:37:26.25: [ 6021]: REMOTE best 0 ms/scanline
> Oct 15 22:37:26.25: [ 6021]: USE 14400 bit/s
> Oct 15 22:37:26.25: [ 6021]: USE 0 ms/scanline
> Oct 15 22:37:26.25: [ 6021]: SEND file "docq/doc206.cover;31"
> Oct 15 22:37:26.26: [ 6021]: USE page width 1728 pixels in 215 mm
> Oct 15 22:37:26.26: [ 6021]: USE unlimited page length 
> Oct 15 22:37:26.26: [ 6021]: USE 7.7 line/mm
> Oct 15 22:37:26.26: [ 6021]: USE 1-D MR
> Oct 15 22:37:26.26: [ 6021]: <-- [23:AT+FIS=1,5,0,2,0,0,0,0\r]
> Oct 15 22:37:26.49: [ 6021]: --> [2:OK]
> Oct 15 22:37:26.49: [ 6021]: <-- [7:AT+FDT\r]
> Oct 15 22:37:26.76: [ 6021]: --> [20:+FCS:1,5,0,2,0,0,0,0]
> Oct 15 22:37:33.61: [ 6021]: --> [7:CONNECT]
> Oct 15 22:37:33.61: [ 6021]: SEND begin page
> Oct 15 22:37:49.22: [ 6021]: SENT 33230 bytes of data
> Oct 15 22:37:49.22: [ 6021]: SEND end page
> Oct 15 22:37:49.22: [ 6021]: SEND send MPS (more pages, same document)
> Oct 15 22:38:06.48: [ 6021]: --> [7:+FHS:52]

Usual USR's timing problems; as you already know, their Class2.0 is buggy...

> Oct 15 22:38:06.48: [ 6021]: REMOTE HANGUP: No response to MPS repeated 3 times (code 52)
> Oct 15 22:38:06.48: [ 6021]: <-- [5:ATH0\r]
> Oct 15 22:38:06.62: [ 6021]: --> [2:OK]
> Oct 15 22:38:06.62: [ 6021]: MODEM set DTR OFF
> Oct 15 22:38:06.62: [ 6021]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
> Oct 15 22:38:06.62: [ 6021]: SESSION END

Hope to hear from you soon,
Dmitry


____________________ HylaFAX(tm) Users Mailing List _______________________
 To unsub: mail -s unsubscribe hylafax-users-request@hylafax.org < /dev/null