AdGuard causing MySQL connections to fail

jamesx · Feb 18, 2015

[Fixed] Adguard causing MySQL connections to fail

This behavior was observed on multiple machines with multiple MySQL versions.

Opening a connection to a remote MySQL server either via the MySQL console client or a 3rd party application (e.g SQLYog) is randomly delayed or aborted with error

"Error No. 2013 Lost connection to MySQL server at 'sending authentication information', system error: 2"

Reproduction:

It can be best reproduced by using SQLYog, setting up a connection to some remote MySQL server in the connection window and pressing the "Test Connection" button repeatedly.

Expected behavior: A window should pop up immediately containing a message "Connection successfully"
Actual behavior: Sometimes the confirmation window is delayed multiple seconds, sometimes it aborts with the error above

The problem disappears completely when either Adguard is switched to "Use Adguard as an HTTP proxy" or fully disabled.

Adguard Version: 5.10.1190.6188

Offtopic:
GUI grammar nazi: "Use Adguard as an HTTP proxy" -> "Use Adguard as HTTP proxy" or ""Use Adguard as a HTTP proxy"

vasily_bagirov · Feb 19, 2015

Hi! We'll test this and will reply you with the results.

PS: looks like 'an HTTP' is correct, for example: http://boards.straightdope.com/sdmb/showthread.php?t=181249

---------- Post added at 06:03 PM ---------- Previous post was at 05:11 PM ----------

In fact, we need more data about MySQL settings:

- What port does MySQL connect to?
- Does it use TCP protocol?

jamesx · Feb 23, 2015

Remote TCP connection to default port (3306).

avatar · Feb 23, 2015

Can't reproduce it on our side.

jamesx said:
Remote TCP connection to default port (3306).

1. What type of authentication do you use? Simple user/password or maybe something like windows authentication?

2. Could you please try http://www.mysql.com/products/workbench/ instead of SQLYog?
Just to check if the problem is specific to SQLYog.

3. Do you use Adguard in HTTP proxy mode?

jamesx · Feb 23, 2015

avatar said:
Can't reproduce it on our side.
1. What type of authentication do you use? Simple user/password or maybe something like windows authentication?

Simple MySQL user/pass auth

avatar said:
Can't reproduce it on our side.
2. Could you please try http://www.mysql.com/products/workbench/ instead of SQLYog?
Just to check if the problem is specific to SQLYog.

This issue is also reproducible by using the mysql.exe console client shipped from MySQL directly. I just added the description for SQLYog because the "Test Connection" button can be pressed repeatedly and reproduces the randomly occuring issue faster.

Of course you can setup your mysql client for auto login by using the [client] section of the my.ini and run mysql.exe repeatedly on command line, the results are the same. At some point the connection is either delayed multiple seconds and in the worst case it is aborted with the error show in the first post.

I just retested this issue with both a virtual machine (running Adguard and MySQL) and a regular machine using the console client.

I recommend reproducing it by having the MySQL server instance installed on another machine not just locally, to force real TCP-IP connections rather than going via localhost.

avatar said:
Can't reproduce it on our side.
3. Do you use Adguard in HTTP proxy mode?

No, I am using Adguard in HTTP proxy mode to work around this issue. As soon as a switch Adguard back to normal mode it reappears.

avatar · Feb 23, 2015

We have some mysql servers so I've used them trying to reproduce this issue.

There is one difference between our configs, I use the latest beta version of Adguard.
Could you please try it instead of release?

Download link:
https://download.adguard.com/d/2/adguardInstallerBeta.exe

jamesx · Feb 23, 2015

Just installed the beta version (6223) from your link.

No change, still randomly appearing delays and occasional errors. As soon as i switch Adguard to proxy mode, everything works smoothly.

Here is something else that might be interesting:

- Enabled "Automatically filter browser traffic"
- Added SQLYog.exe to the Adguard browser list
- Set "Don't filter" on the SQLYog entry

-> Does not fix the problem

- Set "Enable filtering" on the SQLYog entry

-> Does fix the problem

Pretty weird that when I use automatic mode and explicitly tell it to filter SQLYog suddenly the problem disappears.

There is something strange going on with the injected driver. Why does it even mess with MySQL connections when the program is not even on the browser list and even weirder why does it suddenly work when those connections are filtered...?

avatar · Feb 23, 2015

jamesx said:
Pretty weird that when I use automatic mode and explicitly tell it to filter SQLYog suddenly the problem disappears.

There is something strange going on with the injected driver. Why does it even mess with MySQL connections when the program is not even on the browser list and even weirder why does it suddenly work when those connections are filtered...?

That is really weird because if the process is not on the browsers list, Adguard ignores its traffic.

Could you please try restoring "Browsers" list to default and check it again?

