Auto updater stops updating, then WWW proxy hangs

Forum for support for the Kaspersky AntiVirus for WinGate plugin

Moderator: Qbik Staff

Auto updater stops updating, then WWW proxy hangs

Postby saubrey » Feb 26 06 8:05 am

I'm using WG 6.1.1 build 1077 and KAV 2.1. I've had this problem twice within that last month.

The KAV auto updater updates correctly for a few days or few weeks, then for no reason that I can see stops updating. When this happens I used the manual update method using the Kaspersky Antivirus Updater from the Start menu. This does successfully perform the update. However, immediately after the update completes, WG's WWW & FTP proxy refuse to accept connections. (I have the WWW and FTP proxies configured to use KAV). Also GateKeeper can not log into WG. the GateKeeper outer window displays, but none of its contents are displayed. Also, even though the WWW and FTP proxies refuse connections and Gatekeeper can not login, a NAT connection does continue to work correctly, so not all of WG is hung.

I am able to stop, then restart WG from the sys tray icon, and all is well after that.

I have the KAV auto updater scheduled to update once an hour. I remember a long time ago (more than a year ago) there was a bug which would cause all WG proxies that used KAV to hang if the KAV updater ran while a proxy was processing incoming data. Do you think that is still the problem I am having today? I mostly worked around that issue last year by having the KAV auto updater run only once a day at 3:00 am, when no proxies were in use. I'd prefer to now have KAV update once an hour, but will revet to once a day if needed.

Thanks,
Steve
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby saubrey » Feb 28 06 4:30 am

One more new piece of information.

Last night the WG engine crashed immediately after the KAV auto update. This is the first time that I know of that this has happened. The WG engine crashed at 12:17 am. The KAV auto updater runs every hour at 17 minutes past the hour. Below is the Event Log message.
Event ID: 7031. The Qbik WinGate Engine service terminated unexpectedly. It has done this 1 time(s). The following corrective action will be taken in 0 milliseconds: No action.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Feb 28 06 8:13 am

Is there any chance that you have debug logging on in Kaspersky? I'm busy talking to them about the problem because one or two other customers are seeing a similar problem (Unexpected Failure Updating Database)

1. What does memory useage / handle useage of WinGate.exe and the kavss.exe processes look like at the time?
2. Do you have deadlock detection turned on? If not, can you please turn it on?
3. Is it possible to get a copy of your KAV registry settings, please? I would like to make sure it is running in the synchronous scan method.

One bit of advice we received from Kaspersky, although without a handy explanation attached which I'm still waiting on, is to set the AV database servers to:

[Update: Removed list of servers, incorrect list]

They have not indicated why yet, though - so not aware if this will resolve the issue.
Last edited by Pascal on Feb 28 06 4:02 pm, edited 1 time in total.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby Pascal » Feb 28 06 10:39 am

I think this might be a coincidental symptom of another problem. (Just a guestimate at this time based on a few other reports that show remarkably similar symptoms)

Would it be possible for you to turn on deadlock detection and email me those files, please?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Feb 28 06 12:15 pm

>Is there any chance that you have debug logging on in Kaspersky?

Yes. It is on. I turned it on a few months ago when I first noticed that the auto updater stopped updating after a few days or weeks. I hoped it would give some insight as to why auto updater stopped updating.

>1. What does memory useage / handle useage of WinGate.exe and the kavss.exe processes look like at the time

I don't know. Next time it happens, I'll look.

>2. Do you have deadlock detection turned on? If not, can you please turn it on?
No, but I'll turn it on now, and I'll email the files when/if it happens again.

>3. Is it possible to get a copy of your KAV registry settings, please? I would like to make sure it is running in the synchronous scan method.
Sure. Where should I email it?
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Feb 28 06 12:31 pm

Address in my profile, pascalv at qbik . com

Update: Thanks, just received the files and responded. You're using synch. scanning so that is good, no problem with that.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby tomm » Feb 28 06 2:04 pm

Hi Saubrey,

Could you please let us know what OS you are running WinGate on?

Thanks

T
tomm
Qbik Staff
 
