Avast related networking issue

Hello,

I’ve identified a networking issue which thus far appears Avast related. For starters, I’m running a fully up to date XP Pro desktop equipped with Firefox 3.6.8, latest Noscript/AdblockPlus/etc, Avast 5.0.594 (100828-0), and Comodo Firewall 4.1.150349.920. Any malware infection is highly unlikely. I’m not sure when this issue first cropped up, but it has been awhile.

I’ve at times seen unusually heavy network activity lights a short time after closing my last browser instance (when there should be virtually no network traffic). Investigating, I’ve seen what I believe are abnormal terminations of the connection between AvastSvc.exe and some (not all) target webservers. For example, www.digg.com loads .js, .ico, .png, .css, and perhaps other types from the likes of cdn1.diggstatic.com which forward resolves to 98.142.106.40. That IP address reverse resolves to lb140.nyny.cotendo.net and it is this later hostname you will see in the following logs. A simple, reproducable (for me at least) test case where I simply load http://lb140.nyny.cotendo.net

When Avast WebShield is running:

2010-08-28 14:14:50.328672 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [SYN] Seq=0 Win=65535 Len=0 MSS=1460
2010-08-28 14:14:50.348124 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
2010-08-28 14:14:50.348353 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [ACK] Seq=1 Ack=1 Win=65535 Len=0
2010-08-28 14:14:50.348912 [my ipaddress] lb140.nyny.cotendo.net HTTP GET / HTTP/1.1
2010-08-28 14:14:50.368373 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [ACK] Seq=1 Ack=377 Win=6432 Len=0
2010-08-28 14:14:50.385265 lb140.nyny.cotendo.net [my ipaddress] HTTP HTTP/1.1 403 forbidden (text/html)
2010-08-28 14:14:50.450851 [my ipaddress] lb140.nyny.cotendo.net HTTP GET /favicon.ico HTTP/1.1
2010-08-28 14:14:50.485166 lb140.nyny.cotendo.net [my ipaddress] HTTP HTTP/1.1 404 not found (text/html)
2010-08-28 14:14:50.617714 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [ACK] Seq=734 Ack=1184 Win=64352 Len=0
2010-08-28 14:14:53.449087 [my ipaddress] lb140.nyny.cotendo.net HTTP GET /favicon.ico HTTP/1.1
2010-08-28 14:14:53.487361 lb140.nyny.cotendo.net [my ipaddress] HTTP HTTP/1.1 404 not found (text/html)
2010-08-28 14:14:53.680120 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [ACK] Seq=1121 Ack=1779 Win=65535 Len=0
2010-08-28 14:15:13.530165 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [FIN, ACK] Seq=1779 Ack=1121 Win=8576 Len=0
2010-08-28 14:15:13.530218 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [ACK] Seq=1121 Ack=1780 Win=65535 Len=0
** Note: time gap **
2010-08-28 14:16:48.927284 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:16:48.947329 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0
2010-08-28 14:16:50.488877 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:16:50.509768 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0
2010-08-28 14:16:53.660650 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:16:53.682473 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0
2010-08-28 14:17:00.113569 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:17:00.134217 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0
2010-08-28 14:17:12.910029 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:17:12.929682 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0
2010-08-28 14:17:38.502955 [my ipaddress] lb140.nyny.cotendo.net TCP syscomlan > http [FIN, ACK] Seq=1121 Ack=1780 Win=65535 Len=0
2010-08-28 14:17:38.521268 lb140.nyny.cotendo.net [my ipaddress] TCP http > syscomlan [RST] Seq=1780 Win=0 Len=0

Then again after Avast WebShield is stopped:

2010-08-28 14:25:37.721448 [my ipadress] lb140.nyny.cotendo.net TCP cognex-insight > http [SYN] Seq=0 Win=65535 Len=0 MSS=1460
2010-08-28 14:25:37.741270 lb140.nyny.cotendo.net [my ipadress] TCP http > cognex-insight [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
2010-08-28 14:25:37.741542 [my ipadress] lb140.nyny.cotendo.net TCP cognex-insight > http [ACK] Seq=1 Ack=1 Win=65535 Len=0
2010-08-28 14:25:37.742376 [my ipadress] lb140.nyny.cotendo.net HTTP GET / HTTP/1.1
2010-08-28 14:25:37.760486 lb140.nyny.cotendo.net [my ipadress] TCP http > cognex-insight [ACK] Seq=1 Ack=377 Win=6432 Len=0
2010-08-28 14:25:37.881849 lb140.nyny.cotendo.net [my ipadress] HTTP HTTP/1.1 403 forbidden (text/html)
2010-08-28 14:25:38.190579 [my ipadress] lb140.nyny.cotendo.net TCP cognex-insight > http [ACK] Seq=377 Ack=589 Win=64947 Len=0
2010-08-28 14:25:57.901817 lb140.nyny.cotendo.net [my ipadress] TCP http > cognex-insight [FIN, ACK] Seq=589 Ack=377 Win=6432 Len=0
2010-08-28 14:25:57.901871 [my ipadress] lb140.nyny.cotendo.net TCP cognex-insight > http [ACK] Seq=377 Ack=590 Win=64947 Len=0
** Note: no time gap **
2010-08-28 14:26:03.924709 [my ipadress] lb140.nyny.cotendo.net TCP cognex-insight > http [FIN, ACK] Seq=377 Ack=590 Win=64947 Len=0
2010-08-28 14:26:03.944991 lb140.nyny.cotendo.net [my ipadress] TCP http > cognex-insight [ACK] Seq=590 Ack=378 Win=6432 Len=0

I’m rusty when it comes to TCP/IP and Windows networking, but based on the above and observing the TCP/IP connections of Firefox and AvastSvc.exe with Sysinternals Process Explorer, my initial guess is that under some circumstances AvastSvc.exe might not be promptly recognizing and responding to the webserver closings its end.

I’m sharing this in the hopes that others can reproduce it and thus Avast folk can easily investigate further. Confirmation and comments appreciated. Thanks!

Hi Gav,
I am on a similar setup, but can’t reproduce/confirm this behaviour…!!
asyn

Investigating, I've seen what I believe are abnormal terminations of the connection between AvastSvc.exe and some (not all) target webservers.

This is normal as the avastSvc.exe is the main scanning engine and the web shield (and other shields) is controlled by it. So when your browser connects to a site that connection is redirected through the web shield proxy and avastSvc.exe is shown as making the connection rather than seeing it as firefox.exe, etc.

See image extract of my firewall log.

The web shield (or avastSvc.exe) don’t initiate connections of their on volition they are redirecting http port 80 connections through the avast web shield localhost proxy.

Dave, he was talking about connections after closing his browser…!
asyn

So connections take time to die, avast has no control over that if the connection is open avast will still be monitoring it.

True. :wink:
Just for comparision for the OP. It takes about 15 seconds here.
asyn

I have never bothered checking as it is not something that I have any control over.

Thanks for the replies, and attempts to reproduce this. To clarify some things…

I understand that Avast is creating a proxy and, having written numerous proxies back in the day, I understand what that is and how they behave. Unfortunately, I forget much of what I knew and can no longer draw state transition diagrams from memory, recall Windows [version] specific stack quirks, etc. So leave room for me being confused on some details.

I believe I misspoke early, when I said “…after closing my last browser instance”. Come to think of it, I normally don’t close my last browser instance but simply hit home to load my local file home page. I just took a quick look and it appears that behavior is as expected when the browser instance is actually closed. Namely, AvastSvc.exe detects and helps cleanly complete the browser side connection termination and, seeing that, immediately and cleanly terminates its own connection with the webserver. However, if I load http://lb140.nyny.cotendo.net/ and then hit the home button, the socket behavior is the same as if I just left the browser alone. IOW, Firefox does not detect that I’ve navigated away from the http URL to a local file URL… Firefox does not close its connection to the Avast proxy… therefore I still see the abnormal termination behavior I originally questioned.

Regarding the abnormal behavior, it is the behavior after the webserver’s [FIN, ACK]. To perhaps make things easier, here is a log captured while WebShield is running and when visiting a site that doesn’t trigger the behavior I question:

2010-08-28 19:53:17.929676 [my client] [my server] TCP ff-annunc > http [SYN] Seq=0 Win=65535 Len=0 MSS=1460
2010-08-28 19:53:18.029919 [my server] [my client] TCP http > ff-annunc [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
2010-08-28 19:53:18.030230 [my client] [my server] TCP ff-annunc > http [ACK] Seq=1 Ack=1 Win=65535 Len=0
2010-08-28 19:53:18.030796 [my client] [my server] HTTP GET / HTTP/1.1
2010-08-28 19:53:18.130826 [my server] [my client] TCP http > ff-annunc [ACK] Seq=1 Ack=370 Win=6432 Len=0
2010-08-28 19:53:18.233895 [my server] [my client] HTTP HTTP/1.1 200 OK (text/html)
2010-08-28 19:53:18.267786 [my client] [my server] HTTP GET /favicon.ico HTTP/1.1
2010-08-28 19:53:18.368490 [my server] [my client] TCP http > ff-annunc [ACK] Seq=698 Ack=720 Win=7504 Len=0
2010-08-28 19:53:18.391848 [my server] [my client] HTTP HTTP/1.1 404 Not Found (text/html)
2010-08-28 19:53:18.599544 [my client] [my server] TCP ff-annunc > http [ACK] Seq=720 Ack=1108 Win=64428 Len=0
2010-08-28 19:53:21.260157 [my client] [my server] HTTP GET /favicon.ico HTTP/1.1
2010-08-28 19:53:21.362277 [my server] [my client] HTTP HTTP/1.1 404 Not Found (text/html)
2010-08-28 19:53:21.552571 [my client] [my server] TCP ff-annunc > http [ACK] Seq=1100 Ack=1518 Win=65535 Len=0
2010-08-28 19:53:36.356724 [my server] [my client] TCP http > ff-annunc [FIN, ACK] Seq=1518 Ack=1100 Win=8576 Len=0
2010-08-28 19:53:36.356779 [my client] [my server] TCP ff-annunc > http [ACK] Seq=1100 Ack=1519 Win=65535 Len=0
2010-08-28 19:53:41.740387 [my client] [my server] TCP ff-annunc > http [FIN, ACK] Seq=1100 Ack=1519 Win=65535 Len=0
2010-08-28 19:53:41.840893 [my server] [my client] TCP http > ff-annunc [ACK] Seq=1519 Ack=1101 Win=8576 Len=0

In this and the previous cases, it is the webserver that initiates the termination. Notice how in this example (and example #2 above) it goes:

Webserver — [FIN, ACK] —> LocalMachine
LocalMachine — [ACK] --------> Webserver

and then fairly quickly:

LocalMachine — [FIN, ACK] —> Webserver
Webserver — [ACK] --------> LocalMachine

Compare that to log #1, where it goes:

Webserver — [FIN, ACK] —> LocalMachine
LocalMachine — [ACK] --------> Webserver

and then after a significant amount of time:

LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine
LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine
LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine
LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine
LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine
LocalMachine — [FIN, ACK] —> Webserver
Webserver — [RST] --------> LocalMachine

I don’t think this is normal behavior. Something is causing my machine to respond too slowly to the Webserver’s close, and by the time my machine gets around to sending a [FIN, ACK] the Webserver no longer expects it and replies with a RST. Since I’ve so far only seen this happen with certain sites when Avast WebShield is running, I suspect it is related to WebShield running. My thought was that for some reason AvastSvc.exe isn’t catching an event notification of the Webserver’s close, and then after a lengthy timeout, AvastSvc.exe is just up and initiating a close of both its connection with the Webserver and its connection with Firefox.

Is there any way for end users to enable AvastSvc.exe debug output?