As pesquisas de DNS eventualmente tornam-se consistentemente lentas no processo de longa duração de ruby

3

Eu tenho um aplicativo Ruby em execução em um servidor Ubuntu, e esse aplicativo frequentemente precisa fazer solicitações HTTP para outros serviços. Alguns desses serviços estão em um domínio interno, alguns são acessíveis pelo DNS público. Eu tenho um agente Consul colocado em meu aplicativo Ruby, cujo trabalho é resolver consultas DNS para componentes internos.

Eventually, the Ruby app slows down and it comes down to DNS queries to external domains taking 5+ seconds to resolve. I need help understanding why the behaviour described below may be happening.

To clarify, my goal is to understand the following behaviour, I already have several fixes/workaround I'm considering.

Eu isolei o problema para o seguinte:

Exemplo reprodutível mínimo:

/etc/resolv.conf

nameserver 127.0.0.1
nameserver 8.8.8.8

Substitui o Consul pelo seguinte resolvedor sempre-SERVFAIL DNS que escuta na porta 53:

#!/usr/bin/env ruby

require "rubydns"

RubyDNS.run_server(listen: [[:udp, "0.0.0.0", 53], [:tcp, "0.0.0.0", 53]]) do
  otherwise do |transaction|
    transaction.fail!(:ServFail)
  end
end

Eu coloquei o código acima em um arquivo ( /var/vcap/data/tmp/dns.rb ) e então o execute:

ruby /var/vcap/data/tmp/dns.rb

Não é super importante, mas o acima está sendo executado com o sistema ruby, que é o 1.9. Então eu corro o seguinte comando (novamente, provavelmente não é importante, mas isso usa uma versão diferente do ruby):

var/vcap/packages/ruby-2.1.6/bin/ruby -r'net/protocol' -e \
'1.step do |i|; t=Time.now; TCPSocket.open("SOME.REAL.DOMAIN",80).close; p Time.now-t; end'

O acima é uma mentira ligeira , houve um pouco mais de formatação em torno do que foi impresso, mas para ajustá-lo neste post sem precisar de deslocar para a esquerda / direita, simplifiquei um pouco.

Comportamento observado:

The behaviour I see is that for a while, each iteration of the loop takes on the order of 10ms, but eventually it starts taking on the order of 5000ms.

Duração do comportamento lento

Em um ponto, eu modifiquei /etc/resolv.conf para ter options timeout:4 e reexecutei esse experimento, e cada iteração começaria a demorar cerca de 4000ms. Então, os 5000ms parecem estar vindo do tempo limite padrão de 5s do resolvconf.

Número de iterações antes do abrandamento

Pode levar de algumas centenas a dezenas de milhares de iterações para o comportamento aparecer, mas sempre acontece. Se você parar o loop e executar o comando novamente, a mesma coisa, centenas ou milhares de iterações de ~ 10ms e, em seguida, consistentemente ~ iterações de 5000ms. Freqüentemente, há uma ou duas iterações entre elas que levam uma quantidade intermediária de tempo, 2000-4000ms.

Loop de rubi de vida longa vs. repetidos comandos únicos de rubi

Acredito que isso tenha algo a ver com processos ruby de longa duração, porque se eu executar um loop bash e dentro de cada iteração do loop bash ele executar algum ruby, não vejo essa desaceleração eventual. Por exemplo. o seguinte não exibe o mau comportamento:

while true; do time /var/vcap/packages/ruby-VERSION/bin/ruby -r'net/protocol' -e \
'TCPSocket.open("SOME.REAL.DOMAIN, 80).close'; done

Somente servidor de nomes localhost vs. dois servidores de nomes

Além disso, isso tem algo a ver com ter vários servidores de nomes. Se eu editar /etc/resolv.conf para ter apenas o servidor de nomes 127.0.0.1 , e adicionar um rescue nil à iteração ruby (para evitar que o script exploda na primeira iteração), parece que vai demorar muito tempo sem obter lento.

Informações de depuração:

Eu fiz um strace do loop acima em um caso em que havia 7873 iterações rápidas (~ 10ms), depois uma iteração que levou 3013ms, depois todas as iterações subsequentes demoraram pouco mais de 5000ms. A saída de strace de todas as iterações rápidas parece basicamente a mesma que a outra e a saída de strace de todas as iterações de ~ 5000ms é basicamente a mesma que a outra. Por isso incluirei aqui a saída da iteração mais rápida última , a iteração de 3013ms e a iteração primeiro ~ 5000ms. É claro que na saída strace tudo é contíguo, mas estou dividindo em partes separadas para facilitar a visualização.

