Setup.log question

[psw]

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)

[alanrf]

Let me see if I can help...

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:

1) VPS updates
2) program updates
3) 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.

[psw]

Questions are different.
1. 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.
2. 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)
... 

[alanrf]

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.     

[psw]

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.

[Lisandro]

Automatic updates run with /verysilent parameter and low priority.
Manual updates run according to avast update settings and normal priority.

The /updatenews items are really just cosmetic - to the best of my knowledge - and I have not investigated the timing of their initiation.

There are avast4.ini file settings for the iNews.

[DavidR]

See this post, in which I also identify the two differing cmdline: entries, http://forum.avast.com/index.php?topic=34995.msg294117#msg294117.

[alanrf]

In another thread today Tech said:

Quote from: alanrf on Yesterday at 01:07:05

It is often the case in this forum ... opinions (good and bad) are often based on a total absence of real testing of the product.

Just to comment: generally, my posts refers to personal experiences and tests. If not, I based my opinions on other experiences and tests.

Then I am sorry to report that you persist in posting this incorrect statement:

Manual updates run according to avast update settings and normal priority.

[psw]

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

[Lisandro]

Then I am sorry to report that you persist in posting this incorrect statement:

Manual updates run according to avast update settings and normal priority.

What is wrong on it?
Normal or high priority? I would like a confirmation...
What's wrong?

[psw]

Manual updates run at priority 'Below Normal' (6) whelr 'Normal' priority is 8.

[Lisandro]

Manual updates run at priority 'Below Normal' (6) whelr 'Normal' priority is 8.

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...

[DavidR]

@ 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.

[Lisandro]

@ 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.

I see... so the problem is the CPU and not the priority... I thought both will be directed related

[DavidR]

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.