415005 - Investigate antivirus performance

Status: RESOLVED WONTFIX

(Toolkit :: Downloads API, defect)

Description

[Rob Arnold [:robarnold]]

Several users complain of long scan times, especially in comparison to manually scanning with the scanner. In bug 412565 comment 12, Petr suggests that the time taken to initialize the scanner is significantly bigger than the scan time. If this is the case for many scanners, then we can re-architect the download scanner for better performance.

Comment 1

[Rob Arnold [:robarnold]]

Attachment: Performance reporting program

This program enumerates all installed scanners and runs them through several iterations measuring the time taken to initialize, scan and cleanup.

Comment 2

[Rob Arnold [:robarnold]]

Attachment: Performance reporting program (binary)

For convenience, I'm attaching a build of the above program. It is compiled with vc8, so you'll need the vc8 redist if you don't already have it (http://www.microsoft.com/Downloads/details.aspx?FamilyID=32bc1bee-a3f9-4c13-9c99-220b62a191ee).

Comment 3

[Stephen Donner [:stephend] Not actively reading bugmail]

Attachment: Windows Defender and AVG Free timings (run against a 256MB self-extracting exe/zip file)

I ran ScannerTimer.exe on a 256MB file: dxsdk_november2007.exe, with AVG Free 7.5.516 installed on Windows Vista (3.0GHz, with 1.5GB of RAM).

Comment 4

[Rob Arnold [:robarnold]]

Attachment: Performance reporting program (binary)

Turns out that the binary I posted seems to only work on my computer. This new one seems to work everywhere so far (same source, different compiler/settings)

Comment 5

[Stephen Donner [:stephend] Not actively reading bugmail]

Comment on attachment 301093 [details]
Windows Defender and AVG Free timings (run against a 256MB self-extracting exe/zip file)

This ended up being a bogus run, since the file was only 256MB (partial download for some inane reason); it should be 427MB

Comment 6

[Stephen Donner [:stephend] Not actively reading bugmail]

Attachment: Same as above, but with the complete file

Comment 7

[Shawn Wilsher :sdwilsh]

Rob & Jim:
Is this good enough information for you?

Comment 8

[Rob Arnold [:robarnold]]

Attachment: Results for NAV 2005

I'd like to get result for McAfee as well since it is notoriously slow in my experience. Also, this doesn't test the speed of using IAttachmentExecute, but I expect performance to be similar. So far, the trend seems to be that the cost of the scan outweighs the cost of initialization for large files. We should find a small file to test as well.

Comment 9

[Stephen Donner [:stephend] Not actively reading bugmail]

