Looking at setup.log records corresponding to automatic update I found that there are 2 types of records differ in /nolog and /updatenews parameters sending to avast.setup
24.04.2008 01:33:47.000 1208986427 general Started: 24.04.2008, 01:33:47
24.04.2008 01:33:47.000 1208986427 general Running setup_av_pro-49a (1178)
24.04.2008 01:33:47.000 1208986427 system Operating system: WindowsXP ver 5.1, build 2600, sp 2.0 [Service Pack 2]
24.04.2008 01:33:47.000 1208986427 system Memory: 13% load. Phys:2097151/2097151K free, Page:4194303/4194303K free, Virt:2068568/2097024K free
24.04.2008 01:33:47.000 1208986427 system Computer WinName: PSW
24.04.2008 01:33:47.000 1208986427 system Windows Net User: SYSTEM
24.04.2008 01:33:47.000 1208986427 general Cmdline: /downloadpkgs /noreboot /updatevps /verysilent /limitcpu
24.04.2008 01:33:47.000 1208986427 general DldSrc set to inet
24.04.2008 01:33:47.000 1208986427 general Operation set to INST_OP_UPDATE_GET_PACKAGES
24.04.2008 01:33:47.000 1208986427 general Old version: 49a (1178)
and
25.04.2008 20:00:05.000 1209139205 general Started: 25.04.2008, 20:00:05
25.04.2008 20:00:05.000 1209139205 general Running setup_av_pro-49a (1178)
25.04.2008 20:00:05.000 1209139205 system Operating system: WindowsXP ver 5.1, build 2600, sp 2.0 [Service Pack 2]
25.04.2008 20:00:05.000 1209139205 system Memory: 17% load. Phys:2097151/2097151K free, Page:4194303/4194303K free, Virt:2068568/2097024K free
25.04.2008 20:00:05.000 1209139205 system Computer WinName: PSW
25.04.2008 20:00:05.000 1209139205 system Windows Net User: SYSTEM
25.04.2008 20:00:05.000 1209139205 general Cmdline: /downloadpkgs /noreboot /updatenews /verysilent /nolog /limitcpu
25.04.2008 20:00:05.000 1209139205 general DldSrc set to inet
25.04.2008 20:00:05.000 1209139205 general Operation set to INST_OP_UPDATE_GET_PACKAGES
25.04.2008 20:00:05.000 1209139205 general Old version: 49a (1178)
Questiton: what are the conditions when any of these types of updates is applied?
And the second question: is there any method to enable temporary logging of all automatic update attempts?
(I’m not sure but it seems to me that in dial-up environment these attempts are too rare but without full logging it is difficult to define something)
avast provides several pop-up windows, most users are familiar with some of them…
the popup … this indicates a recent change to a VPS update or a program version update
the popup … this indicates a new update to VPS or a new program update is available
the popup … this indicates a problem during a VPS update or a program update
the popup … this very rare popup indicates information considered newsworthy by the avast team (they won an award etc)
To support these the avast update process needs to periodically check for:
VPS updates
program updates
news updates
It appears that (1) & (2) are covered by the same /downloadpkgs and /updatevps parameters. If the user has selected automatic updates then only the blue popup will be seen. If the user has selected “Ask” then the green popup will be shown.
The red popup will only occur when a problem occurs in updating the VPS file or program update.
The check for newsworthy items is covered by the /updatenews parameter.
I change nothing in my avast settings. So it is avast itself who choose which command line parameters should be used. It is interesting which criteria are used during this choose.
Last automatic update in the log I have is
20:17:17 min/gen Started: 25.04.2008, 20:17:17
20:17:17 min/gen Running setup_av_pro-49a (1178)
20:17:17 nrm/sys Operating system: WindowsXP ver 5.1, build 2600, sp 2.0 [Service Pack 2]
20:17:17 nrm/sys Memory: 25% load. Phys:2097151/2097151K free, Page:4194303/4194303K free, Virt:2068568/2097024K free
20:17:17 vrb/sys Computer WinName: PSW
20:17:17 min/sys Windows Net User: PSW\pashkov
20:17:17 min/gen Cmdline: /downloadpkgs /noreboot /updatevps /silent /progress
20:17:17 vrb/gen DldSrc set to inet
20:17:17 vrb/gen Operation set to INST_OP_UPDATE_GET_PACKAGES
20:17:17 min/gen Old version: 49a (1178)
…
20:17:33 min/gen Return code: 0x20000001 [Nothing done]
20:17:33 min/gen Stopped: 25.04.2008, 20:17:33
Last manual update record is
02:17:36 min/gen Started: 26.04.2008, 02:17:36
02:17:36 min/gen Running setup_av_pro-4a1 (1185)
…
02:17:41 min/gen Return code: 0x20000001 [Nothing done]
02:17:41 min/gen Stopped: 26.04.2008, 02:17:41
After this I’ve break my connection, but PC was active (no shutdown). I’ve started a new connection this morning. It is interesting when avast will make next automatic update (yes, I can make manual one, but I want to wait auto one).
20:17:17 min/gen Old version: 49a (1178)
…
I will admit I have not investigated in detail some of these issues. However, it is clear that the VPS updates are the priority for avast.
If automatic updates are the choice of the user then avast will perform the /updatevps /limitcpu on every system startup and then (by default) every 240 minutes thereafter. If you terminate your connection then (as I understand at present) the cycle would begin again as described at the next connection. The cycle is certainly reset by a system restart.
The /updatenews items are really just cosmetic - to the best of my knowledge - and I have not investigated the timing of their initiation.
I add avast.setup logging into firewall and found that avast.setup really trying to connect for updating. Timing are consisting with assumption that updating triggered at the system start
(25.04.08 21:09:24). Using default update interval 240 min planned update times should be 01:15, 05:15, 09:15, 13:15 and so on.
Because of I added logging only at 12:00 now I should have only 1 logged update attempt (26.04.08 13:22:45) but duration of this update and its status are unknown. Resetting dial-up connection itself don’t trigger update process (next firewall log entry for avast.setup marked as 17:25:54. BTW, estimated automatic update duration is 3 min - extra time between 17:25:54 and 13:22:45).
Reaction of avast for the situation when no connection is present at planned update time is unknown.
And I understand the reason why log record at 25.04.08 20:00:05 was appeared. It corresponds to checking for program update. Timing is normal (system restart at 15:51, so next update triggered to ~20:00). But the presence of this record means that new program version is present (probably, 4.8.1185)
20:00:12 vrb/pkg LoadPartInfo: program = prg_av_pro-4a1 returned 00000000
20:00:12 vrb/pkg LoadPartInfo: setup = setup_av_pro-4a1 returned 00000000
I was not near PC, so I can not to say was corresponding green info screen shown or not.
Continuation of checking auto update in RAS configuration.
My settings: VPS update - auto, Progam Updates - Ask, UseRAS=1 AssumeAlwaysConnected=0 UpdatePeriod=240 RASWaitSeconds=180
Before last successfull update check was at 26.04.08 17:25:54
So the next planned update should be near 21:25
I break my connection at 21:20 and start a new one at 21:38:41
Within this interval was no red splash screens (expected).
Autoupdate was started at 21:41:43 (it looks like avast! detected start of connection and waited RASWaitSeconds for start of update).
There are 2 records in FW:
21:41:43 (corresponds to program updates check /updatenews. If to this time there are no program updates but some VPS update is present, this call detects this and trigger /updatevps call)
21:41:46 (/updatevps call, blue splash panel after update)
Next autoupdate is expected at current update time + UpdatePeriod + RASWaitSeconds
Yes, it did at 27.04.08 01:46:48
Dialup connection was broken at 02:12:53 and restarted at 09:20:24
Avast! started autoupdate at 09:23:55 (+RASWaitSeconds)
But this RAS connection was faulty (due to incomplete FW rules svchost connection to DNS server was blocked by FW). So this autoupdate lasted 3 min and gave error log record
09:23:56 nrm/int SYNCER: Agent=Syncer/4.80 (av_pro-1185;p)
09:24:13 nrm/int ERROR:HttpGetWininet, catch returned 0x00002EE7
09:24:31 nrm/int ERROR:HttpGetWininet, catch returned 0x00002EE7
09:24:31 nrm/gen InvalidateCurrent: invalidated server ‘Test (external beta)’ from ‘main’
09:24:31 min/gen SelectCurrent: unable to find any suitable server in ‘main’
09:24:31 dbg/int while trying to get file ‘servers.def.vpu’, error 0x20000004 has occured, try 1
09:24:31 min/int tried 1 servers to get file ‘servers.def.vpu’, but failed (0x20000004)
After unsuccesive update I got red splash screen.
I corrected FW rules and restarted dial-up connection, but this doesn’t trigger immediately update check. So I will wait for next UpdatePeriod time.
Yes, autoupdate was made at 13:33.07. For me this update was delayed by ~3 min (expected time was 13:30 because of last setup log entry was
09:26:49 min/gen Return code: 0x20000004 [Cannot connect to www2.avast.com (unknown:80).]
09:26:49 min/gen Stopped: 27.04.2008, 09:26:49
Indeed… checked now and it runs at level 6 (avast.setup). So, below normal even the manual update. It’s not what I’ve understand from Igor’s and Vlk’s posts… manual should be normal if not higher priority…
@ Tech and psw
The problem is not the priority Below Normal, but the unrestricted CPU use of the manual scan taking up 100% of CPU because it doesn’t have the /limitcpu parameter at the end of the Cmdline:.
So an auto update would have that /limitcpu parameter at the end of the line where a Manual update (or the ‘Ask’ update) doesn’t have that restriction.
Well they may or may not be related, if there are other applications running at a higher priority then they windows would allocate the lions share of CPU time to the higher priority. But when the other applications are either idle or running at the same priority as avast.setup then the avast.setup will gobble up as much CPU as it can until there is none left without the /limitcpu parameter.
If a higher priority application becomes active then windows should re-allocate cpu time, but that may still result in high CPU loads.