Re: [hylafax-users] Infinite loop, defunct faxgetty

[Lee Howard <faxguy@xxxxxxxxxxxxxxxx>]

No, this isn't normal behavior.  And, from what I can tell, this isn't 
to do with line conditions, either.

Can you describe, however, the connection between the sender and the 
receiver?  Are they connected directly, or are they going through a 
relay of some kind?

On 2005.01.03 08:10 Giulio Orsero wrote:

> Jan 03 16:53:58.41: [ 2113]: <-- [11:AT+FRM=146\r]
> Jan 03 16:53:58.41: [ 2113]: <-- <10:41 54 2B 46 52 4D 3D 31 34 36>
> Jan 03 16:53:58.41: [ 2113]: <-- <1:0D>
> Jan 03 16:53:59.08: [ 2113]: --> <144:0D 0A 43 4F 4E 4E 45 43 54 0D 0A
> 6E DB 34 8F F3 FF FF FF FF FF FF FF FF FF FF FF EF E7 E7 E7 E7 E7 E7

There is some garbage here (6E DB 34 8F F3) before the normal FF FF FF 
or 7E 7E 7E 7E 7E sequence began.  I spent some time trying to figure 
out if this was the cause of the problem, but I don't think that it 
was.  It looks like faxgetty correctly determined that it was garbage 
and just ignored it.  I say that because there is no logging of an 
error at this point (just after "CONNECT" below).

> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7>
> Jan 03 16:53:59.08: [ 2113]: --> [7:CONNECT]
> Jan 03 16:53:59.15: [ 2113]: --> <128:E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7>
> Jan 03 16:53:59.22: [ 2113]: --> <128:E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 F7 7D 80 01 C0 37 B7 DA E4 C4 7A
> 9E 09>
> Jan 03 16:53:59.29: [ 2113]: --> <128:C7 7A 0E 91 9B C2 2C 08 D5 91 60
> D2 11 72 A6 5D 85 C8 99 6A 13 8E 9C 29 61 3E E2 83 B2 30 07 CA 67 6E
> 12 4C 0C CA 35 A2 11 37 14 4A BB 2A 42 CA A8 15 81 63 89 92 42 B0 60
> 09 82 41 25 08 86 60 08 1E 14 F2 90 05 0B 86 60 50 C1 90 21 78 C8 43
> 30 E4 0B F9 3C E8 03 9D C7 D4 F8 78 84 9E 8F 79 CC 63 2E 29 BA E7 13
> BA A7 C6 62 ED 3C 42 C5 DA A2 7B 3E 2E BA 2F 8F A2 4F 42 5A F4 E4 56
> 29 6B>
> Jan 03 16:53:59.36: [ 2113]: --> <128:0F 7D D0 6A A3 4B 6A A7 BA 84 B6
> DA 6A 1F D5 05 E1 82 10 10 5D 5A ED 54 97 16 84 68 93 58 10 10 92 58
> 6D 09 5F E1 73 4C F5 61 AA 4F DF 1A DF 75 3D BE EF 76 8D CF BE BA D6
> F5 7D E3 C3 AB BD A4 F6 D2 6A AB 7D 8B AB 4F B4 83 7C 57 FB 5E 57 95
> DA 6E DB 34 8F F3 FF FF FF FF FF FF FF FF FF FF FF EF E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7>

Notice the quantity of these inter-frame synchronization flags (0x7E, 
well, in this case they show up as 0xE7).  Normally a sender will not 
transmit more than a few of these between single frames.  Since the 
sender is HylaFAX, I can guarantee here that something catastrophic has 
gone wrong at this point, as this data is not what HylaFAX is sending.  
I'd have to double-check this, but I believe that HylaFAX only sends 
one flag between image data frames.  This may be what the sending 
*modem* is transmitting, but it is not what HylaFAX is telling the 
modem to transmit.

> Jan 03 16:53:59.36: [ 2113]: --> HDLC<220:FF C0 60 00 FE 76 AD 93 91
> AF 3C C8 71 AF 38 44 EC A1 9A 08 55 C4 83 25 C4 27 32 DD 50 89 CC AB
> 64 38 9C CA 43 3E 47 C2 9A 19 C0 A7 D9 D9 20 C8 C1 4E B1 16 23 B0 A1
> 4B 75 51 09 4C 56 A2 07 1A 45 25 08 34 1A 41 06 0A 90 41 84 18 41 E0
> A1 3C 26 83 41 84 18 2A 0C 26 10 78 4F 08 30 9F 84 FB C1 7C 17 3C 65
> 63 E7 88 5E 7C CF 19 E3 3A 4A 2E F3 E8 5D E5 63 46 B7 3C 42 A3 5B 45
> DE 7C E8 BB F3 C5 17 D2 12 D1 79 3B 54 A6 B7 85 F0 B5 6C 5D 25 6E 55
> D2 16 D5 B5 6F 95 74 10 E8 21 17 4B 56 E5 5D 2D 04 22 D9 23 41 09 23
> 56 D2 1F A1 F7 19 57 C6 55 F5 FD 63 FD 75 E3 FF ED D6 3E DF AE B5 D7
> FF 8F 8F 56 F4 95 BD 2D 5B 56 FE 8E AF A2 DC 13 FD 5B FE BA AA 56 DD
> B6 CB 3C 73>

