[hylafax-devel] Re: Another Class1 question

[Dr. Harald Pollack <Harald.Pollack@Datanews.at>]

On 08 Jun 2000 22:01:01 +0400, Dmitry Bely wrote:

Hello Dmitry!

>> Well, there is a small problem at receivers side,

:-) "small problem" ? :-))) I think it is a HUGE problem, but I hope also, we can solve it.

> if it could not switch fast enough from data 
>> carrier to signal carrier (V.17 or V.29 to V.21), but if first post page message is lost, 
sender 
>> will repeat twice this message (in a window of 15 - 18 seconds), so there is a lot of spare 
time.

It is not the 'fast switching' it is the meaningless timeout wait...

>I have a strange Class1 problem, which I cannot understand without your
>comment. Help!!! :-)

Ok, I will try (but mainly it is black magic and you must believe me :-)

>Here is the log:
>Jun 08 17:17:35.09: [31768]: <-- HDLC<23:FF C0 02 04 04 04 04 04 04 04 04 04 04 04 04 04 04 04 
04 04 04 04 04>
>Jun 08 17:17:35.09: [31768]: <-- data [23]
>Jun 08 17:17:35.10: [31768]: <-- data [2]
>
>send our CSI

OK

>Jun 08 17:17:36.61: [31768]: --> [7:CONNECT]
>Jun 08 17:17:36.61: [31768]: <-- HDLC<10:FF C8 01 00 77 5F 01 79 03 C0>
>Jun 08 17:17:36.61: [31768]: <-- data [10]
>Jun 08 17:17:36.61: [31768]: <-- data [2]
>Jun 08 17:17:37.07: [31768]: --> [2:OK]
>
>... DIS
>
>Jun 08 17:17:37.07: [31768]: <-- [9:AT+FRH=3\r]
>

also OK

>and wait for the response.

Yes, but too long ...

>Jun 08 17:17:41.57: [31768]: --> [0:]
>Jun 08 17:17:41.57: [31768]: MODEM <Empty line>
>Jun 08 17:17:41.57: [31768]: MODEM TIMEOUT: waiting for v.21 carrier

Try a timeout of 2 (TWO) seconds (or maybe less) and cancel AT+FRH=3 state by sending AT\r ... 
modem should response with OK else modem is in undefined state!

>
>still have no CONNECT after 4.5 seconds (T.30 T4 counter). Why?

have wait too long!

>Well, reset the modem, sending CAN character

Use AT\r command instead to force OK response!

>Jun 08 17:17:41.57: [31768]: <-- data [1]
>Jun 08 17:17:41.58: [31768]: --> [2:OK]
>Jun 08 17:17:41.58: [31768]: DELAY 1500 ms

Omitt this delay, because you have lost more than enough time with the former timeout of 4.5 sec.

>
>... and try again

>Jun 08 17:17:45.30: [31768]: <-- [9:AT+FRH=3\r]
>Jun 08 17:17:45.54: [31768]: --> [7:CONNECT]

Well 

>Now we have succeeded! But why failed before?

Obviously, command/response sequence was slightly out of sync (that's why it is repeated :-) In 
class 1 you can see such situations, which will be hidden in class. Do not bother, that's realy 
(sometimes) a normal behaviour, because the T.30 timing values have some 'bandwith', so two 
different faxmachines would not sync always at first try. But as I said before, these is HIDDEN 
in class 2, so it LOOKs like a fault, because you never have seen it before :-)

>Jun 08 17:17:50.65: [31768]: RECV: TCF 2802 bytes, 3% non-zero, 2636 zero-run

:-) TCF check is best done, if you can count continous zero run for at least 1 second (of 1.5 
seconds TCF). This is not a standard value, but it is from my experiences from testing a lot of 
fax machines, how small a TCF could be (less than 1.5 sec) in worst case. Some machines need not 
more than 0.5 sec zero run, other need 1 second, but I have not seen any machine, which needs 
MORE than 1 sec zero run. this is only a hint.

>Jun 08 17:17:52.03: [31768]: MODEM input buffering enabled
>Jun 08 17:17:52.03: [31768]: MODEM set XON/XOFF/FLUSH: input ignored, output generated
>Jun 08 17:17:52.03: [31768]: <-- [11:AT+FRM=146\r]
>Jun 08 17:17:52.92: [31768]: --> [7:CONNECT]

OK, looks very good (and VERY FAST :-)


