DNS and disconnects remain issues

[kalvos]

Hi,

I have three issues with WinGate (latest build) which in one form or another have plagued me for several years, through several hardware and software configurations. I have asked about these here, and before that, at the old Deerfield forums.

1. Client app 'disconnects'. If I am browsing and click on links too quickly (or using some other network application, such as news or whois), sometimes the client app's actions will no longer be seen by the WinGate server. The client computer will still be in the list, but the app in question will drop off the list (other apps on that client will continue to work). The only way to make the app work again is the exit it and restart it, or terminate it from the server.

2. Can't find DNS entry. This is a more recent problem that used to show multiple DNS lookups in the server before returning with an error. Now (with the latest build) the client app returns a DNS error with no apparent lookup problem. But the lookup *was* successful -- once the error is returned, I can perform the same action and get an instant response.

3. WinGate server computer is disconnected. This is the most frustrating, and now it is happening about once a day. Previously, WinGate would just simply hang. The mouse would move, but no clicks or keystrokes would work, and require a hard reboot. Now with the latest WinGate build, the computer is simply disconnected from the outside world -- even local apps on the server no longer function. Pings return no response, etc., and the NIC cannot be renewed. The WinGate server is still being seen by the clients, but the server computer no longer sees the outside world. It requires a reboot to restore the connection.

My server and clients are all Win98SE (all patches). The server has only a few applications installed. I am on a cable modem, and the problem is not with the modem or the ISP.

In order to fix this, I have re-installed Windows (fresh install as well), re-installed WinGate, swapped the NICs (both 3Com 3C905s), and looked for configuration issues in WinGate. I have done the usual deletion of history files, and the unchecking of the IE proxy/autodetect on the server.

When WinGate works, it is absolutely great. But these three issues remain -- a client app going dead, the DNS not being found the first time, and (worst of all) the server computer being shut off from the outside world.

These problems seem related to others that are posted (such as the series on the TCP/IP being damaged by WinGate), and as a longtime WinGate user (5-client version, with upgrades), I am anxious to put this problem to rest one of these days!

Thanks,
Dennis

[kalvos]

Re: The problem of the WinGate server computer being disconnected.

I found a temporary solution in another post -- stop WinGate server, renew NIC lease, restart WinGate server.

Since my ISP renews leases randomly (from 1 hour to 36 hours), doing this by hand is not a solution. It takes little more time to reboot as I have been doing before, but at least I know the problem is with WinGate's relationship to the NIC lease.

Can WinGate automatically detect and reconnect when the lease runs out?

Dennis

[mflowers]

view my earlier post concerning similar symptoms only at the client end. I have not as of yet found a resolution. Hopefully someone here can shed some light the subject.
I would like to hear from anyone else having issues like this.

[kalvos]

Bump up.

Still appreciate any advice on #1 and #2 above, and also how to automatically detect IP lease event re #3.

Dennis

[MattP]

If you open port 67 (UDP) on the firewall it should allow your ISP's DHCP server to re-assign an IP address. Please try this and let us know how it goes.

Still looking at 1 and 2.

[kalvos]

If you open port 67 (UDP) on the firewall it should allow your ISP's DHCP server to re-assign an IP address. Please try this and let us know how it goes.

No luck. The lease came up about 15 minutes ago, and the server went dead. Once I turned off the WinGate engine, it renewed. Then I started the engine again and all was well.

Dennis

[Pascal]

No luck. The lease came up about 15 minutes ago, and the server went dead. Once I turned off the WinGate engine, it renewed. Then I started the engine again and all was well.

Is WinGate physically preventing the lease from updating OR is the updated IP not picked up by the bindings for the services ?

For the DNS issue, I'm wondering if it isn't a problem identifying the correct DNS server to use. Customers with DNS problems generally have some success when they add the preferred DNS Servers they want to use in the DNS/WINS resolver configuration. This overrides (Or is used before) any of the discovered servers. You can find this on the first tab of "DNS/WINS resolver" on the "System" page in GateKeeper.

Also, would it be possible to switch on full logging for the DNS/WINS Resolver and the DNS Service and run one of those lookups that fails the first time but is successful the second time ? Then either post the portion of the logfiles here, or send to me directly, please.

[kalvos]

Is WinGate physically preventing the lease from updating OR is the updated IP not picked up by the bindings for the services ?

WinGate appears to be preventing it. As soon as WinGate is turned off, the system gets the updated IP within the normal period Windows uses, perhaps 15-30 seconds.

For the DNS issue, I'm wondering if it isn't a problem identifying the correct DNS server to use. Customers with DNS problems generally have some success when they add the preferred DNS Servers they want to use in the DNS/WINS resolver configuration. This overrides (Or is used before) any of the discovered servers. You can find this on the first tab of "DNS/WINS resolver" on the "System" page in GateKeeper.