Posts: 7
Joined: Jan 26 06 4:47 pm

Postby Pascal » Feb 28 06 4:05 pm

Ignore that list of servers, they seemed to have stopped responding to update requests. I'm querying Kaspersky Labs on that.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Feb 28 06 5:40 pm

I'm running WG on Win2k server sp4.

Can you please list the original list of KAV update servers. I've already removed the original list and used the list you suggested.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm


Postby saubrey » Apr 05 06 6:05 pm

KAV auto updater stop updating yesterday. The Wingate.exe and KAVss.exe processes look normal. Wingate.exe is consuming 28 MB, which is normal for it and it is consuming only 1% CPU. The two KAVss.exe processare are consuming 14 MB, with is normal for them and they are consuming 0% cpu. Pascal, I've emailed the deadlock detection files that you asked for last month to your email acct.


Thanks, Steve
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Apr 05 06 6:15 pm

Thanks Steve. I just had a quick glance through them and will parse them fully tomorrow when I'm back in the office and can get at the source code.

The only thing that it really seems to turn up is a lengthy holding of the central KAV configuration object lock. About 30 seconds worth; which is worth looking into, but I'll need code for that.

Have you done anything to the system since it stopped updating?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Apr 06 06 8:59 am

I haven't done anything to the server or WinGate in the last 3 or 4 weeks. It has been running fine and KAV has been updating, so I've left it alone.

Yesterday, after I noticed that KAV was no longer updating, I did manually run the KAV update and it seemed to run correctly and WG did not hang after I ran it.

Other than manually running the KAV update, I haven't done anything to the server or WinGate.

-- Steve
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Apr 06 06 9:15 am

Ok. Will you check then today when the auto update is scheduled to run to see if it does?

We've been running this scenario in the lab for a while and thus far the only common issue we've been able to pick out has been a potential for overload from the Update servers themselves.

Internet problems, rather than an actual coding / mechanism issue. Just digging through the code now for those lengthy timeouts.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Apr 06 06 6:15 pm

The manual update that I attempted yesterday didn't update the virus definitions as I thought. The WG KAV plug-in still shows April 2nd as the virus definition date. I tried manually updating again today using the menu option "Kaspersky antivirus updater", but it did update the virus definitions either. No error message was given, but after "connecting to the server" was displayed for 90 seconds or so and nothing happened...the Cancel button just changed back into the Download button. Then I tried using the WG plug-in KAV "Update" button, but it didn't work (although, it has never worked for me, so I don't think the fact that it didn't work today means anything).

I've scheduled the virus definitions to auto-update every hour, but since the WG KAV plug-in is still showing April 2nd, I guess the hourly update isn't working either.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby saubrey » Apr 06 06 6:22 pm

I may have mentioned that for the past year or two, the KAV auto-update works for a while and then stops, like it has now. In the past, after stopping and then restarting WG, the auto updater always works. I suspect if I stop and restart WG now, the auto updater will begin to work correctly.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby saubrey » Apr 08 06 3:41 pm

I stopped and restarted the Wingate service. The KAV autoupdater is now correctly updating.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Apr 11 06 4:21 pm

In this case was the WWW Proxy still unavailable? I assume from the delay that it wasn't. We're busy trying to reproduce in the lab, but thus far the only times we get it is when the system reports that it is unable to download the update; not actually on the updating of the bases. What did your debug log (kaspersky.log file) indicate?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Apr 11 06 6:16 pm

The WWW proxy was still working and so was everything else. The only thing not working was KAV auto-update. I just noticed that there are no KAV logs for the period that KAV stopped updating. I have logs for April 2 and all days prior to April 2. (KAV stopped updating on April 2). And then the next log is April 7. (April 7 is when I stopped and restarted WG). There are no logs for any dates in between.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Apr 11 06 6:17 pm

Any update related logs towards the end of April 2nd?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Apr 11 06 6:23 pm

Here is the entire log from April 2

