Re: [hylafax-users] Problems with Tobit-Faxware/David as TX

[Lee Howard <faxguy@xxxxxxxxxxxxxxxx>]

I comment the session log in-line below.

On 2004.09.14 03:05 roland klose wrote:
> Hi,
>
> I've problems to receive documents if the sender use
> Tobit-Faxware/David.
>
> On my Site I use HylaFAX 4.2.0 with Sitecom Modems (Cirrus Logic
> CL-MD56xx/CD08.55). Faxsetup doesn't find the right Modem first, so I
> now use
> the cirrus config file.
>
> All runs best, only the above mentioned senders makes trouble.

Tobit-Faxware/David is a fax machine or software?

> Here is the excerpt form the receive log:
>
> ------ cut here --------
>
> The full document was not received because:
>
>     Failed to properly detect high-speed data carrier.
>
>     ---- Transcript of session follows ----
>
> Sep 13 15:24:39.35: [29289]: SESSION BEGIN 000002785 494222xxxxxx
> Sep 13 15:24:39.35: [29289]: HylaFAX (tm) Version 4.2.0
> Sep 13 15:24:39.35: [29289]: <-- [4:ATA\r]
> Sep 13 15:24:42.47: [29289]: --> [7:CONNECT]
> Sep 13 15:24:42.47: [29289]: ANSWER: FAX CONNECTION  DEVICE
> '/dev/ttyS0'
> Sep 13 15:24:42.48: [29289]: RECV FAX: begin
> Sep 13 15:24:44.36: [29289]: --> [7:CONNECT]
> Sep 13 15:24:45.11: [29289]: --> [7:CONNECT]
> Sep 13 15:24:45.60: [29289]: --> [2:OK]
> Sep 13 15:24:45.60: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:24:45.83: [29289]: --> [7:CONNECT]
> Sep 13 15:24:47.48: [29289]: --> [2:OK]
> Sep 13 15:24:47.48: [29289]: REMOTE TSI "+49 209 xxxxxx"
> Sep 13 15:24:47.48: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:24:47.50: [29289]: --> [7:CONNECT]
> Sep 13 15:24:47.75: [29289]: --> [2:OK]
> Sep 13 15:24:47.75: [29289]: REMOTE wants 14400 bit/s
> Sep 13 15:24:47.75: [29289]: REMOTE wants A4 page width (215 mm)
> Sep 13 15:24:47.75: [29289]: REMOTE wants unlimited page length
> Sep 13 15:24:47.75: [29289]: REMOTE wants 7.7 line/mm
> Sep 13 15:24:47.75: [29289]: REMOTE wants 1-D MH
> Sep 13 15:24:47.75: [29289]: REMOTE wants T.30 Annex A, 256-byte ECM
> Sep 13 15:24:47.75: [29289]: RECV training at v.17 14400 bit/s
> Sep 13 15:24:47.75: [29289]: <-- [11:AT+FRM=145\r]
> Sep 13 15:24:49.28: [29289]: --> [7:CONNECT]
> Sep 13 15:24:50.66: [29289]: RECV: TCF 2464 bytes, 0% non-zero, 2455
> zero-run
> Sep 13 15:24:50.66: [29289]: --> [10:NO CARRIER]
> Sep 13 15:24:50.66: [29289]: DELAY 75 ms
> Sep 13 15:24:50.74: [29289]: TRAINING succeeded
> Sep 13 15:24:50.74: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:24:50.92: [29289]: --> [7:CONNECT]
> Sep 13 15:24:52.20: [29289]: --> [2:OK]
> Sep 13 15:24:52.20: [29289]: <-- [11:AT+FRM=146\r]
> Sep 13 15:24:52.56: [29289]: --> [7:CONNECT]
> Sep 13 15:24:52.98: [29289]: RECV received frame number 0
> Sep 13 15:24:53.13: [29289]: RECV received frame number 1
> Sep 13 15:24:53.34: [29289]: RECV received frame number 2
> Sep 13 15:24:53.48: [29289]: RECV received frame number 3
>
> ....  many lines deleted (same text) ....
>
> Sep 13 15:25:08.48: [29289]: RECV received frame number 105
> Sep 13 15:25:08.63: [29289]: RECV received frame number 106
> Sep 13 15:25:08.77: [29289]: RECV received frame number 107
> Sep 13 15:25:08.91: [29289]: RECV received frame number 108
> Sep 13 15:25:09.09: [29289]: RECV assumed RCP frame with block end
> Sep 13 15:25:09.09: [29289]: --> [10:NO CARRIER]
> Sep 13 15:25:09.09: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:25:09.12: [29289]: --> [7:CONNECT]
> Sep 13 15:25:10.30: [29289]: --> [2:OK]
> Sep 13 15:25:10.30: [29289]: RECV recv PPS (partial page signal)
> Sep 13 15:25:10.30: [29289]: RECV recv EOP (no more pages or
> documents)
> Sep 13 15:25:10.30: [29289]: RECV received 110 frames of block 1 of
> page 1

This tells us that we're missing frame numbered 109.  (We received 
0-108, but the sender says that it sent 110 count.)  Notice that the 
RCP signal is being assumed from the block ending (carrier drop).  It 
is entirely possible that the sender is dropping its carrier before it 
actually pushes out the data.  Many senders do this.  Usually the 
missing data will get through in a retransmission...

