Edit report at http://bugs.php.net/bug.php?id=52948&edit=1
ID: 52948
User updated by: gilles dot rayrat at continuent dot com
Reported by: gilles dot rayrat at continuent dot com
Summary: Improper connection closing logic leads to TIME_WAIT
sockets on server
Status: Open
Type: Bug
Package: MySQLi related
Operating System: Any
PHP Version: 5.2.14
Block user comment: N
New Comment:
php:
No. Time Source Destination Protocol
Info
1 0.000000 192.168.50.129 192.168.50.128 TCP
57338 >
mysql [SYN] Seq=0 Win=5840 Len=0 MSS=1460 TSV=88257291 TSER=0 WS=5
2 0.000550 192.168.50.128 192.168.50.129 TCP
mysql >
57338 [SYN, ACK] Seq=0 Ack=1 Win=5792 Len=0 MSS=1460 TSV=170478509
TSER=88257291
WS=5
3 0.000574 192.168.50.129 192.168.50.128 TCP
57338 >
mysql [ACK] Seq=1 Ack=1 Win=5856 Len=0 TSV=88257291 TSER=170478509
4 0.001434 192.168.50.128 192.168.50.129 MySQL
Server
Greeting proto=10 version=5.1.26-rc-log
5 0.001960 192.168.50.129 192.168.50.128 TCP
57338 >
mysql [ACK] Seq=1 Ack=64 Win=5856 Len=0 TSV=88257292 TSER=170478510
6 0.005680 192.168.50.129 192.168.50.128 MySQL
Login
Request user=tungsten db=test
7 0.006010 192.168.50.128 192.168.50.129 TCP
mysql >
57338 [ACK] Seq=64 Ack=72 Win=5792 Len=0 TSV=170478511 TSER=88257293
8 0.006073 192.168.50.128 192.168.50.129 MySQL
Response OK
9 0.006383 192.168.50.129 192.168.50.128 MySQL
Request
Quit
10 0.006618 192.168.50.128 192.168.50.129 TCP
mysql >
57338 [FIN, ACK] Seq=75 Ack=77 Win=5792 Len=0 TSV=170478511
TSER=88257293
11 0.006672 192.168.50.129 192.168.50.128 TCP
57338 >
mysql [FIN, ACK] Seq=77 Ack=76 Win=5856 Len=0 TSV=88257293
TSER=170478511
12 0.007198 192.168.50.128 192.168.50.129 TCP
mysql >
57338 [ACK] Seq=76 Ack=78 Win=5792 Len=0 TSV=170478511 TSER=88257293
mysql CLI:
No. Time Source Destination Protocol
Info
1 0.000000 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [SYN] Seq=0 Win=5840 Len=0 MSS=1460 TSV=88268477 TSER=0 WS=5
2 0.000453 192.168.50.128 192.168.50.129 TCP
mysql >
57339 [SYN, ACK] Seq=0 Ack=1 Win=5792 Len=0 MSS=1460 TSV=170489695
TSER=88268477
WS=5
3 0.000671 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [ACK] Seq=1 Ack=1 Win=5856 Len=0 TSV=88268477 TSER=170489695
4 0.001337 192.168.50.128 192.168.50.129 MySQL
Server
Greeting proto=10 version=5.1.26-rc-log
5 0.001504 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [ACK] Seq=1 Ack=64 Win=5856 Len=0 TSV=88268477 TSER=170489695
6 0.001685 192.168.50.129 192.168.50.128 MySQL
Login
Request user=tungsten db=test
7 0.001872 192.168.50.128 192.168.50.129 TCP
mysql >
57339 [ACK] Seq=64 Ack=72 Win=5792 Len=0 TSV=170489695 TSER=88268477
8 0.001984 192.168.50.128 192.168.50.129 MySQL
Response OK
9 0.003621 192.168.50.129 192.168.50.128 MySQL
Request
Query
10 0.004348 192.168.50.128 192.168.50.129 MySQL
Response
11 0.004764 192.168.50.129 192.168.50.128 MySQL
Request
Query
12 0.005434 192.168.50.128 192.168.50.129 MySQL
Response
13 0.005698 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
14 0.005941 192.168.50.128 192.168.50.129 MySQL
Response
15 0.006104 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
16 0.006336 192.168.50.128 192.168.50.129 MySQL
Response
17 0.006438 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
18 0.006650 192.168.50.128 192.168.50.129 MySQL
Response
19 0.006760 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
20 0.006975 192.168.50.128 192.168.50.129 MySQL
Response
21 0.007077 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
22 0.007325 192.168.50.128 192.168.50.129 MySQL
Response
23 0.007884 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
24 0.008327 192.168.50.128 192.168.50.129 MySQL
Response
25 0.008498 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
26 0.008752 192.168.50.128 192.168.50.129 MySQL
Response
27 0.008859 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
28 0.009156 192.168.50.128 192.168.50.129 MySQL
Response
29 0.009269 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
30 0.009541 192.168.50.128 192.168.50.129 MySQL
Response
31 0.009662 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
32 0.009892 192.168.50.128 192.168.50.129 MySQL
Response
33 0.010019 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
34 0.010301 192.168.50.128 192.168.50.129 MySQL
Response
35 0.010411 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
36 0.010637 192.168.50.128 192.168.50.129 MySQL
Response
37 0.010762 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
38 0.011006 192.168.50.128 192.168.50.129 MySQL
Response
39 0.011109 192.168.50.129 192.168.50.128 MySQL
Request
Show Fields
40 0.011342 192.168.50.128 192.168.50.129 MySQL
Response
41 0.011470 192.168.50.129 192.168.50.128 MySQL
Request
Query
42 0.011854 192.168.50.128 192.168.50.129 MySQL
Response
43 0.051473 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [ACK] Seq=312 Ack=1521 Win=8000 Len=0 TSV=88268490 TSER=170489698
44 1.131630 192.168.50.129 192.168.50.128 MySQL
Request
Quit
45 1.131800 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [FIN, ACK] Seq=317 Ack=1521 Win=8000 Len=0 TSV=88268760
TSER=170489698
46 1.132174 192.168.50.128 192.168.50.129 TCP
mysql >
57339 [FIN, ACK] Seq=1521 Ack=318 Win=5792 Len=0 TSV=170489978
TSER=88268760
47 1.132274 192.168.50.129 192.168.50.128 TCP
57339 >
mysql [ACK] Seq=318 Ack=1522 Win=8000 Len=0 TSV=88268760 TSER=170489978
Previous Comments:
------------------------------------------------------------------------
[2010-09-30 08:45:50] gilles dot rayrat at continuent dot com
Thanks for your answer.
Yes, the webserver should get the time_wait connections, since you can
have several web servers but generally only one database server
Furthermore, other mysql client (perl, CLI) will properly let the
time_wait connection on the client side
After some more testing, it actually appears that the behavior is
somehow unpredictable (or I didn't get the logic). I sometimes got
time_wait on the client, sometimes
on the server - the following shows the case where it appears on the
server.
These tests are comparing regular mysql CLI client with a simple php
script.
Host u1 is the client (or webapp)
Host u2 is the mysql server
Mysql command line is:
mysql -hu2 -utungsten -psecret -P3306 test
Php script is:
<?php
# Simple script to demonstrate the TIME_WAIT issue
# Connects to the database, nothing more
$host = "u2"; # Host where the Tungsten Connector is running
$port = 3306; # Using the Tungsten Connector port
$username = "tungsten";
$password = "secret";
$dbname = "test";
echo "Connecting to $host $username $password $dbname $port\n";
# Make the connection
$connection = mysqli_connect($host, $username, $password, $dbname,
$port);
$connection->close();
?>
Command to check for time_wait:
netstat -nat| grep 3306| grep TIME_WAIT
Will attach both dumps taken with wireshark
------------------------------------------------------------------------
[2010-09-30 05:14:41] [email protected]
I'm sorry, I didn't get this. If I understand correctly, you would
prefer the web server to be in a TIME_WAIT, rather than the database
server, and for that it would have to send the first FIN packet.
But why would you prefer the web server to be in a TIME_WAIT state? The
front-end side typically needs to handle many more connections.
Additionally, it would be nice if you provided an example script and its
ouput (in this case, a tcpdump).
------------------------------------------------------------------------
[2010-09-29 08:36:08] gilles dot rayrat at continuent dot com
Description:
------------
Similarly to connector/j bug reported here:
http://bugs.mysql.com/bug.php?
id=56979, there is a problem with mysql disconnection logic where the
TCP
connection TIME_WAIT state is found on the server rather than on the
client. With
multiple clients and multiple connection, the MySQL server can run out
of file
descriptors quickly.
The disconnect method should first set EOF to its input, then send the
QUIT
command, then set its output to EOF, then close the socket
Note: I guess the same bug appears in MySQL-non-i as well
------------------------------------------------------------------------
--
Edit this bug report at http://bugs.php.net/bug.php?id=52948&edit=1