jamesx · Feb 24, 2015

avatar said:
That is really weird because if the process is not on the browsers list, Adguard ignores its traffic.

Somehow it is exactly the other way round. But i can't tell if enabling filtering MySQL connections does cause Adguard to actually ignore it or pass it through its pipelines.

avatar said:
Could you please try restoring "Browsers" list to default and check it again?

Did that, sadly doesn't help.

vasily_bagirov · Feb 26, 2015

Very unusual case. Could you please be so helpful to send us debug logs? We have a manual how to do it:
https://www.dropbox.com/s/c4wyy2dg4plf0bd/protocolfilters_manual.txt?dl=0

If you are going for it, you should do it on the latest beta. It can be downloaded at http://download.adguard.com/d/2/adguardInstallerBeta.exe and will be available later today.

vasily_bagirov · Mar 1, 2015

@jamesx, I am terribly sorry. I gave you a manual but totally forgot to give the required files. They can be found here: https://www.dropbox.com/sh/om31d7hsj0rryzp/AADR-jrghEEvmkt1VhD3kN1Ua?dl=0

jamesx · Mar 2, 2015

No problem, I am looking at your post just now for the first time.

Well, i followed the debug guide and got everything running.

The problem now is, running these debug files i can't reproduce my issue anymore. (Delayed or aborting MySQL connections) Still the issue is present with a regular Adguard installation.

But i found something that could be a clue:

Most of the times the connection is close to instant (running the debug files) but occasionally there is a short but noticeable delay. When this delay happens, this is what shows up on the log files:

So it looks like somehow Adguard and Trendmicro Officescan are interfering with each other. Sadly i cannot disabled Officescan due to restrictions, but i had it running all the time and switching Adguard to proxy mode made the problem go away.

Code:

// Good MySQL connection
Mon Mar 02 12:42:12 2015: Proxy::tcpReceive() id=65489 len=78
Mon Mar 02 12:42:12 2015: Contents:
J
Mon Mar 02 12:42:12 2015: ProxySession::tcp_packet() id=65489 dd=0 pd=0 len=78
Mon Mar 02 12:42:12 2015: ProxySession::postData() id=65489 pd=0 len=78
Mon Mar 02 12:42:12 2015: ProxySession::postData() nf_tcpPostReceive id=65489 len=78
Mon Mar 02 12:42:12 2015: Proxy::tcpCanReceive() id=65489
Mon Mar 02 12:42:12 2015: ProxySession::postData() id=65489 pd=0 len=-1
Mon Mar 02 12:42:12 2015: ProxySession::postData() resume connection
Mon Mar 02 12:42:12 2015: ProxySession::postData() m_receivePosted == 0
Mon Mar 02 12:42:12 2015: Proxy::tcpCanReceive() id=65489
Mon Mar 02 12:42:12 2015: ProxySession::postData() id=65489 pd=0 len=-1
Mon Mar 02 12:42:12 2015: ProxySession::postData() resume connection
Mon Mar 02 12:42:12 2015: ProxySession::postData() m_receivePosted == 0
Mon Mar 02 12:42:12 2015: Proxy::tcpClosed() id=65489
Mon Mar 02 12:42:13 2015: Proxy::tcpConnected() id=65490
Mon Mar 02 12:42:13 2015: tcpConnected id=65490 flag=2 pid=9608 direction=out local=10.0.xxx.xxx:62868 remote=10.6.xxx.xxx:3306
        Process: D:\Tools\MySQL\bin\mysql.exe

// Bad MySQL connection (short delay)
Mon Mar 02 12:42:13 2015: Proxy::tcpReceive() id=65490 len=78
Mon Mar 02 12:42:13 2015: Contents:
J
Mon Mar 02 12:42:13 2015: ProxySession::tcp_packet() id=65490 dd=0 pd=0 len=78
Mon Mar 02 12:42:14 2015: ProxySession::postData() id=65490 pd=0 len=78
Mon Mar 02 12:42:14 2015: ProxySession::postData() nf_tcpPostReceive id=65490 len=78
Mon Mar 02 12:42:14 2015: Proxy::tcpConnected() id=65491
Mon Mar 02 12:42:14 2015: tcpConnected id=65491 flag=2 pid=644 direction=out local=10.0.xxx.xxx:62869 remote=10.0.xxx.xxx:80
        Process: C:\Program Files (x86)\Trend Micro\OfficeScan Client\NTRTScan.exe