última iteração rápida: 9ms

stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendmmsg(7, {{{msg_name(0)=NULL, msg_iov(1)=[{"A
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendmmsg(7, {{{msg_name(0)=NULL, msg_iov(1)=[{"u>
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendto(7, "\r7
nameserver 127.0.0.1
nameserver 8.8.8.8
#!/usr/bin/env ruby

require "rubydns"

RubyDNS.run_server(listen: [[:udp, "0.0.0.0", 53], [:tcp, "0.0.0.0", 53]]) do
  otherwise do |transaction|
    transaction.fail!(:ServFail)
  end
end
ruby /var/vcap/data/tmp/dns.rb
var/vcap/packages/ruby-2.1.6/bin/ruby -r'net/protocol' -e \
'1.step do |i|; t=Time.now; TCPSocket.open("SOME.REAL.DOMAIN",80).close; p Time.now-t; end'
while true; do time /var/vcap/packages/ruby-VERSION/bin/ruby -r'net/protocol' -e \
'TCPSocket.open("SOME.REAL.DOMAIN, 80).close'; done
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendmmsg(7, {{{msg_name(0)=NULL, msg_iov(1)=[{"A
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendmmsg(7, {{{msg_name(0)=NULL, msg_iov(1)=[{"u>
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
open("/etc/hosts", O_RDONLY|O_CLOEXEC)  = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=305, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4e70992000
read(7, "127.0.0.1 localhost af0a3ebe-91a"..., 4096) = 305
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0x7f4e70992000, 4096)            = 0
stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=85, ...}) = 0
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 7
connect(7, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=7, events=POLLOUT}], 1, 0)    = 1 ([{fd=7, revents=POLLOUT}])
sendto(7, "\r7%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45
poll([{fd=7, events=POLLIN}], 1, 5000)  = 1 ([{fd=7, revents=POLLIN}])
ioctl(7, FIONREAD, [45])                = 0
recvfrom(7, "\r71%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45
poll([{fd=7, events=POLLIN}], 1, 4995)  = 0 (Timeout)
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8
connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0
poll([{fd=8, events=POLLOUT}], 1, 0)    = 1 ([{fd=8, revents=POLLOUT}])
sendto(8, "\r7%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45
poll([{fd=8, events=POLLIN}], 1, 3000)  = 1 ([{fd=8, revents=POLLIN}])
ioctl(8, FIONREAD, [61])                = 0
recvfrom(8, "\r710%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61
poll([{fd=8, events=POLLOUT}], 1, 2996) = 1 ([{fd=8, revents=POLLOUT}])
sendto(8, "}7%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45
poll([{fd=8, events=POLLIN}], 1, 2996)  = 1 ([{fd=8, revents=POLLIN}])
ioctl(8, FIONREAD, [109])               = 0
recvfrom(8, "}710%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109
close(7)                                = 0
close(8)                                = 0
socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7
fcntl(7, F_GETFD)                       = 0x1 (flags FD_CLOEXEC)
fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0
fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
close(7)                                = 0
write(1, "7875: 5014ms", 12)            = 12
write(1, "\n", 1)                       = 1
%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=7, events=POLLIN}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "u>1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 poll([{fd=7, events=POLLIN}], 1, 4999) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "e?1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendmmsg(8, {{{msg_name(0)=NULL, msg_iov(1)=[{"u>%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "e?10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 poll([{fd=8, events=POLLIN}], 1, 2997) = 0 (Timeout) poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "u>%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [61]) = 0 recvfrom(8, "u>10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61 poll([{fd=8, events=POLLOUT}], 1, 2997) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 2997) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "e?10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 close(7) = 0 close(8) = 0 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7 fcntl(7, F_GETFD) = 0x1 (flags FD_CLOEXEC) fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 close(7) = 0 write(1, "7874: 3013ms", 12) = 12 write(1, "\n", 1) = 1
%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"YH%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=7, events=POLLIN}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "A1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 poll([{fd=7, events=POLLIN}], 1, 4999) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "YH1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendmmsg(8, {{{msg_name(0)=NULL, msg_iov(1)=[{"A%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"YH%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [61]) = 0 recvfrom(8, "A10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61 poll([{fd=8, events=POLLIN}], 1, 2996) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "YH10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 close(7) = 0 close(8) = 0 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7 fcntl(7, F_GETFD) = 0x1 (flags FD_CLOEXEC) fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 close(7) = 0 write(1, "7873: 9ms", 9) = 9 write(1, "\n", 1) = 1
%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=7, events=POLLIN}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "\r71%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 poll([{fd=7, events=POLLIN}], 1, 4995) = 0 (Timeout) socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "\r7%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [61]) = 0 recvfrom(8, "\r710%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61 poll([{fd=8, events=POLLOUT}], 1, 2996) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "}7%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 2996) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "}710%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 close(7) = 0 close(8) = 0 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7 fcntl(7, F_GETFD) = 0x1 (flags FD_CLOEXEC) fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 close(7) = 0 write(1, "7875: 5014ms", 12) = 12 write(1, "\n", 1) = 1
%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=7, events=POLLIN}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "u>1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 poll([{fd=7, events=POLLIN}], 1, 4999) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "e?1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendmmsg(8, {{{msg_name(0)=NULL, msg_iov(1)=[{"u>%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "e?10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 poll([{fd=8, events=POLLIN}], 1, 2997) = 0 (Timeout) poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "u>%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [61]) = 0 recvfrom(8, "u>10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61 poll([{fd=8, events=POLLOUT}], 1, 2997) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "e?%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 2997) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "e?10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 close(7) = 0 close(8) = 0 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7 fcntl(7, F_GETFD) = 0x1 (flags FD_CLOEXEC) fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 close(7) = 0 write(1, "7874: 3013ms", 12) = 12 write(1, "\n", 1) = 1
%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"YH%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=7, events=POLLIN}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "A1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 poll([{fd=7, events=POLLIN}], 1, 4999) = 1 ([{fd=7, revents=POLLIN}]) ioctl(7, FIONREAD, [45]) = 0 recvfrom(7, "YH1%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, [16]) = 45 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendmmsg(8, {{{msg_name(0)=NULL, msg_iov(1)=[{"A%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 45}, {{msg_name(0)=NULL, msg_iov(1)=[{"YH%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 45}], msg_controllen=0, msg_flags=MSG_CONFIRM}, 45}}, 2, MSG_NOSIGNAL) = 2 poll([{fd=8, events=POLLIN}], 1, 3000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [61]) = 0 recvfrom(8, "A10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 61 poll([{fd=8, events=POLLIN}], 1, 2996) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [109]) = 0 recvfrom(8, "YH10%pre%%pre%%pre%%pre%%pre%%pre%uaauseastappfogq"..., 1987, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("8.8.8.8")}, [16]) = 109 close(7) = 0 close(8) = 0 socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 7 fcntl(7, F_GETFD) = 0x1 (flags FD_CLOEXEC) fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 connect(7, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("63.251.167.126")}, 16) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fstat(7, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 close(7) = 0 write(1, "7873: 9ms", 9) = 9 write(1, "\n", 1) = 1

iteração intermediária: 3013ms

%pre%

primeira iteração lenta: 5014ms

%pre%

Observações adicionais:

Algumas coisas estranhas no acima. Observe que a iteração ~ 3000ms expira o descritor de arquivo de pesquisa 8, que está sendo usado para falar com o servidor de nomes 8.8.8.8 , enquanto a iteração ~ 5000ms (e todas as iterações subseqüentes) expira o descritor de arquivo sondagem 7, que é para 127.0.0.1 nome do servidor. Observe também que todas as iterações rápidas e intermediárias usam sendmmsg para se comunicar através do soquete, mas todas as iterações de ~ 5000ms usam sendto .

    
por Amit Kumar Gupta 13.11.2015 / 06:41

2 respostas

1

Talvez eu tenha entendido o problema (espero). Eu acho que você pode consertar isso jogando com uma configuração personalizada de DNS Bind, usando uma zona "falsa" e zona de internet privadas juntas e corrigindo um TTL adequado para ter mais velocidade para o tempo de resposta usando o mecanismo de cache DNS. Espero que ajude! Atenciosamente.

    
por 13.11.2015 / 11:10
0

Basta configurar o bind no host local. Você terá que adicionar uma zona de encaminhamento para a zona .consul (porta 8600 por padrão), consulte: link

Certifique-se de que seu servidor tenha acesso à Internet (udp e tcp, porta 53 e icmp).

Então você pode remover com segurança a parte 8.8.8.8 em seu /etc/resolv.conf.

    
por 16.11.2015 / 16:47