Would the real update event please step forward?

[runcmd]

Background: I do not have global updating enabled.  I have a scheduled task configured for clients to update all packages daily at 00:00 with 23 hours and 30 minutes of randomization and any missed tasks will run with a 0 minute delay.  My Agent policy is configured to enforce policy every 5 minutes and perform agent-to-server communication every 60 minutes.  The "UpdateLog.txt" on my computer shows two updates for today, at least one of which I initiated:  9:41:27 AM and 9:46:09 AM.

That said, I see "Checking update packages from repository ePO_[MyEpoServer]" entries in my McAfee Agent Activity Log (Agent_[hostname].log and Agent_[hostname]_backup.log) at: 10:29:31; 10:34:31; 10:39:32; 10:44:33; 10:49:33; 10:54:34; etc (every 5 minutes).  With WireShark running, I am able to confirm that the agent is talking back to the ePO every five minutes on ports 443 and 81.  Why?  Why do my clients appear to be attempting an update every five minutes?  Am I reading the log(s) incorrectly?  Is anyone else seeing this?

Thanks!

[runcmd]

Additionally, I see...

2010-01-20 11:23:00 i  #1700  Sched  Scheduler: Invoking task [Workstation Update Task]...

...in the Agent_[hostname]_backup.log but no correlating entry in the UpdateLog.txt for that time.

Message was edited by: runcmd - Spelling correction on 1/20/10 3:01:02 PM EST

[JoeBidgood]

A couple of points:

1) UpdateLog is the name of VirusScan's own update log, rather than the agent's log (which is agent_machinename.log.) This would imply that you still have the default VSE update task running. If you only want the agent tasks to run, you can disable the default task in the VSE policy.

2) I would guess that you have a deployment task set to run at every policy enforcement interval: this will cause the behaviour you're seeing.

Regards -

Joe

[runcmd]

Thanks for the information!  I created a test group and applied a new VirusScan Enterprise 8.7.0 / User Interface Policy with "Display managed tasks in the client console" and "Disable default AutoUpdate task schedule" checked.  I also broke inheritance on my task used to Deploy VirusScan 8.7, for the test group, and unchecked the box to "Run at every policy enforcement (Windows only)".  Then I sent a wakeup call to my test computer and forced a policy and task update.  I'm going to let that cook and see what impact it has on the logs.  I'll let you know that I find.

[runcmd]

When I made the changes to my computer's policy as a test, I dumped all of the log files on my machine so that I could start from scratch.  Searching the new Agent_[hostname].log file for my update task, I found the following entries...

2010-01-21 09:05:28  I  #456  Sched  Workstation Update Task - Last run time(local) is Wed Jan 20 11:23:00 2010
2010-01-21 09:05:28  i  #456  Sched  Next time(local) of task Workstation Update Task: Friday, January 22, 2010 4:34:00 PM
2010-01-21 09:05:28  X  #456  Sched  NTTR( UTC ) of task Workstation Update Task: Fri Jan 22 21:34:00 2010
2010-01-21 09:06:00  I  #2720  Sched  Workstation Update Task - Last run time(local) is Wed Jan 20 11:23:00 2010
2010-01-21 09:06:00  i  #2720  Sched  Next time(local) of task Workstation Update Task: Friday, January 22, 2010 12:29:00 AM
2010-01-21 09:06:00  X  #2720  Sched  NTTR( UTC ) of task Workstation Update Task: Fri Jan 22 05:29:00 2010
2010-01-21 09:06:13  I  #2804  Sched  Workstation Update Task - Last run time(local) is Wed Jan 20 11:23:00 2010
2010-01-21 09:11:42  I  #2804  Sched  Workstation Update Task - Last run time(local) is Wed Jan 20 11:23:00 2010
2010-01-21 09:16:53  I  #2804  Sched  Workstation Update Task - Last run time(local) is Wed Jan 20 11:23:00 2010

According to the log, my last update was 01/20/2010 @ 11:23:00.  (I find it interesting that the "Last run time" log entries do not specify AM or PM.)  Why did the update task change times from 01/22/2010 @ 16:34:00 to 01/22/2010 @ 00:29:00, between 09:05:28 and 09:06:00 in the log today?  Is there something that can trigger a re-randomization of the update time?