04/02/06 00:19:29 0.0.0.0 0000000884 Debug: Obtaining lock in Refresh
04/02/06 00:19:29 0.0.0.0 0000000884 Debug: Releasing lock in Refresh
04/02/06 01:17:47 0.0.0.0 0000003304 Debug: Obtaining lock in Refresh
04/02/06 01:17:47 0.0.0.0 0000003304 Debug: Releasing lock in Refresh
04/02/06 07:17:46 0.0.0.0 0000001344 Debug: Obtaining lock in Refresh
04/02/06 07:17:46 0.0.0.0 0000001344 Debug: Releasing lock in Refresh
04/02/06 08:19:38 0.0.0.0 0000002944 Debug: Obtaining lock in Refresh
04/02/06 08:19:38 0.0.0.0 0000002944 Debug: Releasing lock in Refresh
04/02/06 09:18:25 0.0.0.0 0000002948 Debug: Obtaining lock in Refresh
04/02/06 09:18:25 0.0.0.0 0000002948 Debug: Releasing lock in Refresh
04/02/06 10:17:43 0.0.0.0 0000002740 Debug: Obtaining lock in Refresh
04/02/06 10:17:43 0.0.0.0 0000002740 Debug: Releasing lock in Refresh
04/02/06 11:19:32 0.0.0.0 0000003504 Debug: Obtaining lock in Refresh
04/02/06 11:19:32 0.0.0.0 0000003504 Debug: Releasing lock in Refresh
04/02/06 12:17:43 0.0.0.0 0000003472 Debug: Obtaining lock in Refresh
04/02/06 12:17:43 0.0.0.0 0000003472 Debug: Releasing lock in Re
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Apr 11 06 6:26 pm

Thanks, I'll pass the additional information on to Tom.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » May 30 06 5:51 am

I'm still having this problem. WG has not hung since I last reported it on Feb 26, but the KAV auto updater in WG still stops auto updaing. This time it updated correctly for about 5 days, then stopped updating. Everything else about WG seems to be working correctly. Below is the KAV log for May 27...the day that it stopped updating. As you can see I've set it to auto update once per hour. 15:18 was the last update. This is the entire contents of the log for May 27. The last line with "Re" (e.g. partial word for "Refresh"), is correct, I did not inadvertantly truncate that last few characters.

As before, I believe that if I stop the WG service and then restart it, then the KAV autoupdater will correctly resume auto updating. I have not yet done this in case you want me to do some more investigation while the KAV autoupdater is hung.

Thanks, Steve

05/27/06 00:19:47 0.0.0.0 0000002164 Debug: Obtaining lock in Refresh
05/27/06 00:19:47 0.0.0.0 0000002164 Debug: Releasing lock in Refresh
05/27/06 01:19:38 0.0.0.0 0000000824 Debug: Obtaining lock in Refresh
05/27/06 01:19:38 0.0.0.0 0000000824 Debug: Releasing lock in Refresh
05/27/06 02:17:53 0.0.0.0 0000001844 Debug: Obtaining lock in Refresh
05/27/06 02:17:53 0.0.0.0 0000001844 Debug: Releasing lock in Refresh
05/27/06 03:19:38 0.0.0.0 0000002676 Debug: Obtaining lock in Refresh
05/27/06 03:19:38 0.0.0.0 0000002676 Debug: Releasing lock in Refresh
05/27/06 04:17:59 0.0.0.0 0000002356 Debug: Obtaining lock in Refresh
05/27/06 04:17:59 0.0.0.0 0000002356 Debug: Releasing lock in Refresh
05/27/06 05:19:52 0.0.0.0 0000002760 Debug: Obtaining lock in Refresh
05/27/06 05:19:52 0.0.0.0 0000002760 Debug: Releasing lock in Refresh
05/27/06 06:19:37 0.0.0.0 0000000368 Debug: Obtaining lock in Refresh
05/27/06 06:19:37 0.0.0.0 0000000368 Debug: Releasing lock in Refresh
05/27/06 07:18:27 0.0.0.0 0000000824 Debug: Obtaining lock in Refresh
05/27/06 07:18:27 0.0.0.0 0000000824 Debug: Releasing lock in Refresh
05/27/06 09:18:36 0.0.0.0 0000002516 Debug: Obtaining lock in Refresh
05/27/06 09:18:36 0.0.0.0 0000002516 Debug: Releasing lock in Refresh
05/27/06 10:19:47 0.0.0.0 0000002504 Debug: Obtaining lock in Refresh
05/27/06 10:19:47 0.0.0.0 0000002504 Debug: Releasing lock in Refresh
05/27/06 11:19:06 0.0.0.0 0000002720 Debug: Obtaining lock in Refresh
05/27/06 11:19:06 0.0.0.0 0000002720 Debug: Releasing lock in Refresh
05/27/06 12:18:03 0.0.0.0 0000000856 Debug: Obtaining lock in Refresh
05/27/06 12:18:03 0.0.0.0 0000000856 Debug: Releasing lock in Refresh
05/27/06 13:19:42 0.0.0.0 0000000968 Debug: Obtaining lock in Refresh
05/27/06 13:19:42 0.0.0.0 0000000968 Debug: Releasing lock in Refresh
05/27/06 15:18:17 0.0.0.0 0000002556 Debug: Obtaining lock in Refresh
05/27/06 15:18:17 0.0.0.0 0000002556 Debug: Releasing lock in Re
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » May 30 06 11:22 am

