MySQL5 > Aborted connection > Got an error reading communication packets

Yes, we're on a dedicated server and we average 2.8 hits per second 24 hours a day, seven days a week.  We're currently using mysql_pconnect() and it seems to speed up page load times quite a bit but I don't have any hard numbers to share.  I'll say that it speed it up noticeably so there was no need to benchmark.

There doesn't seem to be much headache on this issue unless I'm missing something? I'm a bit embarrassed to say I didn't even know it was happening until I turned on extended logging in MySQL.  

Should I be concerned?  Should I fix it?

http://www.t1shopper.com/technology.shtml

Hmm... good question.  Any evidence that data was lost?  Absent that, I wouldn't be too concerned.

Quarter million hits per day - great traffic!

I'm not sure if data was lost or how to debug at that level.  I can say that I'm getting an awful lot of this issue though.  My error log has grown to 1.1 MB in just a few days logging all these aborted connections.

Any hints on how I can debug?

P.S.  There's one weird log entry, "Aborted connection 13951 to db: 'unconnected'"  It's wierd because I don't have a table or schema called 'unconnected.'  Thoughts?

080826 20:12:14 [Warning] Aborted connection 13861 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:12:22 [Warning] Aborted connection 13868 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:13:36 [Warning] Aborted connection 13841 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:14:20 [Warning] Aborted connection 13874 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:14:22 [Warning] Aborted connection 13873 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:16:04 [Warning] Aborted connection 13882 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:16:59 [Warning] Aborted connection 13876 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:17:23 [Warning] Aborted connection 13877 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:18:53 [Warning] Aborted connection 13885 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:20:27 [Warning] Aborted connection 13891 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:20:51 [Warning] Aborted connection 13871 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:21:44 [Warning] Aborted connection 13900 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:22:20 [Warning] Aborted connection 13821 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:22:26 [Warning] Aborted connection 13878 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:22:54 [Warning] Aborted connection 13905 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:23:00 [Warning] Aborted connection 13899 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:23:49 [Warning] Aborted connection 13897 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:24:51 [Warning] Aborted connection 13908 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:26:19 [Warning] Aborted connection 13913 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:26:20 [Warning] Aborted connection 13914 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:28:31 [Warning] Aborted connection 13912 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:28:31 [Warning] Aborted connection 13917 to db: 'unconnected' user: 'localhostro' host: 'localhost' (Got an error reading communication packets)
080826 20:28:38 [Warning] Aborted connection 13901 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:29:44 [Warning] Aborted connection 13922 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:31:16 [Warning] Aborted connection 13923 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:31:58 [Warning] Aborted connection 13925 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:31:59 [Warning] Aborted connection 13926 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:32:58 [Warning] Aborted connection 13921 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:37:29 [Warning] Aborted connection 13933 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:41:14 [Warning] Aborted connection 13951 to db: 'unconnected' user: 'localhostro' host: 'localhost' (Got an error reading communication packets)
080826 20:41:41 [Warning] Aborted connection 13924 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:42:00 [Warning] Aborted connection 13945 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:42:09 [Warning] Aborted connection 13953 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:43:33 [Warning] Aborted connection 13959 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:43:52 [Warning] Aborted connection 13952 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080826 20:45:15 [Warning] Aborted connection 13963 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)

Select allOpen in new window

Have you seen this:

http://dev.mysql.com/doc/refman/5.0/en/communication-errors.html
http://dev.mysql.com/doc/refman/6.0/en/communication-errors.html

One jumps out: Client did not call mysql_close before exit.  That's the sort of thing I would forget!

Yes, I saw those.  I'm using mysql_pconnect() so calling mysql_close() will not close a persistent connection.  My wait_timeout is set for the default of 28800 (8 hours).  These "Aborted connections" could be the end of the 8-hour persistent connection?   Thoughts?

Maybe I should be using "interactive_timeout" so that persistent connections are not aborted unless there's really no activity on them if I'm reading that right?

