7

We have a hard time debugging 400 errors on our website. We have a lot of errors like this:

10.0.0.1 - - [08/Oct/2018:14:28:07 +0200] 
"GET /les-news/palmares/detail/article/la-lettre-de-motivation-ideale-pour-une-demande-de-stage-5224/ 
HTTP/1.1" 400 131844 
"https://www.google.com/" 
"Mozilla/5.0 (Linux; Android 7.0; TECNO K7 Build/NRD90M) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.91 Mobile Safari/537.36"

A user reported the problem by email and it was fixed by resetting it's cookies in his browser for other resetting cookies was not enough (but we can't be sure it was correctly done).

The platform is quite complicated and handled by a F5 load balancer, depending on the path the request to forwarded to different servers.

What I'd like at first is being able to reproduce the error because when accessing the URL we don't have any and everything works fine.

We noticed that most of error comes from Android/Chrome: about 85% of all 400 errors.

Here is a full log: 

timestamp   October 8th 2018, 16:26:52.000
version     1
 _id        BmQSVGYB5vF-Dw_g1gVi
 _index     f5_access-2018.10.08
 _score     - 
t _type     doc
t agent     Mozilla/5.0 (Linux; Android 8.1.0; MI 8 Build/OPM1.171019.026) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.91 Mobile Safari/537.36
client_ip   10.0.0.1
client_port     41,068
facility    local2
host        mydomain.fr
httpversion     1
id      2,503,307,391
length      0
logsource   mydomain.network.local
message     virtual=/Common/mydomain.fr_HTTP client_ip=10.0.0.1 client_port=41068 lb_server=10.153.161.12:80 host=mydomain.fr request_port=80 username= request="GET / HTTP/1.1" server_status=400 content_length=0 resp_time=23 user_agent="Mozilla/5.0 (Linux; Android 8.1.0; MI 8 Build/OPM1.171019.026) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.91 Mobile Safari/537.36" referer=http://mydomain.fr/article/100-millions-d-euros-sciences-po-lance-la-plus-grande-levee-de-fonds-de-son-histoire_095255b4-caef-11e8-896c-7d05c73a49da/ ID=2503307391 timestamp=2018-10-08T16:26:52+0200 pool=/Common/POOL_ETUDIANT_v2_nocache
pool        POOL_MYDOMAIN_v2_nocache
program     f5_access
referer     http://mydomain.fr/article/100-millions-d-euros-sciences-po-lance-la-plus-grande-levee-de-fonds-de-son-histoire_095255b4-caef-11e8-896c-7d05c73a49da/
request     /
request_port    80
server_ip   10.0.0.1
server_port     80
severity    Informational
status      400
stdstatus   4xx
stdvirtual  mydomain_fr_HTTP
tags        f5_access
time        23
timestamp   October 8th 2018, 16:26:52.000
type        f5_access
verb        GET
virtual     mydomain.fr_HTTP
COil
  • 207
  • 3
  • 12

1 Answers1

6

This is most likely caused by the client, not by the server (well, indirectly it can be). If it's not just a malformed url (one that is blocked by 400 before being able to trigger 404), in 99% of cases this is caused by

  • corrupted cookies (can for example be caused by extensions)
  • blocked cookies
  • too many cookies (some browsers block huge amounts of cookies)
  • client trying a deceptive request (I assume unintentionally)

If you want to test for the blocked cookie assumption, block cookies on your browser and see if you get a 400 error, the rest is a bit trickier, see: https://airbrake.io/blog/http-errors/400-bad-request

Since you already said that it got fixed with refreshing the cookies I would assume that it's cookie related.

Edit:

I have another angle: The request was over http (unencrypted) and includes a referrer with the GET request that includes the string "username". This actually makes users who visits the site with that referrer in their header identifiable, more so, the request can be viewed by a man in the middle in clear text.

Since Google has started kind of a war against unencrypted http traffic I could assume that Chrome causes some problems. This is just an assumption though, I cannot confirm this or back it up. But it's worth a try since you should encrypt your traffic anywas.

Do you have https set up on your server and if so, can you try to reproduce the same error when using https?

Broco
  • 1,919
  • 12
  • 21
  • Tested with refusing cookies and it still works. Accept that the "cookie bar" shows on every page. We noticed that most of error comes from Android / Chrome. Thanks for the article. – COil Oct 08 '18 at 13:39
  • Thinking about it, you said you have a load balancer, do you share status information between the servers? Are the times set correctly? E.g. if Server 1 issues a cookie for a client and the next time the client connects to Server 2 but tries to make a request with the Server 1 cookie, do you make sure it works? This could be a potential source of the error. Also do different firewall rules apply for you when you test it? Try to reproduce the clients environment as close as possible. – Broco Oct 08 '18 at 13:46
  • Yes I'll try, not easy. I have added a full F5 log. – COil Oct 08 '18 at 14:49
  • I edited my answer, do you have encryption on your server and if so, can you reproduce when using https instead? – Broco Oct 08 '18 at 15:16
  • No https for now, we are planning to switch soon. – COil Oct 08 '18 at 15:22
  • I think it's a pretty good bet that the error will disappear then. It's about time, especially for such a big site ;) Btw, I tried and got sent over a 100 cookies, that's pretty excessive + I cannot set cookie preferences before I get bombarded with them. – Broco Oct 08 '18 at 15:31
  • This was indeed due to https. Now that we have switched to https theses 410 errors are gone, thanks for the help. :) – COil Feb 15 '19 at 10:16