Home / server / Questions / 496711
In Process
carillonator
Asked: 2013-04-06 16:09:52 +0800 CST

mysql client slow login strace

  • 772

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             |
mysql

0 Answers