Day: April 5, 2007

Sudden activity
has been noticed on 04-Apr-2007, between 14:30 and 14:40 – arount that time, when observing the system performance this morning, where the amount of free memory decreased to zero, causing a larger number of processes to stall for a moment and introducing a big increase in pagefile usage – it used to be about 30% in use and all of a sudden (more or less) it was up to 50% – even more, but gradually decreasing.
So tonight I took a look to the webserver log and indeed: two or three processes, more or less concurrently, acccessed the blog in the same time.
It started with rather innocent looking requests:
59.162.117.59 - - [04/Apr/2007:14:34:07 +0100] "GET /sysblog/xmlrpc.php?rsd HTTP/1.1" 200 1045
74.6.73.219 - - [04/Apr/2007:14:34:47 +0100] "GET /family/Holiday2003/12-jul/imagepages/image10.html HTTP/1.0" 200 5030
59.162.117.59 - - [04/Apr/2007:14:34:07 +0100] "GET /sysblog/xmlrpc.php HTTP/1.1" 200 252
59.162.117.59 - - [04/Apr/2007:14:34:07 +0100] "GET /sysblog/index.php?m=200702 HTTP/1.1" 200 16296
Next, accessing the blog, pretty normal:
59.162.117.59 - - [04/Apr/2007:14:35:16 +0100] "GET /sysblog/index.php?page_id=2 HTTP/1.1" 200 9333
59.162.117.59 - - [04/Apr/2007:14:35:16 +0100] "GET /sysblog/index.php?page_id=38 HTTP/1.1" 200 10249
59.162.117.59 - - [04/Apr/2007:14:36:24 +0100] "GET /sysblog/index.php?p=64 HTTP/1.1" 200 9956
59.162.117.59 - - [04/Apr/2007:14:36:27 +0100] "GET /sysblog/index.php?p=60 HTTP/1.1" 200 594
and next, another this address seased access, another (normally behaving) did two requests, after which the second “bad guy” introduced himself:
59.162.117.59 - - [04/Apr/2007:14:36:24 +0100] "GET /sysblog/index.php?p=61 HTTP/1.1" 200 10451
74.6.75.12 - - [04/Apr/2007:14:37:06 +0100] "GET /robots.txt HTTP/1.0" 200 430
74.6.72.41 - - [04/Apr/2007:14:37:06 +0100] "GET /family/March2005/res/favicon.ico HTTP/1.0" 200 13499
71.0.167.105 - - [04/Apr/2007:14:38:39 +0100] "GET /Family.css HTTP/1.1" 404 887
Pretty normal again, but the system must have been somewhat overloaded, because all of a suddent, there is twist in the timing:
but soemwa, one of them issuing direct requests uisng some session ID that – for obvious reasons – failed. But some request seems to have triggered a stall in the PHP engine, because THIS is weird:
71.0.167.105 - - [04/Apr/2007:14:38:39 +0100] "GET /family/Rita/Quilt/quilting.htm HTTP/1.1" 200 1768
71.0.167.105 - - [04/Apr/2007:14:38:39 +0100] "GET /openVMS/HOW_TO/index.htm HTTP/1.1" 200 3100
71.0.167.105 - - [04/Apr/2007:14:37:24 +0100] "GET /sysblog/index.php?p=59 HTTP/1.1" 502 0
71.0.167.105 - - [04/Apr/2007:14:37:25 +0100] "GET /sysblog/index.php?p=55#respond HTTP/1.1" 502 0
Mind the log time! These have been issues earlier but are somewhat delayed in delivery.
After some (obscuring?) norrmal requests, he starts direct requests – to services that are not enabled for such a request:
71.0.167.105 - - [04/Apr/2007:14:39:36 +0100] "GET /openVMS/HOW_TO/SharedSCSI/Controller.htm HTTP/1.1" 200 5320
71.0.167.105 - - [04/Apr/2007:14:39:36 +0100] "GET /family/Holiday2005/index.html HTTP/1.1" 200 19191
71.0.167.105 - - [04/Apr/2007:14:39:36 +0100] "GET /family/March2005/ HTTP/1.1" 200 9365
71.0.167.105 - - [04/Apr/2007:14:39:36 +0100] "GET /cgi-bin/query/./index.php?sid=56e3771a2ca5e56773c41c6ac261113f HTTP/1.1" 404 767
71.0.167.105 - - [04/Apr/2007:14:39:36 +0100] "GET /cgi-bin/query/./search.php?sid=56e3771a2ca5e56773c41c6ac261113f HTTP/1.1" 404 7
Some automated requests, by the way, seen the times.
At 14:40 was his last attempt:
71.0.167.105 - - [04/Apr/2007:14:40:05 +0100] "GET /cgi-bin/query/profile.php?mode=editprofile&sid=56e3771a2ca5e56773c41c6ac261
71.0.167.105 - - [04/Apr/2007:14:40:05 +0100] "GET /cgi-bin/query/privmsg.php?folder=inbox&sid=56e3771a2ca5e56773c41c6ac261113f
204.104.55.243 - - [04/Apr/2007:14:40:28 +0100] "GET /forums/templates/Galaxian/images/icon_mini_members.gif HTTP/1.1" 304 187
In exacty this timeframe, there have been two major increases of used memory and increased paging.
I did a lookup on these addresses but neither of them results in a valid reference. This may mean someone used an anonimizer.
I’ll need to investigate further.