Mon Mar 02 12:42:14 2015: Proxy::tcpCanReceive() id=65490
Mon Mar 02 12:42:14 2015: ProxySession::postData() id=65490 pd=0 len=-1
Mon Mar 02 12:42:14 2015: ProxySession::postData() resume connection
Mon Mar 02 12:42:14 2015: ProxySession::postData() m_receivePosted == 0
Mon Mar 02 12:42:14 2015: Proxy::tcpConnected() id=65492
Mon Mar 02 12:42:14 2015: tcpConnected id=65492 flag=2 pid=644 direction=out local=10.0.xxx.xxx:62870 remote=10.0.xxx.xxx:80
        Process: C:\Program Files (x86)\Trend Micro\OfficeScan Client\NTRTScan.exe

Mon Mar 02 12:42:14 2015: Proxy::tcpSend() id=65492 len=227
Mon Mar 02 12:42:14 2015: Contents:
GET /tmcss/?LCRC=9C4E654146B6CBFA4E9DFE0CD913B3B85A0753D5E20A5BA903B68F53C506AD69 HTTP/1.1
User-Agent: OSCE;10.6;5495;5c48cd67-9990-49f4-8315-b9d42b77a92b;a474a507-6eb8-46f2-ad0d-b5faa97560ff
Host: 10.0.xxx.xxx
Accept: */*


Mon Mar 02 12:42:14 2015: ProxySession::tcp_packet() id=65492 dd=0 pd=1 len=227
Mon Mar 02 12:42:14 2015: ProxySession::postData() id=65492 pd=1 len=227
Mon Mar 02 12:42:14 2015: ProxySession::postData() nf_tcpPostSend id=65492 len=227
Mon Mar 02 12:42:14 2015: ProxySession::postData() nBytes == 0
Mon Mar 02 12:42:14 2015: Proxy::tcpClosed() id=65490
Mon Mar 02 12:42:14 2015: Proxy::tcpCanSend() id=65492
Mon Mar 02 12:42:14 2015: ProxySession::postData() id=65492 pd=1 len=-1
Mon Mar 02 12:42:14 2015: ProxySession::postData() resume connection
Mon Mar 02 12:42:14 2015: ProxySession::postData() nBytes == 0
Mon Mar 02 12:42:14 2015: Proxy::tcpCanSend() id=65492
Mon Mar 02 12:42:14 2015: ProxySession::postData() id=65492 pd=1 len=-1
Mon Mar 02 12:42:14 2015: ProxySession::postData() resume connection
Mon Mar 02 12:42:14 2015: ProxySession::postData() nBytes == 0
Mon Mar 02 12:42:14 2015: Proxy::tcpClosed() id=65492

Full logs in priv msg.

***EDIT

I did some further testing and it turns out Trendmicro Officescan is not the cause of the issue. I managed to unload it completely (both the realtime scan and the proxy service) and the MySQL issue with Adguard persists.
If i apply the debug files the problem is going away, so i fear the debug logs might be useless. I hope you can read more out of them.
(I did the additional testing with 5.10.2002.6237)

avatar · Mar 3, 2015

That dropbox folder contains two things: debug kernel drivers (drivers.bin) and debug user mode management libs (ProtocolFilters.dll, nfapi.dll).

Could you please check them separately?
Just want to narrow it down to either driver or management lib.

Also to test it you'll need to install new beta version (use the same link as above).
We've updated drivers in the latest beta.

jamesx · Mar 4, 2015

Running 5.10.2004.6244 beta installation - problem still exists. It actually feels like the problem got worse with this beta version, there are a lot more aborted connections.

Replacing kernel drivers (drivers.bin) with files from dropbox - problem still exists.

Replacing management libs (ProtocolFilters.dll, nfapi.dll) with the files from dropbox - problem gone.

Tried repeatedly, Officescan was disabled during the whole test.

vasily_bagirov · Mar 5, 2015

jamesx said:
Running 5.10.2004.6244 beta installation - problem still exists. It actually feels like the problem got worse with this beta version, there are a lot more aborted connections.

Replacing kernel drivers (drivers.bin) with files from dropbox - problem still exists.

Replacing management libs (ProtocolFilters.dll, nfapi.dll) with the files from dropbox - problem gone.

Tried repeatedly, Officescan was disabled during the whole test.

Thanks for letting us know, we are working on it.

avatar · Mar 6, 2015

This problem should be fixed in the latest beta (5.10.2005).

Could you please check it?

jamesx · Mar 9, 2015

It looks like it is fixed.

Great job!

Best regards

AdGuard causing MySQL connections to fail

jamesx

New Member

vasily_bagirov

Administrator

jamesx

New Member

avatar

Administrator

jamesx

New Member

avatar

Administrator

jamesx

New Member

avatar

Administrator

jamesx

New Member

vasily_bagirov

Administrator

vasily_bagirov

Administrator

jamesx

New Member

avatar

Administrator

jamesx

New Member

vasily_bagirov

Administrator

avatar

Administrator

jamesx

New Member