I have tried both ways already. The result is the same. It appears the IP is actually being fetched, but not being delivered to the client. I have tested this by having two clients ready with the same URL, hitting the first, and almost immediately hitting the second. The first does not get the IP, the second does (it will happen with the computers reversed).

This is especially a problem on pages like eBay's, which fetch various pieces from what look like a dozen different servers. It will hang on one of them, preventing display of the page (or most of it). Refreshing the page will bring up everything unless it hits a new IP that hasn't already been found.

Also, would it be possible to switch on full logging for the DNS/WINS Resolver and the DNS Service and run one of those lookups that fails the first time but is successful the second time ? Then either post the portion of the logfiles here, or send to me directly, please.

I will do that tomorrow.

(I should note that I am using fixed IPs for the clients in the 192.168.244.xxx range.)

Thanks,
Dennis

[Pascal]

I have tried both ways already. The result is the same. It appears the IP is actually being fetched, but not being delivered to the client. I have tested this by having two clients ready with the same URL, hitting the first, and almost immediately hitting the second. The first does not get the IP, the second does (it will happen with the computers reversed).

I will do that tomorrow.

Thanks! When you are capturing that tomorrow, I'm wondering if we shouldn't try one other thing as well.

1. Disable the WinGate DNS Server
2. Create a temporary UDP mapping on port 53 to forward internal requests to the ISP's DNS Server

Only reason for that test is to see if the problem is with the DNS resolver in WinGate or if it is with the communication back to the client.

[kalvos]

Also, would it be possible to switch on full logging for the DNS/WINS Resolver and the DNS Service and run one of those lookups that fails the first time but is successful the second time ? Then either post the portion of the logfiles here, or send to me directly, please.

Here is a portion of the files, with the various conditions identified. I will try the direct mapping later. I hope this offers some clues:

==example 1: exists but not forwarded to client first time==

01/12/04 13:28:14 Request: request [0181e24a] A lookup "stringacademy.net."
01/12/04 13:28:14 Debug: bounce request [0181e24a]<0> to try 1 (nothing useful in cache)
01/12/04 13:28:14 Debug: selected 216.204.165.70 <user input> for request [0181e24a]<1> (best looking)
01/12/04 13:28:14 Debug: request [0181e24a](ID 48) sent to 216.204.165.70 <user input> (35 bytes)
01/12/04 13:28:14 Debug: received block [134] (server 216.204.165.70, port 53)
01/12/04 13:28:14 Debug: added to cache from [0181e24a]
01/12/04 13:28:14 Debug: completed [0181e24a](ID 48) (0.06s)

==tried again: works==

01/12/04 13:28:14 Request: request [036fed48] PTR lookup "246.75.39.66.in-addr.arpa."
01/12/04 13:28:14 Debug: bounce request [036fed48]<0> to try 1 (nothing useful in cache)
01/12/04 13:28:14 Debug: selected 216.204.165.70 <user input> for request [036fed48]<1> (best looking)
01/12/04 13:28:14 Debug: request [036fed48](ID 49) sent to 216.204.165.70 <user input> (43 bytes)
01/12/04 13:28:14 Debug: received block [154] (server 216.204.165.70, port 53)
01/12/04 13:28:14 Debug: added to cache from [036fed48]
01/12/04 13:28:14 Debug: completed [036fed48](ID 49) (0.07s)

==example 2: cannot find at all==

01/12/04 13:30:42 Request: request [018247ea] A lookup "www.cssazuki.ca."
01/12/04 13:30:42 Debug: bounce request [018247ea]<0> to try 1 (nothing useful in cache)
01/12/04 13:30:42 Debug: selected 216.204.165.70 <user input> for request [018247ea]<1> (best looking)
01/12/04 13:30:42 Debug: request [018247ea](ID 52) sent to 216.204.165.70 <user input> (33 bytes)
01/12/04 13:30:42 Debug: received block [97] (server 216.204.165.70, port 53)
01/12/04 13:30:42 Debug: added to cache from [018247ea]
01/12/04 13:30:42 Debug: completed [018247ea](ID 52) (0.05s)

01/12/04 13:32:51 Request: request [0184f622] A lookup "www.cssazuki.ca."
01/12/04 13:32:51 Debug: bounce request [0184f622]<0> to try 1 (nothing useful in cache)
01/12/04 13:32:51 Debug: selected 216.204.165.70 <user input> for request [0184f622]<1> (best looking)
01/12/04 13:32:51 Debug: request [0184f622](ID 53) sent to 216.204.165.70 <user input> (33 bytes)
01/12/04 13:32:51 Debug: received block [99] (server 216.204.165.70, port 53)
01/12/04 13:32:51 Debug: added to cache from [0184f622]
01/12/04 13:32:51 Debug: completed [0184f622](ID 53) (0.05s)

