Túnel de calamar HTTPS usando CONNECT muy lento

11

Uso squid en mi red para almacenar en caché el contenido. Lanzo Chrome con un interruptor de línea de comando que le dice que use el proxy.

En su mayor parte, esto funciona muy bien ya que el calamar almacena en caché una gran cantidad de contenido y con un número limitado de usuarios funciona bien.

Cuando visito un sitio web que es HTTPS con Chrome, la primera página se carga muy lentamente. La barra de estado en Chrome dice "Esperando el túnel proxy ...". Chrome usa el verbo CONNECT para hacer un túnel a través del proxy y establecer HTTPS con el servidor. Las páginas posteriores son rápidas porque Chrome mantiene la conexión abierta.

Revisé mis registros de squid3. Estas son algunas de las entradas de CONNECT. La segunda columna es el tiempo de respuesta en milisegundos.

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 -

¡Algunas de las conexiones toman más de 60000 milisegundos!

Aquí hay algunos GET para comparar

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

¡El rendimiento general del calamar es excelente! Pero para CONNECT es muy lento.

Descubrí que puedes usar echoy ncsolicitar un túnel desde la línea de comandos.

Hice dos conexiones consecutivas usando esta 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

En los troncos

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 primera conexión tomó 3079 milisegundos, pero la segunda solo 208. Entonces, parece que Squid no siempre es lento.

Más tarde, hice lo mismo otra vez, pero solía tcpdumpcapturar el tráfico del squidservidor.

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

Como puede ver, la latencia informada es de 732 ms.

Aquí está la salida de la captura de tcpdump de los primeros 3 paquetes, SYNdesde mi caja, SYN ACKdesde el control remoto y ACK desde mi caja. Entiendo que este es el apretón de manos de 3 vías necesario para establecer la conexión.

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

El tiempo transcurrido es 206.8 ms en ese intercambio. Entonces, en este ejemplo, squidtiene 526 ms de latencia si mi análisis es correcto. Un extra de ~ 500 ms de latencia es enorme.

Pero creo que mi análisis puede ser defectuoso porque el "tiempo de respuesta" para un CONNECTcalamar solo mide el tiempo total que el túnel estuvo abierto.

Edité mi logformatdirectiva para squidagregar el tiempo de resolución DNS en milisegundos.

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 segunda columna es el tiempo de búsqueda de DNS, la tercera es el "tiempo de respuesta" que puede no significar mucho CONNECT. La columna aparece como -porque squidtiene almacenamiento en caché de DNS interno. Esto significa que squid usó su caché DNS interno para la próxima conexión. Esto explica que la primera vista de la página sea lenta y que las posteriores sean relativamente rápidas. Esto también explica los ~ 500 ms adicionales de latencia. Estoy usando bind9 ejecutándose en el reenvío de host local a Google DNS en ipv4. ¿Cómo obtengo ~ 500 ms de latencia para una simple búsqueda de DNS?

Ejecutar nslookupusando 8.8.8.8 directamente y sin pasar por mi 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

Esto muestra 56 ms de latencia para toda la búsqueda. Hacer ping a ese servidor proporciona una latencia de alrededor de 50 ms, por lo que tiene sentido.

Entonces, ¿algo sobre squidy bind9no estar de acuerdo el uno con el otro?

https squid Eric Urban
fuente
¿Está ejecutando algún firewall en algún lugar entre el proxy y el rango de red pública o entre la plataforma de escritorio y el proxy?
Xavier Lucas
Sí, estoy usando otra máquina que iptablesactúa como un firewall NAT + para mi conexión a Internet.
Eric Urban
Asegúrese de que sus reglas usen estados de filtro de red (NUEVO, ESTABLECIDO) para permitir el tráfico y no solo ip: pares de puertos. Un poco de tcpdump para ver qué está tomando tiempo definitivamente ayudaría (por ejemplo, verifique las solicitudes de DNS).
Xavier Lucas
¿Cómo sería eso diferente que solo tener una regla iptables -A chain_name -j ACCEPT? Quiero decir, seguro, podría agregarlo, pero no veo por qué importaría.
Eric Urban
1
Definitivamente es más rápido verificar el estado de una conexión existente que probar un montón de reglas para cada paquete. En mi experiencia, vi una dramática pérdida de rendimiento sin dicha configuración. La mejor manera de analizar su problema: tcpdump.
Xavier Lucas

Respuestas:

11

Sé que es una pregunta antigua , pero tuve el mismo problema y resolví usar esto en squid.conf

dns_v4_first on

Saludos

Juliano Piassa
fuente
Impresionante, muchas gracias! Estaba culpando a Chrome todo el tiempo que estaba teniendo este molesto problema. Debería haber pensado en esto ya que tengo un problema con la red IPv6 en mi vm.
piit79
1

Publicar esto ya que creo que será útil para cualquier persona que ejecute squid con un cuadro pfSense. Gracias a Juliano por su respuesta! La misma configuración se puede encontrar en (en su cuadro pfSense) Servicios> Servidor Squid Proxy> General como Resolve DNS IPv4 First. Debajo hay una captura de pantalla.

Configuración de proxy de calamar pfSense

darshanags
fuente
-1

Tuve que configurar "connect_timeout 2.0" porque intentaba primero la resolución de ipv6 dns y luego cambiaba a ipv4 después de un tiempo de espera predeterminado de 60 segundos.

HawtDogFlvrWtr
fuente