Squid HTTPS Tunneling usando CONNECT muito lento

11

Eu uso o squid na minha rede para armazenar em cache o conteúdo. Eu inicio o chrome com uma opção de linha de comando que diz para ele usar o proxy.

Na maioria das vezes, isso funciona muito bem, pois o squid armazena uma grande quantidade de conteúdo e, com um número limitado de usuários, ele funciona bem.

quando visito um site que é HTTPS usando o chrome, a primeira página é carregada muito lentamente. A barra de status no chrome diz "Aguardando o túnel do proxy ...". O Chrome usa o verbo CONNECT para passar pelo proxy e estabelecer HTTPS com o servidor. As páginas subseqüentes são rápidas porque o Chrome mantém a conexão aberta.

Eu verifiquei meus logs do squid3. Aqui estão algumas das entradas CONNECT. A segunda coluna é o tempo de resposta em milissegundos

1416064285.231   2926 192.168.12.10 TCP_MISS/200 0 CONNECT www.google.com:443 - DIRECT/74.125.136.105 -
1416064327.076  49702 192.168.12.10 TCP_MISS/200 1373585 CONNECT r2---sn-q4f7sn7l.googlevideo.com:443 - DIRECT/173.194.141.152 -
1416064345.018  63250 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064372.020  63038 192.168.12.10 TCP_MISS/200 1809 CONNECT www.facebook.com:443 - DIRECT/31.13.91.2 -
1416064393.040  64218 192.168.12.10 TCP_MISS/200 25346 CONNECT clients4.google.com:443 - DIRECT/173.194.32.196 -
1416064408.040  63021 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064408.040  62515 192.168.12.10 TCP_MISS/200 619 CONNECT ssl.gstatic.com:443 - DIRECT/173.194.32.207 -
1416064427.019  90301 192.168.12.10 TCP_MISS/200 2663948 CONNECT r2---sn-q4f7sn7l.googlevideo.com:443 - DIRECT/173.194.141.152 -
1416064429.019  63395 192.168.12.10 TCP_MISS/200 1339 CONNECT clients6.google.com:443 - DIRECT/173.194.32.195 -
1416064439.015  63382 192.168.12.10 TCP_MISS/200 764 CONNECT talkgadget.google.com:443 - DIRECT/173.194.32.199 -
1416064446.896 170270 192.168.12.10 TCP_MISS/200 2352814 CONNECT r20---sn-q4f7dm7z.googlevideo.com:443 - DIRECT/208.117.252.121 -
1416064471.010  62969 192.168.12.10 TCP_MISS/200 516 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064524.010  63389 192.168.12.10 TCP_MISS/200 764 CONNECT talkgadget.google.com:443 - DIRECT/173.194.32.195 -
1416064534.014  63003 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064542.010  63387 192.168.12.10 TCP_MISS/200 2114 CONNECT www.facebook.com:443 - DIRECT/31.13.91.2 -
1416064553.010  63376 192.168.12.10 TCP_MISS/200 470 CONNECT clients4.google.com:443 - DIRECT/173.194.32.194 -
1416064561.010  63379 192.168.12.10 TCP_MISS/200 1807 CONNECT mail.google.com:443 - DIRECT/173.194.32.213 -
1416064597.019  63003 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064600.126      0 192.168.12.10 TCP_DENIED/403 3630 CONNECT www.google-analytics.com:443 - NONE/- text/html
1416064610.122  10959 192.168.12.10 TCP_MISS/200 626 CONNECT avatars0.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.129  10968 192.168.12.10 TCP_MISS/200 576 CONNECT avatars1.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.130  10968 192.168.12.10 TCP_MISS/200 628 CONNECT avatars1.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.130  10967 192.168.12.10 TCP_MISS/200 576 CONNECT avatars1.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.133  10972 192.168.12.10 TCP_MISS/200 576 CONNECT avatars1.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.133  10970 192.168.12.10 TCP_MISS/200 627 CONNECT avatars0.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.135  10972 192.168.12.10 TCP_MISS/200 576 CONNECT avatars3.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.135  10972 192.168.12.10 TCP_MISS/200 628 CONNECT avatars2.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.260  11098 192.168.12.10 TCP_MISS/200 574 CONNECT avatars3.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064610.316  11155 192.168.12.10 TCP_MISS/200 1063 CONNECT avatars3.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064611.722  13327 192.168.12.10 TCP_MISS/200 17113 CONNECT github.com:443 - DIRECT/192.30.252.128 -
1416064619.130  19005 192.168.12.10 TCP_MISS/200 141 CONNECT avatars3.githubusercontent.com:443 - DIRECT/185.31.17.133 -
1416064639.016  95397 192.168.12.10 TCP_MISS/200 1037 CONNECT talkgadget.google.com:443 - DIRECT/173.194.32.194 -
1416064643.210   4739 192.168.12.10 TCP_MISS/200 4085 CONNECT dgafology.com:443 - DIRECT/198.74.52.100 -
1416064662.010  64990 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -
1416064665.219  65086 192.168.12.10 TCP_MISS/200 3851 CONNECT collector.githubapp.com:443 - DIRECT/54.236.179.219 -
1416064685.276   4003 192.168.12.10 TCP_MISS/200 3956 CONNECT qa.sockets.stackexchange.com:443 - DIRECT/198.252.206.25 -
1416064689.142   3750 192.168.12.10 TCP_MISS/200 357 CONNECT qa.sockets.stackexchange.com:443 - DIRECT/198.252.206.25 -
1416064709.014  78381 192.168.12.10 TCP_MISS/200 779 CONNECT clients6.google.com:443 - DIRECT/173.194.32.193 -
1416064721.010  63396 192.168.12.10 TCP_MISS/200 764 CONNECT talkgadget.google.com:443 - DIRECT/173.194.32.193 -
1416064725.013  63001 192.168.12.10 TCP_MISS/200 545 CONNECT mtalk.google.com:5228 - DIRECT/74.125.136.188 -

