Recebendo erros do BADREQ 400 no HaProxy?

4

Eu tenho recebido um número considerável de entradas BADREQ no meu log HAProxy (10+ por minuto).

Exemplo:

Oct 1 19:46:00 LB haproxy[19022]: 69.171.251.8:57356 [01/Oct/2018:19:46:00.903] sitename sitename/ -1/-1/-1/-1/5 400 187 - - PRNN 19/19/0/0/5 0/0 ""

Quase todos parecem vir do rastreador do Facebook.

O rastreador parece estar copiando conteúdo muito bem na maior parte do tempo. No entanto, um pequeno número dessas solicitações está resultando em erros de BADREQ.

Como sugerido em outro lugar, usei socat para ver o último erro executando o seguinte comando:

sudo echo "show errors" | sudo socat unix-connect:/var/run/haproxy.stat stdio

Isso me deu a seguinte saída:

  invalid request
  backend mysite (#2), server <NONE> (#-1), event #127
  src 69.171.251.1:61042, session #9717, session flags 0x00000080
  HTTP msg state 26, msg flags 0x00000000, tx flags 0x00000000
  HTTP chunk len 0 bytes, HTTP body len 0 bytes
  buffer flags 0x00808002, out 0 bytes, total 517 bytes
  pending 517 bytes, wrapping at 32776, error at position 0:

  00000  \x16\x03\x01\x02\x00\x01\x00\x01\xFC\x03\x03 B\x9B\xF8\xAE\xFB=\xD7dN
  00021+ \x8D\xAD\xCCP\x99\x9C\xEEow#w\n
  00033  \xB5\x99\x16g@\x1F{\x9A5H\x00\x00\xAA\xC00\xC0,\xC0(\xC0$\xC0\x14\xC0
  00057+ \n
  00058  \x00\xA5\x00\xA3\x00\xA1\x00\x9F\x00k\x00j\x00i\x00h\x009\x008\x007
  00080+ \x006\xCC\xA9\xCC\xA8\xCC\x14\xCC\x13\xCC\xAA\xCC\x15\x00\x88\x00\x87
  00098+ \x00\x86\x00\x85\xC02\xC0.\xC0*\xC0&\xC0\x0F\xC0\x05\x00\x9D\x00=\x005
  00120+ \x00\x84\xC0/\xC0+\xC0'\xC0#\xC0\x13\xC0\t\x00\xA4\x00\xA2\x00\xA0\x00
  00141+ \x9E\x00g\x00@\x00?\x00>\x003\x002\x001\x000\x00\x9A\x00\x99\x00\x98
  00164+ \x00\x97\x00E\x00D\x00C\x00B\xC01\xC0-\xC0)\xC0%\xC0\x0E\xC0\x04\x00
  00187+ \x9C\x00<\x00/\x00\x96\x00A\xC0\x12\xC0\x08\x00\x16\x00\x13\x00\x10
  00206+ \x00\r\xC0\r\xC0\x03\x00\n
  00214  \x00\xFF\x01\x00\x01)\x00\x00\x00\x14\x00\x12\x00\x00\x0Ffb.mysite.c
  00242+ om\x00\x0B\x00\x04\x03\x00\x01\x02\x00\n
  00254  \x00\x1C\x00\x1A\x00\x17\x00\x19\x00\x1C\x00\e\x00\x18\x00\x1A\x00\x16
  00272+ \x00\x0E\x00\r\x00\x0B\x00\x0C\x00\t\x00\n
  00284  \x00\r\x00 \x00\x1E\x06\x01\x06\x02\x06\x03\x05\x01\x05\x02\x05\x03
  00302+ \x04\x01\x04\x02\x04\x03\x03\x01\x03\x02\x03\x03\x02\x01\x02\x02\x02
  00319+ \x033t\x00\x00\x00\x10\x00\x0B\x00\t\x08http/1.1\x00\x15\x00\xAE\x00
  00344+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00361+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00378+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00395+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00412+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00429+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00446+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00463+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00480+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00497+ \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
  00514+ \x00\x00\x00

Eu serei honesto, não tenho ideia de como entender o que foi dito acima

Atualização: Eu consegui capturar o tráfego na porta 80 usando o tcpdump. Eu baixei o arquivo de captura e o abri com o WinShark.

Eu peguei alguns pedidos vindos do Facebook IP 31.13.127.5:

10622   15.837038   31.13.127.5 MYSERVERIP TCP  66  47658 → 80 [ACK] Seq=1 Ack=1 Win=61440 Len=0 TSval=1921577847 TSecr=59275252

10701   15.848790   31.13.127.5 MYSERVERIP TCP  583 47658 → 80 [PSH, ACK] Seq=1 Ack=1 Win=61440 Len=517 TSval=1921577859 TSecr=59275252

10702   15.848846   MYSERVERIP  31.13.127.5 HTTP    253 HTTP/1.0 400 Bad request  (text/html)

10914   15.927603   31.13.127.5 MYSERVERIP  TCP 66  47658 → 80 [FIN, ACK] Seq=518 Ack=189 Win=63488 Len=0 TSval=1921577937 TSecr=59275274

10915   15.927611   MYSERVERIP  31.13.127.5 TCP 66  80 → 47658 [ACK] Seq=189 Ack=519 Win=30080 Len=0 TSval=59275294 TSecr=1921577937

12044   17.419319   31.13.127.5 MYSERVERIP  TCP 74  53712 → 80 [SYN] Seq=0 Win=61320 Len=0 MSS=1460 SACK_PERM=1 TSval=1921579431 TSecr=0 WS=2048

12045   17.419337   MYSERVERIP  31.13.127.5 TCP 74  80 → 53712 [SYN, ACK] Seq=0 Ack=1 Win=28960 Len=0 MSS=1460 SACK_PERM=1 TSval=59275667 TSecr=1921579431 WS=128

12125   17.493182   31.13.127.5 MYSERVERIP  TCP 66  53712 → 80 [ACK] Seq=1 Ack=1 Win=61440 Len=0 TSval=1921579505 TSecr=59275667

12126   17.501269   31.13.127.5 MYSERVERIP  TCP 583 53712 → 80 [PSH, ACK] Seq=1 Ack=1 Win=61440 Len=517 TSval=1921579513 TSecr=59275667

12127   17.501387   MYSERVERIP  31.13.127.5 HTTP    253 HTTP/1.0 400 Bad request  (text/html)

12179   17.576974   31.13.127.5 MYSERVERIP  TCP 66  53712 → 80 [FIN, ACK] Seq=518 Ack=189 Win=63488 Len=0 TSval=1921579589 TSecr=59275687
    
por Wayne 01.10.2018 / 21:53

1 resposta

3

O que você vê nesse log é uma mensagem de TLS Client Hello.

Essa é a mensagem inicial enviada pelo cliente para iniciar a negociação, conseqüentemente, não há nada criptografado nessa mensagem. Você notará que há dois campos nessa mensagem que contém texto. Esses são os próximos campos do protocolo SNI (indicação do nome do servidor) e ALPN (negociação do protocolo da camada de aplicação). O resto da mensagem é de dados binários e, portanto, não é tão fácil de ler.

Naquele estágio inicial do TLS, o protocolo da camada de aplicação ainda não foi negociado e as chaves de sessão não foram estabelecidas. O cliente nem recebeu um certificado que possa validar. Isso significa que não há como o cliente ter enviado qualquer solicitação HTTP ainda e, sem solicitação HTTP, não há nada para enviar um código de status em resposta.

A entrada de log certamente parece que o HAProxy acha que está respondendo a uma solicitação HTTP, mesmo que nenhuma tenha sido enviada.

A partir disso, parece que o que está acontecendo aqui é que o servidor está falando HTTP e o cliente está falando HTTPS. A mensagem TLS Client Hello está, portanto, sendo mal interpretada como uma solicitação HTTP e rejeitada como inválida.

Seria útil capturar o tráfego de modo que ele possa ser inspecionado para descobrir o que realmente está sendo enviado pela rede. Se estou certo sobre o que precede, você deve ver um cliente TLS Hello que pode ser decodificado usando o Wireshark (ou similar) e uma resposta HTTP não criptografada com o código de erro 400.

O que também será interessante sobre a captura de pacotes será o número da porta.

Uma maneira de ver o que aconteceu foi se um usuário inseriu uma URL com protocolo e número de porta, como https://example.com:80/ , e o Facebook está tentando recuperar essa URL repetidamente (pois ela continua falhando).

Eu mesmo tentei colocar um URL malformado no facebook e, com certeza, o facebook enviou uma mensagem do Client Hello para a porta 80. Meu servidor da web (Apache) respondeu com um código de status 400 como esperado.

Sua captura de pacotes confirma que o tráfego no seu caso também está acontecendo na porta 80. Então, presumivelmente, alguém deu ao facebook um URL https apontando para o seu site e substituindo o número de porta correto por 80.

Seu servidor está respondendo corretamente com um código 400 e o Facebook percebe que a busca do URL falhou. Não há nada para consertar. Seu servidor está funcionando conforme o esperado e o único problema foi um erro do usuário ao inserir o URL no facebook.

É possível descobrir um pouco mais sobre a URL defeituosa fazendo com que o seu servidor detecte automaticamente o protocolo para suportar HTTP e HTTPS na mesma porta. No entanto, eu não recomendaria esses hacks, e não sei se algum software de servidor da web oferece suporte a ele.

    
por 28.10.2018 / 20:18

Tags