http://dev.mysql.com/doc/refman/5.0/en/server-system-variables.html#option_mysqld_interactive_timeout

"These "Aborted connections" could be the end of the 8-hour persistent connection?   Thoughts?"

That's plausible, but far from certain in my mind.  However if you restarted things and got none of them until after 8 hours, it would be a strong symptom.

I have never used the interactive timeout.

It may be beside the point, but are there any visible symptoms besides the error log?

Good thinking on doing the restart.  I'm going to try that now and watch it for 8 hours.

Other than the logs, there's no pain I'm aware of.  But the connection that shows up in the log the most is a high use connection that's not connected to any revenue yet so it doesn't get watched a lot.  So maybe we are not getting responses from the database and I wouldn't know at this point.  I'll have to put some processes in to watch it.  Arrrrrggg..

Well, the "Aborted connections" are not the end of the 8-hour persistent connection because I started seeing them right MySQL was restarted per log entries below.  Arrrggg.

What is this error and how do I keep it from happening?!

080827 14:16:29  mysqld started
080827 14:16:30  InnoDB: Started; log sequence number 75 xxxxxxxxxx
080827 14:16:30 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.0.45-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
080827 14:17:59 [Warning] Aborted connection 9 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)
080827 14:18:37 [Warning] Aborted connection 14 to db: 'network_tools' user: 'network_tools' host: 'localhost' (Got an error reading communication packets)

Select allOpen in new window

I share your frustration.  It's a particularly obscure message, and a collection of searches is not turning up much.  This was one link suggestion: http://dev.mysql.com/doc/refman/5.0/en/making-trace-files.html

Gelu's commens here may be germaine: http://lists.mysql.com/mysql/106790

Michael McGlothlin here: http://forums.mysql.com/read.php?21,108326,123792#msg-123792

Also, http://www.mydatabasesupport.com/forums/mysql/174618-aborted-clients-got-error-reading-communication-packets.html

Hope this doesn't send us in circles... http://themattreid.com/wordpress/?p=15

Thanks - I just tried upping the max_allowed_packet from the default of 1M to 32M but that doesn't make things any better.  

Unfortunately it looks like I cannot make a trace file because Red Hat doesn't compile support for that into their release of MySQL er version info below.

Still at a bit of a loss.  Nothing seems to be fixing this.  The error occurs mostly when submitting the form at the following link: http://www.t1shopper.com/tools/port-scanner/

MySQL support is $600 USD a year.

shell> /usr/libexec/mysqld -V
/usr/libexec/mysqld  Ver 5.0.45-log for redhat-linux-gnu on x86_64 (Source distribution)

Select allOpen in new window

So I still have 106 Aborted_clients in about 30 minutes.

At least MySQL documentation is upbeat saying, "If these kinds of things happen, it might indicate that someone is trying to break into your server! "  http://dev.mysql.com/doc/refman/5.0/en/communication-errors.html

mysql> SHOW GLOBAL STATUS;
+-----------------------------------+-----------+
| Variable_name                     | Value     |
+-----------------------------------+-----------+
| Aborted_clients                   | 106       |
| Aborted_connects                  | 0         |

Select allOpen in new window

Please accept my apologies - my dog went down with a terrible spinal injury this afternoon.  Good luck going forward, but I have to sign off on this.  Hopefully I can be back in a couple of days.  ~Ray

Ray, I'm sorry to hear that and I hope everything heals up quickly and as pain free as possible.

BTW, my connection string looks like this:

$link = mysql_pconnect('localhost', 'network_tools', 'my_password', MYSQL_CLIENT_INTERACTIVE);

Well the dog is a little better but we have not had much sleep.  So what's the advantage of MYSQL_CLIENT_INTERACTIVE?

Well, I w as thinking maybe the connection  was timing out enven though it shouldn't.

So I thinkt maybe if I specified MYSQL_CLIENT_INTERACTIVE that would force PHP to use the MySQL settings under *interactive_timeout* instead of just the *wait_timeout* or whatever else it might do.  I though being more specific would be better...