>Jun 08 17:17:52.92: [31768]: RECV: begin page
>Jun 08 17:18:20.17: [31768]: RECV/CQ: Bad 1D pixel count, row 1142, got 0, expected 1728
>Jun 08 17:18:20.19: [31768]: RECV/CQ: Bad 1D pixel count, row 1143, got 0, expected 1728
>Jun 08 17:18:20.19: [31768]: RECV/CQ: Bad 1D pixel count, row 1144, got 0, expected 1728
>Jun 08 17:18:20.19: [31768]: RECV/CQ: Bad 1D pixel count, row 1145, got 0, expected 1728
>Jun 08 17:18:20.19: [31768]: RECV/CQ: Bad 1D pixel count, row 1146, got 0, expected 1728
>
>... found RTC

Are you sure ? I hope so. From this moment on, discard any received bit and wait for <DLE><ETX> 
A_N_D "NO CARRIER" sequence in parallel. Mainly USR brand modems in class 1 loose sometimes the 
DLE+ETX and they only send 'NO CARRIER' (but this can cost a lot of time for you).

>Jun 08 17:18:20.26: [31768]: RECV/CQ: Bad 1D pixel count, row 1147, got 425, expected 1728
>Jun 08 17:18:20.26: [31768]: RECV/CQ: Bad 1D pixel count, row 1148, got 1867, expected 1728
>Jun 08 17:18:20.49: [31768]: RECV/CQ: Bad 1D pixel count, row 1149, got 1853, expected 1728
>Jun 08 17:18:20.79: [31768]: RECV/CQ: Invalid EOL code word, row 1150, x 255
>Jun 08 17:18:20.79: [31768]: RECV/CQ: Bad 2D pixel count, row 1150, got 255, expected 1728
>Jun 08 17:18:20.79: [31768]: RECV/CQ: Invalid WhiteTable code word, row 1151, x 29
>Jun 08 17:18:20.79: [31768]: RECV/CQ: Bad 1D pixel count, row 1151, got 29, expected 1728
>Jun 08 17:18:21.00: [31768]: RECV/CQ: Bad 2D pixel count, row 1152, got 1729, expected 1728
>Jun 08 17:18:21.08: [31768]: RECV/CQ: Bad 1D pixel count, row 1153, got 2993, expected 1728
>Jun 08 17:18:21.63: [31768]: RECV/CQ: Adjusting for trailing noise (12 run)
>Jun 08 17:18:21.63: [31768]: RECV: 1142 total lines, 0 bad lines, 0 consecutive bad lines
>Jun 08 17:18:21.63: [31768]: RECV: end page
>Jun 08 17:18:21.63: [31768]: --> [10:NO CARRIER]

I miss the explicit detection of DLE+ETX. Watch the log time! You have found RTC at 17:18:20.19 
and you mark 'NO CARRIER' at 17:18:21.63 (which is 1.5 seconds). Seems that you have lost time 
while trying to decode waste bits instead of reading modem response. Can not happen, if program 
is multithreaded :-)

>
>What is why I presume to disturb you. :-)) Remote has not immediately
>dropped the carrier after RTC!!!

Yes, you MUST NOT assume, that sender will do so! But sender starts its own 75ms wait time after 
RTC. So in fact these 75 ms are the time, phase C carrier decreases slowly.

>Or our DCE has not detected its loss and eaten 
>PPM as Phase C data? Or what???

I assume, that fax software itself has eaten the time while trying to decode sensles bits after 
RTC. Keep in mind, you have choosen 14400 bps, so there is space for a lot of waste bits between 
RTC and V.21 carrier.

>Jun 08 17:18:21.63: [31768]: MODEM set XON/XOFF/DRAIN: input ignored, output disabled
>Jun 08 17:18:21.63: [31768]: MODEM input buffering disabled
>Jun 08 17:18:21.63: [31768]: <-- [9:AT+FRH=3\r]
>
>We are still trying to detect PPM...

Yes, but completly out of command/response cycle (out of sync). This is also a problem in class 
2/2.0 but not so obvious to see :-)

>Jun 08 17:19:01.62: [31768]: --> [0:]
>Jun 08 17:19:01.62: [31768]: MODEM <Empty line>
>Jun 08 17:19:01.62: [31768]: MODEM TIMEOUT: waiting for v.21 carrier
>
>... but with no luck even after 40 secs (T.30 T1 timer)

You can close the door after 20 sec as well :-) And you can start this timeout exactly, when 
detecting RTC...

>
>Do you have any idea why all this can happen?

As I said, I assume that fax software spent a lot of time (too much) to decode bits after RTC and 
does not read quick enough DEL+ETX and/or 'NO CARRIER' response from modem. But this is only a 
theorie. I can do only a diagnosis, if I can receive with my OS/2 fax software (and also a well 
known PC), where I K_N_O_W exactly the timeing behaviour.


Mit herzlichen Gruessen / Yours sincerely

Dr. Harald Pollack

Harald.Pollack@DATAnews.at


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