Algumas das conexões demoram mais de 60000 milissegundos!

Aqui estão alguns GETs para comparação

1416064691.281     68 192.168.12.10 TCP_MISS/200 412 GET http://serverfault.com/questions/ticks? - DIRECT/198.252.206.16 text/plain
1416064693.492     70 192.168.12.10 TCP_MISS/200 309 GET http://serverfault.com/search/titles? - DIRECT/198.252.206.16 application/json
1416064693.548    126 192.168.12.10 TCP_MISS/200 739 GET http://serverfault.com/content/img/progress-dots.gif - DIRECT/198.252.206.16 image/gif

O desempenho geral das lulas é excelente! Mas para CONNECT, é muito lento.

Eu descobri que você pode usar echoe ncsolicitar um túnel na linha de comando.

Eu fiz duas conexões consecutivas usando essa técnica

ericu@ericu-desktop:~$ echo -e -n 'CONNECT russiatoday.com:443\r\n\r\n' | nc 192.168.12.95 3127
HTTP/1.0 200 Connection established

ericu@ericu-desktop:~$ echo -e -n 'CONNECT russiatoday.com:443\r\n\r\n' | nc 192.168.12.95 3127
HTTP/1.0 200 Connection established

Nos logs,

1416065033.065   3079 192.168.12.10 TCP_MISS/200 0 CONNECT russiatoday.com:443 - DIRECT/62.213.85.4 -
1416065034.090    208 192.168.12.10 TCP_MISS/200 0 CONNECT russiatoday.com:443 - DIRECT/62.213.85.4 -

A primeira conexão levou 3079 milissegundos, mas a segunda apenas 208. Parece que o Squid nem sempre é lento.

Mais tarde, fiz a mesma coisa novamente, mas costumava tcpdumpcapturar o tráfego do squidservidor.

1416070989.180    732 192.168.12.10 TCP_MISS/200 0 CONNECT russiatoday.com:443 - DIRECT/62.213.85.4 -

Como você pode ver, a latência relatada é de 732ms.

Aqui está a saída da captura tcpdump dos 3 primeiros pacotes, SYNda minha caixa, SYN ACKdo controle remoto e ACK da minha caixa. Entendo que este é o aperto de mão de três vias necessário para estabelecer a conexão

11:03:08.973995 IP 192.168.12.95.34778 > 62.213.85.4.443: Flags [S], seq 1280719736, win 14600, options [mss 1460,sackOK,TS val 605181173 ecr 0,nop,wscale 7], length 0
11:03:09.180753 IP 62.213.85.4.443 > 192.168.12.95.34778: Flags [S.], seq 614920595, ack 1280719737, win 14480, options [mss 1460,sackOK,TS val 1284340103 ecr 605181173,nop,wscale 7], length 0
11:03:09.180781 IP 192.168.12.95.34778 > 62.213.85.4.443: Flags [.], ack 1, win 115, options [nop,nop,TS val 605181225 ecr 1284340103], length 0