Not sure it really gives me anything, I'm just groping in the dark now.  

Anyone?  Thoughts?

Hi,
I have experienced this when after closing the port, it is not made available again for a certain period of time (Default is 2 Mins I believe).
Try the following:
in the following key:
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip\Parameters
add a DWORD called 'MaxUserPort' and set it to 65535
This specifies the maximum number of ports MySQL can use.

also, add another DWORD called 'TcpTimedWaitDelay' and set it to 30
This is the time allowed before the port is freed up again.

Reboot the PC and try it again...

Hope this helps,

James

sorry, that should have been 65534

angelIII:Thanks, I would love to have an answer on this.  This question seems to have stumped everyone, including Red Hat support in Service Request 1853688 where they say, and I quote:

1) The issue is reproducible in the Lab.  Here are the quick steps.

a) Install Mysql.
b) Set the "wait_timeout" OR "interactive_timeout" to "30 Seconds" in my.cnf
c) Write a simple script and add "sleep" for "1" minute.
d) After running this script we do get similar errors as you pointed in the post 27-AUG-2008 18:48:04.

as "expert", I would check out this one:
http://www.php.net/set_time_limit

ie, the web page script timeout. eventually your web page times out, hence the script is aborted, including the db connection...

in short: the first-level problem would not be mysql, but the php page taking too long.
however, if the web page takes more than 30 seconds, eventually due to a mysql query taking too long, it's still a problem on the mysql db missing indexes for example, or the script just being written poorly (could also be poor db design).

please check it out.

angelIII: I was sure I had set max_execution_time to some large value but alas, it was indeed set to 30 seconds!!  What a geek. I've increased it to 360 seconds.  I'll monitor this for a few days and post back here.

That said, I learned something new from the PHP documentation.  It appears that the time it takes to do DB calls, exec(), system()  are not counted toward the max_execution_time.

"Note: The set_time_limit() function and the configuration directive max_execution_time  only affect the execution time of the script itself. Any time spent on activity that happens outside the execution of the script such as system calls using system(), stream operations, database queries, etc. is not included when determining the maximum time that the script has been running."

Nope, that didn't do it.  After changing the max_execution_time to 360 and rebooting the server I see that there are 32 Aborted_clients within 30 minutes of reboot.

Any other thoughts?

So I've got proof.  I wrote the below PHP script and then tailed the mysql.log.  You can see that the "Aborted connection" message in the log happened at 19:29:41 which was exactly the same time the script showed the problem.  The error happened 99 seconds after script start time.

---=== SCRIPT OUTPUT ===---
At 2008-25-11 19:28:02 the number of Aborted_clients=0
<snip>
At 2008-25-11 19:29:38 the number of Aborted_clients=0
At 2008-25-11 19:29:40 the number of Aborted_clients=0
At 2008-25-11 19:29:42 the number of Aborted_clients=2
At 2008-25-11 19:29:44 the number of Aborted_clients=2

---=== mysqld.log ===---
081125 19:29:41 [Warning] Aborted connection 13 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)

<?php
$link = mysql_pconnect('localhost', 'root', 'roots_password_here');
 
$time_end=time()+300; //Run loop for 5 minutes.
while (time()<$time_end) {
  $query = "SHOW STATUS WHERE Variable_name='Aborted_clients'";
  $result = mysql_query($query);
  $row = mysql_fetch_row($result);
  echo "At ".date('Y-d-m H:i:s')." the number of Aborted_clients=".$row[1]."<hr>";
  sleep(2); //Sleep 2 seconds after every query.
}
?>

Select allOpen in new window

angelIII: Well, the point of this thread was to try to get mysql_pconnect() working because we have a busy website and pconnect() is supposed to offer some performance advantages.

I guess we'll switch back to mysql_connect() since aborted connections just seem bad and I just don't have the time to benchmark to see what performance gains we're getting out of mysql_pconnect().