01/12/04 13:34:20 Request: request [0181f192] A lookup "www.uswp.edu."
01/12/04 13:34:20 Debug: bounce request [0181f192]<0> to try 1 (nothing useful in cache)
01/12/04 13:34:20 Debug: selected 216.204.165.70 <user input> for request [0181f192]<1> (best looking)
01/12/04 13:34:20 Debug: request [0181f192](ID 55) sent to 216.204.165.70 <user input> (30 bytes)
01/12/04 13:34:20 Debug: received block [97] (server 216.204.165.70, port 53)
01/12/04 13:34:20 Debug: added to cache from [0181f192]
01/12/04 13:34:20 Debug: completed [0181f192](ID 55) (0.06s)

01/12/04 13:35:38 Request: request [0182f856] A lookup "www.uswp.edu."
01/12/04 13:35:38 Debug: bounce request [0182f856]<0> to try 1 (nothing useful in cache)
01/12/04 13:35:38 Debug: selected 216.204.165.70 <user input> for request [0182f856]<1> (best looking)
01/12/04 13:35:38 Debug: request [0182f856](ID 62) sent to 216.204.165.70 <user input> (30 bytes)
01/12/04 13:35:38 Debug: received block [100] (server 216.204.165.70, port 53)
01/12/04 13:35:38 Debug: added to cache from [0182f856]
01/12/04 13:35:38 Debug: completed [0182f856](ID 62) (0.05s)

==example 3: exists but not forwarded to client first time==

01/12/04 13:37:21 Request: request [01834b1e] A lookup "www.preucil.org."
01/12/04 13:37:21 Debug: bounce request [01834b1e]<0> to try 1 (nothing useful in cache)
01/12/04 13:37:21 Debug: selected 216.204.165.70 <user input> for request [01834b1e]<1> (best looking)
01/12/04 13:37:21 Debug: request [01834b1e](ID 63) sent to 216.204.165.70 <user input> (33 bytes)
01/12/04 13:37:22 Debug: request [01834b1e] "www.preucil.org." (no response on try 1)
01/12/04 13:37:22 Debug: multicast request [01834b1e]<2> (5 good servers)
01/12/04 13:37:22 Debug: request [01834b1e](ID 64) sent to 216.204.165.70 <user input> (33 bytes)
01/12/04 13:37:22 Debug: request [01834b1e](ID 65) sent to 216.204.165.71 <user input> (33 bytes)
01/12/04 13:37:22 Debug: request [01834b1e](ID 66) sent to 216.92.61.61 <user input> (33 bytes)
01/12/04 13:37:22 Debug: request [01834b1e](ID 67) sent to 216.92.60.60 <user input> (33 bytes)
01/12/04 13:37:22 Debug: request [01834b1e](ID 68) sent to 216.92.61.2 <user input> (33 bytes)
01/12/04 13:37:22 Debug: received block [33] (server 216.92.61.61, port 53)
01/12/04 13:37:22 Debug: completed [01834b1e](ID 66) (0.05s)
01/12/04 13:37:22 Debug: received block [33] (server 216.92.61.2, port 53)
01/12/04 13:37:22 Debug: no information for response [68] (server 216.92.61.2)
01/12/04 13:37:22 Debug: received block [33] (server 216.92.60.60, port 53)
01/12/04 13:37:22 Debug: no information for response [67] (server 216.92.60.60)
01/12/04 13:37:22 Debug: received block [292] (server 216.204.165.70, port 53)
01/12/04 13:37:22 Debug: no information for response [64] (server 216.204.165.70)

==tried again: works==

01/12/04 13:38:03 Request: request [0182f856] A lookup "www.preucil.org."
01/12/04 13:38:03 Debug: bounce request [0182f856]<0> to try 1 (nothing useful in cache)
01/12/04 13:38:03 Debug: selected 216.204.165.70 <user input> for request [0182f856]<1> (best looking)
01/12/04 13:38:03 Debug: request [0182f856](ID 69) sent to 216.204.165.70 <user input> (33 bytes)
01/12/04 13:38:03 Debug: received block [271] (server 216.204.165.70, port 53)
01/12/04 13:38:03 Debug: added to cache from [0182f856]
01/12/04 13:38:03 Debug: completed [0182f856](ID 69) (0.06s)
01/12/04 13:38:03 Request: request [036fed48] PTR lookup "3.33.235.64.in-addr.arpa."
01/12/04 13:38:03 Debug: bounce request [036fed48]<0> to try 1 (nothing useful in cache)
01/12/04 13:38:03 Debug: selected 216.204.165.70 <user input> for request [036fed48]<1> (best looking)
01/12/04 13:38:03 Debug: request [036fed48](ID 70) sent to 216.204.165.70 <user input> (42 bytes)
01/12/04 13:38:03 Debug: received block [142] (server 216.204.165.70, port 53)
01/12/04 13:38:03 Debug: added to cache from [036fed48]
01/12/04 13:38:03 Debug: completed [036fed48](ID 70) (0.16s)

