mysql client strace de login lento

Question

Estou tendo um problema com conexões / logins lentos para um servidor mysql carregado, mesmo quando conectado através do arquivo de soquete unix (CentOS 6.3). As consultas estão sendo concluídas rapidamente - (0.00 sec) neste caso -, mas o login leva alguns segundos, neste caso:

real    0m3.128s
user    0m0.010s
sys     0m0.011s

O mysqld está rodando com skip-name-resolve e thread_cache_size , de modo que nenhum novo tópico está sendo criado durante este problema. É um problema baseado em carga , ou seja, os logins são muito rápidos quando o servidor está ocioso. O servidor está lidando com cerca de 60 conexões e 300 consultas por segundo em hardware potente, por isso é bem subutilizado.

Aqui está a seção de uma faixa onde ela está parada, notada com as linhas vazias. Estou assumindo que a paralisação em read( significa que está aguardando uma resposta do servidor:

$ 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, "031
395354 | unauthenticated user | connecting host    | NULL    | Connect | NULL | login                             | NULL             |
real    0m3.128s
user    0m0.010s
sys     0m0.011s
$ 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, "031
395354 | unauthenticated user | connecting host    | NULL    | Connect | NULL | login                             | NULL             |
%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%", 16) = 0
setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "031%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%", 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%pre%%pre%%pre%\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%pre%%pre%52%pre%%pre%%pre%%pre%!%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%"..., 84) = 84
%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%", 16) = 0
setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "031%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%", 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%pre%%pre%%pre%\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%pre%%pre%52%pre%%pre%%pre%%pre%!%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%"..., 84) = 84

Por que vale a pena, esse mysqld é um nó da API na frente do NDB (MySQL Cluster), mas tenho a sensação de que não tem nada com o NDB, já que as consultas em tabelas NDB também estão retornando muito rapidamente.

ATUALIZAÇÃO

configurar nosso aplicativo php para usar conexões persistentes ( p:<hostname> com mysqli) resolveu o problema completamente, mas ainda estou surpreso com a baixa taxa de conexão que se tornou um problema, comparado ao mysqld normal e ao Percona XtraDB Cluster.

para responder à pergunta do @ HTTP500, não vemos checking permissions state, mas vemos alguns deles em um determinado momento:

%pre%