(In reply to comment #8)
> Created an attachment (id=301211) [details]
> Results for NAV 2005
> 
> I'd like to get result for McAfee as well since it is notoriously slow in my
> experience. Also, this doesn't test the speed of using IAttachmentExecute, but
> I expect performance to be similar. So far, the trend seems to be that the cost
> of the scan outweighs the cost of initialization for large files. We should
> find a small file to test as well.

I'll have McAfee results for you tomorrow (native-hardware, non-VM instance).

Suggestions for the small file against which to compare?

Comment 10

[Rob Arnold [:robarnold]]

Attachment: Performance reporting program (binary)

Updated program to include IAttachmentExecute

Comment 11

[Rob Arnold [:robarnold]]

Attachment: Performance reporting program (source)

Updated version of the source

Comment 12

[Rob Arnold [:robarnold]]

Attachment: IAttachmentExecute results for XP SP2, NAV 2005

Here's the IAE results from my machine. I wonder how they differ by OS/AV

Comment 13

[Stephen Donner [:stephend] Not actively reading bugmail]

Attachment: Trend Micro Internet Security 2007 IAttachmentExecute results

Machine specs: Pentium 4, 3GHz, 2GB of RAM, running Windows XP SP2.

Comment 14

[Stephen Donner [:stephend] Not actively reading bugmail]

Attachment: McAfee VirusScan Plus 2007 IAttachmentExecute results

Same machine as in comment 13; McAfee VirusScan Plus 2007+ apparently only implements IAttachmentExecute, not IOfficeAntiVirus...

Comment 15

[Jim Mathies [:jimm]]

Pretty much every product tested here shows object init time to be irrelevant. Scan times seem respectable too, although that big scan Stephen did with AVG was horrible -

90.747846 362851.492578 26.066441
44.696742 219959.783995 16.461031
48.839168 269356.713214 14.975646
48.478787 199839.564805 15.211710
42.317948 188428.665096 14.930389
47.754673 167952.587270 12.895494
45.877060 185196.683377 12.846046
19.227583 171427.452092 15.220650
44.929453 182586.207465 15.331278
37.683002 191615.700319 12.619760
45.180882 173139.888450 14.851050
..

Performance improved though in consecutive scans.  

The products that don't kick in the IOfficeAntiVirus are largely irrelevant as well, those are the ones that have chosen other methods to monitor files, and IAE times on all of them looked fine.
 
My own tests showed AVG taking about 3 seconds with heavy disk thrashing during the scan. That, IMHO, is not something we can control - it's the user's choice what they run. Since the product if free, maybe that's just the price you pay.

I'd say avoid initialization on boot of the browser and due to memory retention in the IOAV objects, create and destroy each scanner on a per scan basis. Anybody else?

Comment 16

[Shawn Wilsher :sdwilsh]

(In reply to comment #15)
> I'd say avoid initialization on boot of the browser and due to memory retention
> in the IOAV objects, create and destroy each scanner on a per scan basis.
> Anybody else?
I agree.

Comment 17

[Jim Mathies [:jimm]]

"due to memory retention in the IOAV objects.."

~45MB for one product I just tested.

not cool. 

Comment 18

[Stephen Donner [:stephend] Not actively reading bugmail]

Rob / Jim - would you like to see more from QA?  Rob had mentioned to me at one point he'd like to see small-file-size-scan results; let me know.

Comment 19

[Matt]

Attachment: IAttachmentExecute NOD 32 v2.70.39 XP SP2, Also Bit defender free v10(2nd scan result)

Comment 20

[Matt]

I seemed to have gotten a weird output, please see my attachment asap.

Comment 21

[Rob Arnold [:robarnold]]

(In reply to comment #20)
> I seemed to have gotten a weird output, please see my attachment asap.
> 

Do you consistently get these results over multiple runs? Which file did you test this on? I assume that your computer wasn't doing anything else while the program ran.

Comment 22

[Matt]

Yep, and similar runs with different files as well. Will post more if you want

ScannerTimer.exe dxsdk_november2007.exe

is what i did for the attachment posted. nothing else is really running. I also checked with a 134mb self-executable zip file, and a regular 12 .exe install file.

Also just checked on some zipped/compressed files, including Firefox's source file (beta 2 source) and very similar output. I'll post that as an example. I have no other programs running except Firefox, the virus scanner (which is always on), AVG anti-spyware, and pidgin. I don't see how any of those programs would or could cause problems except for AVG, which I'm uninstalling now to rule out. I also realized i had bit defender anti virus installed, uninstalling that. Bit defender wasn't running in the back round though.

Comment 23

[Matt]

{ 0x68da9fab, 0x4a6a, 0x4975, {0xa1, 0xca, 0xb5, 0x0e, 0x56, 0xb1, 0xf4, 0xf3} }

Is pretty much the line that stays consistent between running that program. Everything AV/Spyware scan related is now uninstalled and computer has been rebooted. No matter what file is put into there 400mb dxsdk file, or 1.41 text file all seem to show that same output in the file. All other outputs appear different. Posted results again of dxsdk*.exe file, but also with a nspr_leaks.log (text file 1.4kb in size from leak-gauge.pl output), and also the beta 2 Firefox source (245mb in size).

Comment 24

[Matt]

Attachment: IAttachmentExecute NOD 32 v2.70.39 XP SP2 - 3 file test output - 2008021104 Minefield/3.0b4pre , Also Bit defender free v10(2nd scan result)

Comment 25

[Rob Arnold [:robarnold]]

The third time you ran in, there's this line
> 0.030730 0.260089 -0.005867

That last number shouldn't be negative. Are you running XP in a virtual machine?

Comment 26

[Jim Mathies [:jimm]]

>I seemed to have gotten a weird output, please see my attachment asap.

I'm not sure I understand why this output is unexpected - first runs across unknown files would require extra work. 

Comment 27

[Rob Arnold [:robarnold]]

(In reply to comment #26)
> >I seemed to have gotten a weird output, please see my attachment asap.
> 
> I'm not sure I understand why this output is unexpected - first runs across
> unknown files would require extra work. 
> 

It's unexpected to me since IAE should just be writing some data to disk whereas the AV scanner should be doing (hopefully) lots more analysis on the file. The numbers in his output are the exact opposite of what we've seen so far.

Comment 28

[Matt]

(In reply to comment #25)
> The third time you ran in, there's this line
> > 0.030730 0.260089 -0.005867
> 
> That last number shouldn't be negative. Are you running XP in a virtual
> machine?
> 

No, no virtual machine.

In response to Rob's comment, you mean that in my case I'm actually experiencing much faster scan times than most people? I still don't get how then I've had it turn Firefox unresponsive for 10-15 seconds (lately use to be much worse), particularly on large files. Wish I had a specific example as some files are worse than others but generally larger = longer hang times.

Comment 29

[Matt]

Also, sorry spamming the comments, but is { 0x68da9fab, 0x4a6a, 0x4975, {0xa1, 0xca, 0xb5, 0x0e, 0x56, 0xb1, 0xf4, 0xf3}
}
meaningful in anyway? It doesn't appear in trendnet or mcaffee scans.

As for the -0.005867 I'm not sure why, I re-ran the test on that file again, no negative numbers. Not sure why that particular run had that there. I'll be on the look out for any negative numbers in future runs.

Comment 30

[Matt]

Another weird development. I decided to go ahead and try to reinstall NOD32, leaving all settings default. I figured I'd run the tests again, record results before, and then compare after. I happened to run scannertimer.exe with no file specified to scan.. and it displayed an output. I also tried on filenames I know don't exist. It also displayed an output for those non existing file names.. is this suppose to happen?

Comment 31

[Matt]

Attachment: After uninstall/reinstall NOD32 2.70, default settings, Also Bit defender free v10(2nd scan result)

Comment 32

[Matt]

Attachment: Uninstalled 2.7, Rebooted Installed NOD32 3.0.621.0 - XP SP2

Comment 33

[Jim Mathies [:jimm]]

>Another weird development. I decided to go ahead and try to reinstall NOD32,
>leaving all settings default. I figured I'd run the tests again, record results
>before, and then compare after. I happened to run scannertimer.exe with no file
>specified to scan.. and it displayed an output. I also tried on filenames I
>know don't exist. It also displayed an output for those non existing file
>names.. is this suppose to happen?

Yes, it passes in a default filename of eicar.com that it looks for in the working directory. The interface is still called with the missing file and the results are totaled.

Comment 34

[Jim Mathies [:jimm]]

>Also, sorry spamming the comments, but is { 0x68da9fab, 0x4a6a, 0x4975, {0xa1,
>0xca, 0xb5, 0x0e, 0x56, 0xb1, 0xf4, 0xf3}
>}
>meaningful in anyway? It doesn't appear in trendnet or mcaffee scans.


A search on google seems to indicate it's either part of nod32 or some sort of back door trojan installed on your system that's registered as a virus scanner. 

http://www.google.com/search?q=68da9fab&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:en-US:official&client=firefox-a

You might try uninstalling nod32, then running the scan test to see if it is removed from the list. If not I'd suggest digging into your registry to find the dll associated with that clsid to take a closer look at it.

Comment 35

[Matt]

(In reply to comment #34)
> >Also, sorry spamming the comments, but is { 0x68da9fab, 0x4a6a, 0x4975, {0xa1,
> >0xca, 0xb5, 0x0e, 0x56, 0xb1, 0xf4, 0xf3}
> >}
> >meaningful in anyway? It doesn't appear in trendnet or mcaffee scans.
> 
> 
> A search on google seems to indicate it's either part of nod32 or some sort of
> back door trojan installed on your system that's registered as a virus scanner. 
> 
> http://www.google.com/search?q=68da9fab&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:en-US:official&client=firefox-a
> 
> You might try uninstalling nod32, then running the scan test to see if it is
> removed from the list. If not I'd suggest digging into your registry to find
> the dll associated with that clsid to take a closer look at it.
> 
In regards to that, I figured it out to be bit defender anti virus free v10, which I didn't realize was called for scanning as well, I forgot it was even installed really. I've since uninstalled that and that registry key isn't there anymore. I'll take a look... seems to have disappeared completely though since uninstalling that. I also uninstalled 2.7 and replaced it with nod 3.0 so that could be it as well.

I'm still not sure what the negative number sometimes means/meant. It pops up from time to time. Also, as it appears the scan is very fast, NOD32 is known for fast scanning/low system resource usage and being one of if not the best at detection as well. However with certain files, for instance I downloaded the latest ad-aware from betanews.com last night as a test, and the browser was unresponsive for 5-10 seconds during the scan. Alot better than it use to be (especially with v3.0 of NOD32, but I also think that's been due to frequent patching since the initial release.. mostly a NOD32 problem). Running the scannertimer on the file a few times seemed only to show the problem once, however I'm not exactly sure how to interpret the output other than how fast it displays it on screen. AVG 7.5 free edition was the worst with this I actually closed it the scannertimer was taking so long on dxsdk, but I plan on running it again and posting results unless someone says that its not needed.

Also I'm going to apologize for the post spam last night, but most of the new information seemed relevant, I should have held off and just posted it all in one post.

Comment 36

[Jim Mathies [:jimm]]

>and the browser was unresponsive for 5-10 seconds during the scan.

Just to confirm, are you saying the browser window was completely frozen or was it just unresponsive (as in something that could be caused by a CPU spike)?

>Running the
>scannertimer on the file a few times seemed only to show the problem once,
>however I'm not exactly sure how to interpret the output other than how fast it
>displays it on screen..

I think your numbers are ok - 200ms-300ms for a scan time on first use. Most of the tests we've run show this kind of behavior but slightly smaller (50ms-200ms) but we never tested nod32. We should probably confirm your results on our end.

Comment 37

[Matt]

Relevant wilderssecurity thread i just happened upon: http://www.wilderssecurity.com/showthread.php?t=197056

Comment 38

[Shawn Wilsher :sdwilsh]

(In reply to comment #37)
> Relevant wilderssecurity thread i just happened upon:
> http://www.wilderssecurity.com/showthread.php?t=197056
It looks to me like they are talking about Firefox 2 in that thread...

Comment 39

[James May [:fowl2]]

What about the case with no anti-virus installed, is that slow because we have to go looking for one each time?

Comment 40

[Rob Arnold [:robarnold]]

Older versions of Firefox would explicitly enumerate anti virus providers when the download manager started (and only then). Our newer code uses a different interface provided by Windows starting in XP SP2. This API is a black box - we haven't investigated what it does on each OS though someone with spare time and regmon/filemon from sysinternals should be able to figure out what it does.

Comment 41

[Aaron Lawrence]

As noted elsewhere. apparently Nod32 is quite slow when using it's "advanced heuristics" option, speedy otherwise.
To me it seems that the whole browser is hanging, not merely slow... hence, bug 551427

Comment 42

[Ioana (away)]

Is there anything still needed from QA here? I don't see any specific request when the keyword was added.

Comment 43

[[:mmc] Monica Chew (no longer reading bugmail)]

(In reply to Ioana Budnar, QA [:ioana] from comment #42)
> Is there anything still needed from QA here? I don't see any specific
> request when the keyword was added.

No, the download scanner will be removed entirely: https://mail.mozilla.org/pipermail/firefox-dev/2013-August/000848.html

Marking as WONTFIX.