Opened 3 years ago
Last modified 3 years ago
#54 new defect
502 Errors
Reported by: | chris | Owned by: | chris |
---|---|---|---|
Priority: | major | Milestone: | Maintenance |
Component: | crin2 | Version: | |
Keywords: | Cc: | peter | |
Estimated Number of Hours: | 0 | Add Hours to Ticket: | 0 |
Billable?: | yes | Total Hours: | 3.0 |
Description
Last night the wiki:NginxLogWatch script found a lot of 502 errors:
Dec 22 288 502, 0 503 and 0 504 errors from crin2.crin.org Dec 22 4283 502, 0 503 and 0 504 errors from crin2.crin.org
I'm not sure why yet.
Attachments (25)
Change History (33)
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
comment:1 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 1
- Total Hours set to 1
comment:2 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.25
- Total Hours changed from 1 to 1.25
So far so good:
/usr/local/bin/nginx-logwatch /var/log/nginx/crin.org.ssl_access.log | less Total 502 errors: 0 Total 503 errors: 119 Total 504 errors: 0
The 119 503's were caused by an IP address in Hanoi, requesting lots of pages between 22/Dec/2015:14:49:28 and 22/Dec/2015:14:49:35, so around 17 pages a second, and what is good is that there are no other IP addresses with errors, so the rate limiting prevented the IP address being abusive from causing a load spike which would have had a bad effect on other users.
comment:3 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.25
- Total Hours changed from 1.25 to 1.5
With the limit of one PHP page per IP address per second we have had the max number of PHP processes peaking to 9 and the recent 503's which were a result of this limit:
/usr/local/bin/nginx-logwatch /var/log/nginx/crin.org.ssl_access.log.1 | less Total 502 errors: 0 Total 503 errors: 95 Total 504 errors: 0
So in /etc/nginx/nginx.conf I have doubled the number of requests per second per IP to 2:
#limit_req_zone $binary_remote_addr zone=one:10m rate=1r/s; limit_req_zone $binary_remote_addr zone=one:10m rate=2r/s;
If it goes OK at this level it can go higher.
comment:4 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.1
- Total Hours changed from 1.5 to 1.6
There have been a few more 503's and not much in the way of load increases so upping the limit to 4 PHP pages per IP address per second in /etc/nginx/nginx.conf:
limit_req_zone $binary_remote_addr zone=one:10m rate=4r/s;
comment:5 Changed 3 years ago by chris
I also changed this in /etc/nginx/sites-available/crin.org:
#limit_req zone=one burst=10; limit_req zone=one burst=10;
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
comment:6 follow-up: ↓ 8 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.75
- Total Hours changed from 1.6 to 2.35
Over the last week there has been a large, saw-tooth shaped, increase in requests to the site in the early hours of the morning, see these graphs:
These have coincided with a increase in 502 and 503 errors, for example the Subject lines from the alert emails from last night for the HTTPS and HTTP logs:
75 502, 1 503 and 0 504 errors from crin2.crin.org 3701 502, 678 503 and 0 504 errors from crin2.crin.org
Looking at the errors from last night, this lists the IPs by numbers of requests:
nginx-logwatch /var/log/nginx/crin.org.access.log.1 | awk '{ print $1 }' | sort | uniq -c | sort -bgr -k 1 433 93.95.228.179 238 101.65.XX.XX ...
Looking at the top IPs, the top one was requesting 30 RSS feeds a second and using URL's from when the site was using ASP, for example:
93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss_info.asp?ID=27166 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any5&country=176 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /Law/rss.asp?scope=i&TypeID=1004&langlist=3&country=169 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?country=169&GM=1001 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /Law/rss.asp?scope=i&TypeID=1003&langlist=3&country=171 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /en/Law/rss.asp?scope=i&TypeID=1004&langlist=3&country=232 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?country=232&GM=1001 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any3&country=176 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any5&country=172 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss_info.asp?ID=26928 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /Law/rss.asp?scope=i&TypeID=1004&langlist=3&country=176 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?country=176&GM=1001 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /en/resources/rss.asp?categoryID=67&country=232 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=232 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any4&country=175 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /en/resources/rss_info.asp?ID=30664 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=67&country=177 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=177 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=67&country=175 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=175 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any4&country=172 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /en/resources/rss.asp?categoryID=67&country=173 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss_info.asp?ID=29383 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=173 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss_info.asp?ID=24703 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any3&country=170 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=67&country=168 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=168 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any5&country=169 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=67&country=166 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=9&country=166 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss_info.asp?ID=24376 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /resources/rss.asp?categoryID=Any5&country=170 HTTP/1.0" 503 212 "-" "-" 93.95.XX.XX - - [07/Jan/2016:03:05:23 +0000] "GET /en/resources/rss.asp?categoryID=Any5&country=168 HTTP/1.0" 503 212 "-" "-"
The fact that these requests are served 503's is good, if they were served 502's the load impact could result in other clients accessing the site at the same time also getting errors.
I have just realised that these requests are coming from Crin1! It much be some MediaWiki RSS script, this probably calls for another ticket...
The second most active IP address is a Chinese one, but this was at a different time from the peaks, a sample of the requests:
101.65.XX.XX - - [06/Jan/2016:13:58:44 +0000] "GET /library/custom-search-publications/?field_publications=470 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:44 +0000] "GET /en/general-measures/1-process-law-reform HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:44 +0000] "GET /library/custom-search-publications/?field_publications=468 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:44 +0000] "GET /en/general-measures/2-development-independent-human-rights-institutions-children HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:44 +0000] "GET /en/issue/child-participation HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:45 +0000] "GET /library/custom-search-publications/?field_publications=462 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:45 +0000] "GET /library/custom-search-publications/?field_publications=453 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:45 +0000] "GET /library/custom-search-publications/?field_publications=450 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:45 +0000] "GET /library/custom-search-publications/?field_publications=448 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/custom-search-publications/?field_publications=444 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/custom-search-publications/?field_publications=442 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/custom-search-publications/?field_publications=443 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/custom-search-publications/?field_publications=441 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /en/library/organisations/child-rights-international-network HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/custom-search-publications/?field_publications=1365 HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.XX.XX - - [06/Jan/2016:13:58:46 +0000] "GET /library/country HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" ... 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/marshall-islands HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/malta HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/mali HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/malaysia HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/madagascar HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /library/countries/macedonia-former-yugoslav-republic HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:00 +0000] "GET /en/library/countries/netherlands-antilles-netherlands HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:01 +0000] "GET /library/countries/macao-special-administrative-region-china HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:01 +0000] "GET /library/countries/liechtenstein HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:01 +0000] "GET /en/library/countries/nauru HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/liberia HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/latvia HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/korea-democratic-peoples-republic HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/kuwait HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/kyrgyzstan HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /library/countries/kiribati HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:02 +0000] "GET /en/library/countries/mongolia HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:03 +0000] "GET /library/countries/jamaica HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:03 +0000] "GET /library/countries/japan HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:03 +0000] "GET /library/countries/israel HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:03 +0000] "GET /library/countries/italy HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:03 +0000] "GET /library/countries/iraq HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/india HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/kenya HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/honduras HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/holy-see HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/hong-kong-special-administrative-region-china HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/hungary HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/haiti HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/guyana HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/guinea-bissau HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:04 +0000] "GET /library/countries/guinea HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/guatemala HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/greenland-denmark HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/guadeloupe-france HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/guam HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/ghana HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /library/countries/germany HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60" 101.65.47.46 - - [06/Jan/2016:13:59:05 +0000] "GET /en/library/countries/maldives HTTP/1.1" 503 212 "" "Opera/9.80 (Windows NT 5.1; U; en) Presto/2.10.229 Version/11.60"
These requests are not from a human, the fact that they result on 503 errors and don't take the site down for others is probably a good thing, if someone doesn't want to crawl the whole site they need to use rate limiting.
The next top IP address was getting 502's and ever request has a different User Agent string -- this appears to be a bot upto no good, for example:
192.3.XX.XX - - [06/Jan/2016:23:22:04 +0000] "GET /en/library/countries/tuvalu?qt-countr-tabs=4 HTTP/1.1" 502 574 "http://www.crin.org/en/library/countries/tuvalu?qt-countr-tabs=4" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36" 192.3.XX.XX - - [06/Jan/2016:23:22:04 +0000] "GET /custom-search?field_country=618&type=un_and_regional_documentation HTTP/1.1" 502 574 "http://www.crin.org/custom-search?field_country=618&type=un_and_regional_documentation" "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0)" 192.3.XX.XX - - [06/Jan/2016:23:22:05 +0000] "GET /en/library/legal-database/dojan-v-germany HTTP/1.1" 502 172 "http://www.crin.org/en/library/legal-database/dojan-v-germany" "Mozilla/5.0 (Windows NT 5.1; rv:33.0) Gecko/20100101 Firefox/33.0" 192.3.XX.XX - - [06/Jan/2016:23:22:05 +0000] "GET /docs/CRIN_Mechanisms_2011.pdf HTTP/1.1" 502 172 "http://www.crin.org/docs/CRIN_Mechanisms_2011.pdf" "Mozilla/5.0 (Windows NT 6.1; rv:31.0) Gecko/20100101 Firefox/31.0" 192.3.XX.XX - - [06/Jan/2016:23:23:02 +0000] "GET /en/library/countries/algeria?qt-countr-tabs=1 HTTP/1.1" 502 574 "http://www.crin.org/en/library/countries/algeria?qt-countr-tabs=1" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.71 Safari/537.36" 192.3.XX.XX - - [07/Jan/2016:02:50:54 +0000] "GET /es/node/41461 HTTP/1.1" 502 574 "http://www.crin.org/es/node/41461" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/37.0.2062.120 Chrome/37.0.2062.120 Safari/537.36" 192.3.XX.XX - - [07/Jan/2016:02:50:54 +0000] "GET /en/library/custom-search-organisations?search_api_language=current&promo=1&f[0]=field_themes%3A24&f[1]=field_themes%3A23 HTTP/1.1" 502 574 "http://www.crin.org/en/library/custom-search-organisations?search_api_language=current&promo=1&f[0]=field_themes%3A24&f[1]=field_themes%3A23" "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.122 Safari/537.36" 192.3.XX.XX - - [07/Jan/2016:02:50:55 +0000] "GET /en/library/custom-search-organisations?search_api_language=current&promo=1&f[0]=field_themes%3A18&f[1]=field_themes%3A24 HTTP/1.1" 502 574 "http://www.crin.org/en/library/custom-search-organisations?search_api_language=current&promo=1&f[0]=field_themes%3A18&f[1]=field_themes%3A24" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.122 Safari/537.36" 192.3.XX.XX - - [07/Jan/2016:02:50:55 +0000] "GET /en/library/organisations/child-wise HTTP/1.1" 502 574 "http://www.crin.org/en/library/organisations/child-wise" "Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.71 Safari/537.36"
I'm not sure if it is worth spending too much more time digging into these logs, even though I haven't found the cause of the large overnight loads-- I think I'd better spend time on the caching ticket, ticket:56 as I only have a day a month to work on the servers.
comment:7 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.25
- Total Hours changed from 2.35 to 2.6
Only 5 502 errors yesterday, all of these from MediaWiki requesting non-existant RSS feeds. One, typical, 503 error from BingBot, there are a few of these every day, I have no idea why URLs like this are requested:
157.55.39.223 - - [07/Jan/2016:10:16:22 +0000] "GET /docs/%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%82%C2%A0%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%C2%A2%C3%A2%E2%82%AC%C5%BE%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AE%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%82%C2%A6%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%82%C2%A6%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%ACPeru%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%82%C2%A0%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%C2%A2%C3%A2%E2%82%AC%C5%BE%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AE%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%82%C2%A6%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%A2%E2%82%AC%C2%A0%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%A2%E2%80%9E%C2%A2%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%9A%C3%82%C2%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%E2%80%9A%C3%82%C2%AC%C3%83%C6%92%C3%A2%E2%82%AC%C2%A6%C3%83%E2%80%9A%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%E2%80%A0%C3%A2%E2%82%AC%E2%84%A2%C3%83%C6%92%C3%82%C2%A2%C3%83%C2%A2%C3%A2%E2%82%AC%C5%A1%C3%82%C2%AC%C3%83%E2%80%A6%C3%82%C2%A1%C3%83%C6%92%C3%86%E2%80%99%C3%83%C2%A2%C3%A2%E2%80%9A%C2%AC%C3%85%C2%A1%C3%83%C6%92%C3%A2%E2%82%AC%C5%A1%C3%83%E2%80%9A%C3%82%C2%81_GIN_NGO_Report.doc HTTP/1.1" 502 172 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
Changed 3 years ago by chris
comment:8 in reply to: ↑ 6 Changed 3 years ago by chris
- Add Hours to Ticket changed from 0 to 0.4
- Total Hours changed from 2.6 to 3.0
Replying to chris:
Over the last week there has been a large, saw-tooth shaped, increase in requests to the site in the early hours of the morning
That pattern was on-going until a few days ago, when it stopped, these are some graphs from the last week:
And these are from the last month, showing the duration of the pattern:
I did look at the traffic during these periods, several times, and it appears to be traffic from bots, the User Agent string was different for each request, and there were huge numbers of GET and HEAD requests being made at the same time.
However I'm not sure that this was the sole cause of the saw tooth pattern -- last night there were 584 503 errors served by Crin2 and of these 292 were to one IP address (again lots of different User Agent strings) between 07:05:15 and 07:05:17 and another 292 of them were server to another IP address between 09:39:20 and 09:39:23.
I don't know what conclusion to draw from this apart from the one that the Nginx rate limiting of requests for PHP generated pages to 6 per seconds per remote IP address is working quite well at stopping abuse from bots -- no human is going to try open almost 300 tags in two seconds to read articles using multiple user agent strings...
Most days there are between one and five 502 errors caused by Bing bot requests like this:
Looking at the email alerts, one is for port 80 and one for port 443, saved the list of requests in files and counted them and the ones from a specific IP:
So this load spike was basically caused by a massive number of requests from one IP address starting at: 21/Dec/2015:23:44:31 and ending at 21/Dec/2015:23:45:05 for the first file and starting at 21/Dec/2015:23:44:14 and ending at 21/Dec/2015:23:45:11 for the second file, so one IP address made around 5k requests in less than a minute.
This shows up as a clear spike on the Munin graphs:
The IP address is owned by Vultr in Miami: https://www.robtex.com/ip/45.32.160.62.html
I guess we could contact them about this, but for now I'm simply going to deny access from this IP address using IP tables via the wiki:IpDrop script I just installed.
The Nginx ngx_http_limit_req_module allows rate limiting, following this article /etc/nginx/nginx.conf was edited to add:
And in /etc/nginx/sites-available/crin.org:
If IP addresses exceed requesting a PHP page per second they should now get 503 errors rather than cause 502 errors.
I'll check over the next few days how this rate limit effects things.