O tempo decorrido é de 206,8 ms nessa troca. Portanto, neste exemplo, squidtem 526 ms de latência, se minha análise estiver correta. Um extra de ~ 500 ms de latência é enorme.

Mas minha análise pode ter falhas, eu acho, porque o "tempo de resposta" de uma CONNECTlula no meio mede o tempo total em que o túnel foi mantido aberto.

Editei minha logformatdiretiva para squidadicionar o tempo de resolução do DNS em milissegundos.

1416072432.918 580 776 192.168.12.10 TCP_MISS/200 0 CONNECT russiatoday.com:443 - DIRECT/62.213.85.4 -
1416072446.823 - 185 192.168.12.10 TCP_MISS/200 0 CONNECT russiatoday.com:443 - DIRECT/62.213.85.4 -

A segunda coluna é o tempo de pesquisa do DNS, a terceira é o "tempo de resposta", o que pode não significar muito CONNECT. A coluna aparece como -porque squidpossui cache DNS interno. Isso significa que o squid usou seu cache DNS interno para a próxima conexão. Isso explica que a exibição da primeira página é lenta e as subsequentes, relativamente rápidas. Isso também explica os ~ 500 ms extras de latência. Estou usando o bind9 em execução no encaminhamento de host local para pesquisar o DNS no ipv4. Como estou recebendo ~ 500ms de latência para uma simples pesquisa de DNS?

Executando nslookupusando 8.8.8.8 diretamente e ignorando meu servidor local:

ericu@katz:~$ time nslookup russiatoday.com 8.8.8.8
Server:     8.8.8.8
Address:    8.8.8.8#53

Non-authoritative answer:
Name:   russiatoday.com
Address: 62.213.85.4


real    0m0.056s
user    0m0.004s
sys 0m0.008s

Isso mostra 56 ms de latência para toda a pesquisa. O ping desse servidor fornece uma latência de cerca de 50 ms, então isso faz sentido.

Então, algo sobre squide bind9não concorda um com o outro?

https squid Eric Urban
fonte
Você está executando algum firewall entre o proxy e o alcance da rede pública ou entre o equipamento de desktop e o proxy?
Xavier Lucas
Sim, estou usando outra máquina que iptablesfunciona como um firewall NAT + para minha conexão com a Internet.
Eric Urban
Verifique se suas regras usam os estados netfilter (NEW, ESTABELECIDO) para permitir o tráfego e não apenas os pares ip: port. Um pouco de tcpdump para ver o que está demorando definitivamente ajudaria (por exemplo, verifique as solicitações de DNS).
Xavier Lucas
como isso seria diferente do que apenas ter uma regra iptables -A chain_name -j ACCEPT. Quero dizer, eu poderia adicioná-lo, mas não vejo por que isso importaria.
Eric Urban
1
É definitivamente mais rápido verificar o estado de uma conexão existente do que testar várias regras para cada pacote. Na minha experiência, vi uma perda dramática de desempenho sem essa configuração. Melhor maneira de analisar seu problema: tcpdump.
Xavier Lucas

Respostas:

11

Eu sei que é uma pergunta antiga, mas eu tive o mesmo problema e resolvi usando isso no squid.conf

dns_v4_first em

Saudações

Juliano Piassa
fonte
Incrível, muito obrigado! Eu estava culpando o Chrome o tempo todo que estava tendo esse problema irritante. Deveria ter pensado nisso, pois tenho um problema com a rede IPv6 na minha vm.
piit79
1

Postar isso como eu acho que será útil para qualquer pessoa que esteja executando o squid com uma caixa pfSense. Obrigado a Juliano pela resposta! A mesma configuração pode ser encontrada em (na caixa do pfSense) Serviços> Squid Proxy Server> Geral como Resolve DNS IPv4 First. Abaixo está uma captura de tela.

Configurações de proxy do squid do pfSense

darshanags
fonte
-1

Eu tive que definir "connect_timeout 2.0" porque estava tentando primeiro a resolução de DNS do IPv6 e depois passou para o ipv4 após um tempo limite padrão de 60 segundos.

HawtDogFlvrWtr
fonte