You can restart it; odd though the log does not show any updater activity. Even at a basic level there should be at least something logged to indicate it is attempting the update:

Code: Select all
01/17/06 11:00:00   0.0.0.0   <system>   0000002820   Starting update
01/17/06 11:00:00   0.0.0.0   <system>   0000001984   Starting update : http://downloads1.kaspersky-labs.com/updates_ext
01/17/06 11:00:00   0.0.0.0   <system>   0000001984   Connecting to server : downloads1.kaspersky-labs.com [Busy]
01/17/06 11:00:00   0.0.0.0   <system>   0000001984   Connecting to server : downloads1.kaspersky-labs.com [Done]
01/17/06 11:00:00   0.0.0.0   <system>   0000001984   Selecting files : /updates_ext/ [Busy]
01/17/06 11:00:07   0.0.0.0   <system>   0000001984   Selecting files : /updates_ext/ [Done]
01/17/06 11:00:07   0.0.0.0   <system>   0000001984   Downloading file [Busy]
01/17/06 11:00:09   0.0.0.0   <system>   0000001984   Downloading file : daily.avc [Done]
01/17/06 11:00:10   0.0.0.0   <system>   0000001984   Downloading file : daily-ex.avc [Done]
01/17/06 11:00:12   0.0.0.0   <system>   0000001984   Downloading file : gen004.avc [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Downloading file : avp.klb [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Downloading file [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Installing file [Busy]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Installing file [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Disconnecting from server : downloads1.kaspersky-labs.com [Busy]
01/17/06 11:00:30   0.0.0.0   <system>   0000001984   Disconnecting from server : downloads1.kaspersky-labs.com [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000000332   Starting update
01/17/06 11:00:30   0.0.0.0   <system>   0000002296   Starting update : http://updates-us1.kaspersky-labs.com/updates_ext
01/17/06 11:00:30   0.0.0.0   <system>   0000002296   Connecting to server : updates-us1.kaspersky-labs.com [Busy]
01/17/06 11:00:30   0.0.0.0   <system>   0000002296   Connecting to server : updates-us1.kaspersky-labs.com [Done]
01/17/06 11:00:30   0.0.0.0   <system>   0000002296   Selecting files : /updates_ext/ [Busy]
01/17/06 11:00:35   0.0.0.0   <system>   0000002296   Selecting files : /updates_ext/ [Done]
01/17/06 11:00:35   0.0.0.0   <system>   0000002296   Downloading file [Busy]
01/17/06 11:00:37   0.0.0.0   <system>   0000002296   Downloading file : daily.avc [Done]
01/17/06 11:00:37   0.0.0.0   <system>   0000002296   Downloading file : daily-ex.avc [Done]
01/17/06 11:00:39   0.0.0.0   <system>   0000002296   Downloading file : gen004.avc [Done]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Downloading file : avp.klb [Done]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Downloading file [Done]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Installing file [Busy]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Installing file [Done]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Disconnecting from server : updates-us1.kaspersky-labs.com [Busy]
01/17/06 11:00:40   0.0.0.0   <system>   0000002296   Disconnecting from server : updates-us1.kaspersky-labs.com [Done]
01/17/06 11:00:40   0.0.0.0   <system>   0000002820   Starting update
01/17/06 11:00:40   0.0.0.0   <system>   0000002504   Starting update : C:\Program Files\WinGate\Plugins\Kaspersky AntiVirus\Downloads\
01/17/06 11:00:40   0.0.0.0   <system>   0000002504   Selecting files : C:\Program Files\WinGate\Plugins\Kaspersky AntiVirus\Downloads\ [Busy]
01/17/06 11:00:41   0.0.0.0   <system>   0000002504   Selecting files : C:\Program Files\WinGate\Plugins\Kaspersky AntiVirus\Downloads\ [Done]
01/17/06 11:00:41   0.0.0.0   <system>   0000002504   Downloading file [Busy]


Do you even get the syslog messages indicating that it is attempting to run that update? (If not, the problem will be with the scheduled event that is setup)
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » May 31 06 4:40 pm

The system log shows that KAV auto updater is attempted. Every hour there are two KAV entries in the sys log. For instance:

16:20.25 Data file update for Kaspersky antivirus for Wingate could not be completed
16:17.09 Data File update initiated for Kapersky antivirus for Wingate

-- Steve
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby saubrey » Jun 02 06 4:59 pm

What should I do next to help resolve this issue?
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Jun 08 06 4:08 pm

Sorry for the delay Steve. Between myself and Tom we've been trying to work out why your logfiles show only those few lines and trying to reproduce the issue.

Firstly, do you have Antivirus Update Logging enabled at all?

Secondly, thus far:

[quote=Tom]
- was able to produce 3 update failures (unspecified reason). However with each, KAV was able to successfully update on the subsequent try.

- the setup I had included KAV on a wingate machine behind another wg
machine. So kav was going through the 2nd wg machine's proxy server.
Attached are the log msgs for 3 failures and a whole bunch of successes.
The pattern seen is that when an update is successful, the last thing kav
downloads is avp.klb. But each time it failed it tried to download other
stuff after downloading avp.klb, most notably daily.avc. Also of note is
that each update always leaves a hanging session in the proxy server that
takes 2 minutes to timeout (in the activity window the session is always the last thing downloaded, eg avp.klb).
[/quote]

We're talking to Kaspersky Support to try and get more information from them.
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby saubrey » Jun 08 06 5:31 pm

I thought I had logging turned on as I was getting a log file, but I didn't have all the options turned on. I only had "request blocked" on...sorry. I have now turned on "KAV update logging" and "debug". I've emailed to you the log file that has one attempted KAV update. I don't think the update succeeded as the log shows "Failed", and the KAV update date shown in Gatekeeper still shows yesterday's date.
saubrey
WinGate Master
 
Posts: 207
Joined: Sep 15 03 12:55 pm

Postby Pascal » Jun 09 06 10:49 am

"Unable to download antivirus database - update failed - Unspecified error"

That's the clue. It was unable to connect to the Kaspersky Update Servers. At the same time, it looks as if other traffic was still going through the system. Do you have any proxy configuration done on the WinGate server itself? Also, if it is still in this state - can you manually reach any of the update URLs? (Using a browser from the server). Although, time-wise I suspect this has passed now.

The logfile will grow in size quite rapidly, so you'll need to keep a close watch on that one.

Are you still updating on an hourly basis?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Postby Pascal » Jun 09 06 2:45 pm

Steve, is your local IE (Server) set to run through the proxy?
Pascal

Qbik New Zealand
pascalv@qbik.com
http://www.qbik.com
Pascal
Qbik Staff
 
Posts: 2623
Joined: Sep 08 03 8:19 pm
Location: Auckland, New Zealand

Next

Return to Kaspersky AntiVirus for WinGate

Who is online

Users browsing this forum: No registered users and 2 guests