I am experiencing an issue with slow connections/logins to a loaded mysql server, even when connecting via the unix socket file (CentOS 6.3). Queries are completing very quickly -- (0.00 sec)
in this case -- but the login takes up to several seconds, in this case:
real 0m3.128s
user 0m0.010s
sys 0m0.011s
mysqld is running with skip-name-resolve
and a thread_cache_size
such that no new threads are being created during this issue. It is a load-based problem, i.e. logins are very fast when the server is idle. The server is handling about 60 connections and 300 queries per second on powerful hardware, so it is well underutilized.
Here is the section of an strace where it stalls, noted with the empty lines. I am assuming the stall on read(
means it is waiting for a response from the server:
$ time strace mysql -e 'select 1'
[...]
read(3, "# /etc/services:\n# $Id: services"..., 4096) = 4096
read(3, "ervice\nfinger 79/tcp\nfi"..., 4096) = 4096
read(3, " 209/udp "..., 4096) = 4096
read(3, "a-cluster 694/tcp "..., 4096) = 4096
read(3, " 1494/tcp "..., 4096) = 4096
read(3, "603/udp #"..., 4096) = 4096
close(3) = 0
munmap(0x7f10609da000, 4096) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x3318c32920}, {SIG_DFL, [], 0}, 8) = 0
socket(PF_FILE, SOCK_STREAM, 0) = 3
fcntl(3, F_SETFL, O_RDONLY) = 0
fcntl(3, F_GETFL) = 0x2 (flags O_RDWR)
connect(3, {sa_family=AF_FILE, path="/var/run/mysqld/mysqld.sock"}, 110) = 0
setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
setsockopt(3, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
read(3,
"e\0\0\0\n5.5.29-ndb-7.2.10-cluster-g"..., 16384) = 105
open("/usr/lib/locale/locale-archive", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=99158576, ...}) = 0
mmap(NULL, 99158576, PROT_READ, MAP_PRIVATE, 4, 0) = 0x7f105216f000
close(4) = 0
stat("/usr/share/mysql/charsets/Index.xml", {st_mode=S_IFREG|0755, st_size=18312, ...}) = 0
brk(0x222b000) = 0x222b000
open("/usr/share/mysql/charsets/Index.xml", O_RDONLY) = 4
read(4, "<?xml version='1.0' encoding=\"ut"..., 18312) = 18312
close(4) = 0
futex(0x986300, FUTEX_WAKE_PRIVATE, 2147483647) = 0
write(3, "P\0\0\1\205\242\17\0\0\0\0\1!\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 84) = 84
For what it's worth, this mysqld is an API node in front of NDB (MySQL Cluster), but I have a feeling it has nothing to with NDB, since queries against NDB tables are also returning very quickly.
UPDATE
configuring our php application to use persistent connections (p:<hostname>
with mysqli) solved the problem completely, but I am still surprised at what a low connection rate this became an issue, compared to normal mysqld and Percona XtraDB Cluster.
to answer @HTTP500's question, we don't see checking permissions
state, but do see a few of these at any given time:
395354 | unauthenticated user | connecting host | NULL | Connect | NULL | login | NULL |