Tunnel Squid HTTPS utilisant CONNECT très lent

11

J'utilise squid sur mon réseau pour mettre en cache le contenu. Je lance Chrome avec un commutateur de ligne de commande qui lui dit d'utiliser le proxy.

Pour la plupart, cela fonctionne très bien car Squid met en cache une grande quantité de contenu et avec un nombre limité d'utilisateurs, il fonctionne bien.

lorsque je visite un site Web HTTPS utilisant du chrome, la première page se charge très lentement. La barre d'état sur Chrome indique "En attente du tunnel proxy ...". Chrome utilise le verbe CONNECT pour tunneler le proxy et établir HTTPS avec le serveur. Les pages suivantes sont rapides car Chrome maintient la connexion ouverte.

J'ai vérifié mes journaux squid3. Voici quelques entrées CONNECT. La deuxième colonne est le temps de réponse en millisecondes

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 -

Certaines connexions prennent plus de 60000 millisecondes!

Voici quelques GET pour comparaison

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

La performance globale du calmar est excellente! Mais pour CONNECT, c'est très lent.

J'ai découvert que vous pouvez utiliser echoet ncdemander un tunnel à partir de la ligne de commande.

J'ai fait deux connexions dos à dos en utilisant cette technique

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

Dans les journaux,

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 -

La première connexion a pris 3079 millisecondes, mais la seconde seulement 208. Il semble donc que Squid ne soit pas toujours lent.

Plus tard, j'ai refait la même chose mais utilisé tcpdumppour capturer le trafic du squidserveur.

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

Comme vous pouvez le voir, la latence signalée est de 732 ms.

Voici la sortie de la capture tcpdump des 3 premiers paquets, SYNde ma boîte, SYN ACKde la télécommande et ACK de ma boîte. Ma compréhension est que c'est la poignée de main à 3 voies nécessaire pour établir la connexion

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

Le temps écoulé est de 206,8 ms dans cet échange. Donc dans cet exemple squida 526 ms de latence si mon analyse est correcte. Une latence supplémentaire de ~ 500 ms est énorme.

Mais mon analyse peut être erronée je pense parce que le "temps de réponse" pour un CONNECTcalmar mesure juste le temps total pendant lequel le tunnel a été maintenu ouvert.

J'ai modifié ma logformatdirective pour squidajouter le temps de résolution DNS en millisecondes.

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 -

La deuxième colonne est le temps de recherche DNS, la 3ème est le "temps de réponse" qui peut ne pas signifier grand-chose CONNECT. Les spectacles de colonne comme -car squida la mise en cache DNS interne. Cela signifie que Squid a utilisé son cache DNS interne pour la prochaine connexion. Cela explique que la première vue de page soit lente et que les suivantes soient relativement rapides. Cela explique également les ~ 500 ms de latence supplémentaires. J'utilise bind9 en cours d'exécution sur le transfert d'hôte local vers googles DNS sur ipv4. Comment obtenir environ 500 ms de latence pour une simple recherche DNS?

Exécuter nslookupdirectement avec 8.8.8.8 et contourner mon serveur 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

Cela montre 56 ms de latence pour la recherche entière. Pinging ce serveur donne une latence d'environ 50 ms, donc cela a du sens.

Donc, quelque chose squidet vous bind9n'êtes pas d'accord?

https squid Eric Urban
la source
Exécutez-vous un pare-feu quelque part entre le proxy et la plage Internet publique ou entre la plate-forme de bureau et le proxy?
Xavier Lucas
Oui, j'utilise une autre machine qui sert iptablesde pare-feu NAT + pour ma connexion Internet.
Eric Urban
Assurez-vous que vos règles utilisent des états de netfilter (NOUVEAU, ÉTABLI) pour autoriser le trafic et pas seulement les couples ip: port. Un peu de tcpdump pour voir ce qui prend du temps serait certainement utile (par exemple, vérifiez les requêtes DNS).
Xavier Lucas
en quoi cela serait-il différent d'avoir simplement une règle iptables -A chain_name -j ACCEPT. Je veux dire bien sûr, je pourrais l'ajouter, mais je ne vois pas pourquoi cela importerait.
Eric Urban
1
Il est nettement plus rapide de vérifier l'état d'une connexion existante que de tester un tas de règles pour chaque paquet. Dans mon expérience, j'ai vu une perte de performances spectaculaire sans une telle configuration. Meilleure façon d'analyser votre problème: tcpdump.
Xavier Lucas

Réponses:

11

Je sais que c'est une vieille question mais j'ai eu le même problème et résolu en utilisant ceci dans squid.conf

dns_v4_first sur

Cordialement

Juliano Piassa
la source
Génial, merci beaucoup! Je blâmais Chrome tout le temps que je rencontrais ce problème ennuyeux. J'aurais dû y penser car j'ai un problème avec le réseau IPv6 sur mon vm.
piit79
1

Publier ceci car je pense que cela sera utile à toute personne utilisant Squid avec une boîte pfSense. Merci à Juliano pour leur réponse! Le même paramètre peut être trouvé sous (dans votre boîte pfSense) Services> Squid Proxy Server> General as Resolve DNS IPv4 First. Voici une capture d'écran.

Paramètres du proxy Squid pfSense

darshanags
la source
-1

J'ai dû définir "connect_timeout 2.0" car il essayait d'abord la résolution DNS ipv6, puis passait à ipv4 après un délai d'expiration par défaut de 60 secondes.

HawtDogFlvrWtr
la source