Lot of 400 errors in the Apache logs
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
Solution 1:
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?