Thanks!

[JoeBidgood]

Can you post the full logs so I can have a look?

Thanks -

Joe

[runcmd]

My Agent_[hostname].log file rolls off pretty quickly.  At 1mb, I'm only storing about 4 hours worth of data, which translates to a maximum of about 8 hrs between the Agent_[hostname].log and the Agent_[hostname]_backup.log.  I just changed the "HKLM\SOFTWARE\Network Associates\ePolicy Orchestrator\LogSize" value from 1 to 4.  When I did that, I noticed that the LogLevel was set to 8.  I'm not sure why but it may have been from a previous support issue--I dropped it back to 7.  (Is it possible to force the LogSize and/or LogLevel for all clients by policy, rather than hacking the registry?)

That said, the entries I referred to in my previous post are already gone.  I checked my log this morning and it shows the last update as occurring 01/21/2010 @ 16:23:00...

2010-01-22 08:56:03 I  #1904  Sched  Workstation Update Task - Last run time(local) is Thu Jan 21 16:23:00 2010

That time doesn't match either of the times provided by yesterday's log entry.  If I can find similar entries, again, I'll post the full log.  Thanks for the help to-date!

Message was edited by: runcmd on 1/22/10 2:40:03 PM EST

[runcmd]

After letting this cook over the weekend, it appears that things have worked themselves out and it is both updating properly and calculating the updates properly.  Unless it happens again, I think my investigation is complete.  Thanks for the clarification you provided!  I wouldn't have figured this out by myself.

2010-01-23 17:17:02  I  #3532  Sched  Workstation Update Task - Last run time(local) is Fri Jan 22 14:27:00 2010
2010-01-23 17:22:00  i  #3504  Sched  Scheduler: Invoking task [Workstation Update Task]...
2010-01-23 17:22:00  I  #3504  Sched  Workstation Update Task - Last run time(local) is Sat Jan 23 17:22:00 2010
2010-01-23 17:22:00  i  #3504  Sched  Next time(local) of task Workstation Update Task: Sunday, January 24, 2010 9:41:00 AM
2010-01-23 17:22:00  I  #3500  Sched  The task Workstation Update Task is still running
2010-01-23 17:22:02  I  #3532  Sched  Workstation Update Task - Last run time(local) is Sat Jan 23 17:22:00 2010
2010-01-23 17:22:51  i  #3500  Sched  The task Workstation Update Task is successful
2010-01-23 17:22:51  i  #3500  Sched  Scheduler: Task [Workstation Update Task] is finished
2010-01-23 17:27:03  I  #3532  Sched  Workstation Update Task - Last run time(local) is Sat Jan 23 17:22:00 2010
---
2010-01-24 09:36:36  I  #3532  Sched  Workstation Update Task - Last run time(local) is Sat Jan 23 17:22:00 2010
2010-01-24 09:41:00  i  #3504  Sched  Scheduler: Invoking task [Workstation Update Task]...
2010-01-24 09:41:00  I  #3504  Sched  Workstation Update Task - Last run time(local) is Sun Jan 24 09:41:00 2010
2010-01-24 09:41:00  i  #3504  Sched  Next time(local) of task Workstation Update Task: Monday, January 25, 2010 12:52:00 PM
2010-01-24 09:41:00  I  #3500  Sched  The task Workstation Update Task is still running
2010-01-24 09:41:37  I  #3532  Sched  Workstation Update Task - Last run time(local) is Sun Jan 24 09:41:00 2010
2010-01-24 09:41:48  i  #3500  Sched  The task Workstation Update Task is successful
2010-01-24 09:41:48  i  #3500  Sched  Scheduler: Task [Workstation Update Task] is finished
2010-01-24 09:46:38  I  #3532  Sched  Workstation Update Task - Last run time(local) is Sun Jan 24 09:41:00 2010

[JoeBidgood]

Glad it appears to have sorted itself out

Regards-

Joe