This is the logging of the HDLC frame that was collected until the 
flags started happening.  It's clear that the complete frame was not 
received, because a complete HDLC frame here would have been 256 bytes, 
not 220.  Thus, the "corrupt terminating flag" was the first on our 
checklist of things to do to verify the validity of the data frame, and 
it failed the test, and thus we get this error message:

> Jan 03 16:53:59.36: [ 2113]: Bad HDLC terminating flag received.

Take notice that the frame above is numbered "0" (FF C0 60 *00*).  This 
is appropriate for the first frame of any ECM block.  Now look what 
happens, first more "inter-frame" sync flags:

> Jan 03 16:53:59.43: [ 2113]: --> <136:E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7>
> Jan 03 16:53:59.50: [ 2113]: --> <136:E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7>
> Jan 03 16:53:59.57: [ 2113]: --> <136:E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> F7 7D 80 01 C0 37 B7 DA E4 C4 7A 9E 09 C7 7A 0E 91 9B C2 2C 08 D5 91
> 60 D2 11 72 A6 5D 85 C8 99 6A 13 8E 9C 29 61 3E E2 83 B2 30 07 CA 67
> 6E 12 4C 0C CA 35 A2 11 37 14 4A BB 2A 42 CA A8 15 81 63 89 92 42 B0
> 60 09 82 41 25 08 86 60 08 1E>

Okay, now we have some data...

> Jan 03 16:53:59.64: [ 2113]: --> <128:14 F2 90 05 0B 86 60 50 C1 90 21
> 78 C8 43 30 E4 0B F9 3C E8 03 9D C7 D4 F8 78 84 9E 8F 79 CC 63 2E 29
> BA E7 13 BA A7 C6 62 ED 3C 42 C5 DA A2 7B 3E 2E BA 2F 8F A2 4F 42 5A
> 6E DB 34 8F F3 FF FF FF FF FF FF FF FF FF FF FF EF E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7 E7
> E7 E7>

Ooops!  Now we have another large set of sync flags.  Something's 
really not going right.

> Jan 03 16:53:59.64: [ 2113]: --> HDLC<138:FF C0 60 00 FE 76 AD 93 91
> AF 3C C8 71 AF 38 44 EC A1 9A 08 55 C4 83 25 C4 27 32 DD 50 89 CC AB
> 64 38 9C CA 43 3E 47 C2 9A 19 C0 A7 D9 D9 20 C8 C1 4E B1 16 23 B0 A1
> 4B 75 51 09 4C 56 A2 07 1A 45 25 08 34 1A 41 06 0A 90 41 84 18 41 E0
> A1 3C 26 83 41 84 18 2A 0C 26 10 78 4F 08 30 9F 84 FB C1 7C 17 3C 65
> 63 E7 88 5E 7C CF 19 E3 3A 4A 2E F3 E8 5D E5 63 46 B7 3C 42 A3 5B 45
> DE 7C E8 BB F3 C5 17 D2 12 D3 B6 D9 67 8E>

Okay, here's the logging of the partial HDLC frame.  Notice this one is 
only 138 bytes of 256.  Also notice the frame number.  Hello, it is 
frame number "0" again!  Now, I can guarantee that HylaFAX did not send 
the data to the sending modem this way.  I'm going to trim things up a 
bit...

> Jan 03 16:53:59.92: [ 2113]: --> HDLC<138:FF C0 60 00 FE 76 AD 93 91

> Jan 03 16:54:00.20: [ 2113]: --> HDLC<138:FF C0 60 00 FE 76 AD 93 91

Okay, so you get frame number 0 over and over and over indefinitely.

It's interesting to note that all of the last frames are 138 bytes.  
This means that the receiver is receiving the same set of data over and 
over and over again.

Unless you have some fax-relay in-between the sender and the receiver, 
like a FoIP gateway, since your sending log indicates that the modem 
hung up happily, I think that the problem here is with the receiving 
modem.  It looks like it got a buffer full of data, and then relays 
that buffer to HylaFAX, and it never empties the buffer, and just 
resends that same buffer to HylaFAX over and over again.

If this receiving modem was working fine before you may want to try 
power-cycling it.  If it has never worked right, then you may want to 
look into changing the flow control.

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*