==example 4: works on first try==

01/12/04 13:39:35 Debug: request [0182f856] "www.gussetviolins.com." (no response on try 1)
01/12/04 13:39:35 Debug: multicast request [0182f856]<2> (5 good servers)
01/12/04 13:39:35 Debug: request [0182f856](ID 74) sent to 216.204.165.70 <user input> (39 bytes)
01/12/04 13:39:35 Debug: request [0182f856](ID 75) sent to 216.204.165.71 <user input> (39 bytes)
01/12/04 13:39:35 Debug: request [0182f856](ID 76) sent to 216.92.61.61 <user input> (39 bytes)
01/12/04 13:39:35 Debug: request [0182f856](ID 77) sent to 216.92.60.60 <user input> (39 bytes)
01/12/04 13:39:35 Debug: request [0182f856](ID 78) sent to 216.92.61.2 <user input> (39 bytes)
01/12/04 13:39:35 Debug: received block [208] (server 216.204.165.70, port 53)
01/12/04 13:39:35 Debug: added to cache from [0182f856]
01/12/04 13:39:35 Debug: completed [0182f856](ID 74) (0.08s)
01/12/04 13:39:35 Debug: received block [39] (server 216.92.61.61, port 53)
01/12/04 13:39:35 Debug: no information for response [76] (server 216.92.61.61)
01/12/04 13:39:35 Debug: received block [39] (server 216.92.60.60, port 53)
01/12/04 13:39:35 Debug: no information for response [77] (server 216.92.60.60)
01/12/04 13:39:35 Debug: received block [39] (server 216.92.61.2, port 53)
01/12/04 13:39:35 Debug: no information for response [78] (server 216.92.61.2)
01/12/04 13:39:36 Debug: received block [77] (server 216.204.165.70, port 53)
01/12/04 13:39:36 Debug: added to cache from [036fed48]
01/12/04 13:39:36 Debug: completed [036fed48](ID 73) (0.21s)

[kalvos]

Maybe this is relevant. I have no idea what it means, but after re-enabling logging, the WinGate NAT log places these identical four lines every five seconds. The log is about 3MB already (in 7 hours).

01/12/04 22:54:40 Debug: NAT error message code FFE0B40B, context 1417 OutICMP=0, InICMP=0, OutUDP=0, InUDP=0, OutTCP=0, InTcp=0
01/12/04 22:54:40 Debug: NAT error message code FFE0B40B, context 1425 OutICMP=1, InICMP=23060, OutUDP=0, InUDP=0, OutTCP=0, InTcp=0
01/12/04 22:54:40 Debug: NAT error message code FFE0B40D, context 1431 Total locked memory in use is 190350
01/12/04 22:54:40 Debug: NAT error message code FFE0B40E, context 1438 Unknown Frames = 0, Status Queue Size = 128

[kalvos]

Bump up.

Client app disconnections and DNS problems continue, but have lessened somewhat with logging turned on. Maybe there's some sort of timing issue.

However, the four-line additions to the WinGate NAT log continue. (I have NAT enabled, but use WGIC on all the clients.)

Dennis

[Pascal]

Maybe this is relevant. I have no idea what it means, but after re-enabling logging, the WinGate NAT log places these identical four lines every five seconds. The log is about 3MB already (in 7 hours).

01/12/04 22:54:40 Debug: NAT error message code FFE0B40B, context 1417 OutICMP=0, InICMP=0, OutUDP=0, InUDP=0, OutTCP=0, InTcp=0
01/12/04 22:54:40 Debug: NAT error message code FFE0B40B, context 1425 OutICMP=1, InICMP=23060, OutUDP=0, InUDP=0, OutTCP=0, InTcp=0
01/12/04 22:54:40 Debug: NAT error message code FFE0B40D, context 1431 Total locked memory in use is 190350
01/12/04 22:54:40 Debug: NAT error message code FFE0B40E, context 1438 Unknown Frames = 0, Status Queue Size = 128

Those four lines are only information. Because we use the same mechanism to report statistics as we do to send other text messages from the driver to the engine the engine logs them as 'errors' even though they are only debugging information.

We are still looking into the DNS issue. Adrien's posted some comments in http://forums.qbik.com/viewtopic.php?t=846, but I think you've seen that one.

[Pascal]

Have you had an opportunity to try this with the direct mapping ? (Bypassing the WG DNS Resolver to see where the problem lies)