> Sep 13 15:25:10.30: [29289]: DELAY 70 ms
> Sep 13 15:25:10.37: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:25:10.55: [29289]: --> [7:CONNECT]
> Sep 13 15:25:12.79: [29289]: --> [2:OK]
> Sep 13 15:25:12.79: [29289]: RECV send PPR (partial page request)
> Sep 13 15:25:12.79: [29289]: <-- [11:AT+FRM=146\r]
> Sep 13 15:25:13.14: [29289]: --> [7:CONNECT]
> Sep 13 15:25:13.61: [29289]: RECV assumed RCP frame with block end
> Sep 13 15:25:13.61: [29289]: --> [10:NO CARRIER]
> Sep 13 15:25:13.61: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:25:13.64: [29289]: --> [7:CONNECT]
> Sep 13 15:25:14.82: [29289]: --> [2:OK]
> Sep 13 15:25:14.82: [29289]: RECV recv PPS (partial page signal)
> Sep 13 15:25:14.82: [29289]: RECV recv EOP (no more pages or
> documents)
> Sep 13 15:25:14.82: [29289]: RECV received 1 frames of block 1 of page
> 1

It says that it sent 1 frame, but I don't see it.  Furthermore, the RCP 
frame is assumed again, so we know for certain that we're not seeing 
the requisite RCP frames.  If you turned up the logging even more you 
could see exactly the data bytes that we are receiving.

It is possible that your modem is reporting NO CARRIER before it relays 
all of the data that is has received.  If so, switching modems (to 
another make/model) should resolve this.

> Sep 13 15:25:14.82: [29289]: DELAY 70 ms
> Sep 13 15:25:14.89: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:25:15.06: [29289]: --> [7:CONNECT]
> Sep 13 15:25:17.30: [29289]: --> [2:OK]
> Sep 13 15:25:17.30: [29289]: RECV send PPR (partial page request)
> Sep 13 15:25:17.30: [29289]: <-- [11:AT+FRM=146\r]
> Sep 13 15:25:17.65: [29289]: --> [7:CONNECT]
> Sep 13 15:25:18.12: [29289]: RECV assumed RCP frame with block end
> Sep 13 15:25:18.12: [29289]: --> [10:NO CARRIER]
> Sep 13 15:25:18.12: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:25:18.15: [29289]: --> [7:CONNECT]
> Sep 13 15:25:19.32: [29289]: --> [2:OK]
> Sep 13 15:25:19.32: [29289]: RECV recv PPS (partial page signal)
> Sep 13 15:25:19.32: [29289]: RECV recv EOP (no more pages or
> documents)
> Sep 13 15:25:19.32: [29289]: RECV received 1 frames of block 1 of page
> 1

Again, same problem.

> Sep 13 15:25:19.32: [29289]: DELAY 70 ms
> Sep 13 15:25:19.39: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:25:19.57: [29289]: --> [7:CONNECT]
> Sep 13 15:25:21.81: [29289]: --> [2:OK]
> Sep 13 15:25:21.81: [29289]: RECV send PPR (partial page request)
> Sep 13 15:25:21.81: [29289]: <-- [11:AT+FRM=146\r]
> Sep 13 15:25:22.16: [29289]: --> [7:CONNECT]
> Sep 13 15:25:22.63: [29289]: RECV assumed RCP frame with block end
> Sep 13 15:25:22.63: [29289]: --> [10:NO CARRIER]
> Sep 13 15:25:22.63: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:25:22.66: [29289]: --> [7:CONNECT]
> Sep 13 15:25:23.84: [29289]: --> [2:OK]
> Sep 13 15:25:23.84: [29289]: RECV recv PPS (partial page signal)
> Sep 13 15:25:23.84: [29289]: RECV recv EOP (no more pages or
> documents)
> Sep 13 15:25:23.84: [29289]: RECV received 1 frames of block 1 of page
> 1

And again...

> Sep 13 15:25:23.84: [29289]: DELAY 70 ms
> Sep 13 15:25:23.91: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:25:24.08: [29289]: --> [7:CONNECT]
> Sep 13 15:25:26.32: [29289]: --> [2:OK]
> Sep 13 15:25:26.32: [29289]: RECV send PPR (partial page request)
> Sep 13 15:25:26.32: [29289]: RECV sent fourth PPR
> Sep 13 15:25:26.32: [29289]: <-- [9:AT+FRH=3\r]
> Sep 13 15:25:26.45: [29289]: --> [7:CONNECT]
> Sep 13 15:25:27.60: [29289]: --> [2:OK]
> Sep 13 15:25:27.60: [29289]: RECV recv CTC (continue to correct)

After the 4th time we transmit PPR the sender is expected (in non-V.34 
sessions) to signal CTC (continue to correct) or EOR (end 
retransmissions).  If it signals CTC, then it can change the bitrate.

> Sep 13 15:25:27.60: [29289]: DELAY 70 ms
> Sep 13 15:25:27.67: [29289]: <-- [9:AT+FTH=3\r]
> Sep 13 15:25:27.85: [29289]: --> [7:CONNECT]
> Sep 13 15:25:29.14: [29289]: --> [2:OK]
> Sep 13 15:25:29.14: [29289]: RECV send CTR (confirm continue to
> correct)
> Sep 13 15:25:29.14: [29289]: <-- [11:AT+FRM=145\r]
> Sep 13 15:25:36.13: [29289]: RECV keeping unconfirmed page

Notice these timestamps.  The modem gave no response for 7 seconds.  So 
either the modem is having a problem here, or the sender is not obeying 
T.30 5 Note 5  (which requires it to use long training on the first 
high-speed session following CTC).  Most likely the problem is with 
your modem.  If you must keep your modem try disabling ECM 
(Class1ECMSupport: no).

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*