Anatomy of a compromise: forensics on a breached shop server

18 October 2018

This part is less about the malware and more about the method: how you work out what happened from the logs, and what it looks like when a forensic investigator images your server. The site was a Magento 1 shop on a single Linux server in 2018. Card payments were involved, so once the breach was confirmed a PCI Forensic Investigator (PFI) was appointed, and that changes how you handle the box.

The first rule: do not tidy up

The instinct when you find a compromise is to start deleting things. Do not, at least not until the evidence is safe. Every file you open in an editor, every log you truncate, every package you upgrade changes timestamps and overwrites the record. Take copies of the logs first, and if there is any chance of an investigation, ask before you touch anything.

Imaging the disk

The investigator supplied a small toolkit: a live-response script and a static dcfldd binary. The live-response script ran first, writing its output to a text file named after the case. Then the disk was imaged over SSH straight to their server, so nothing extra was written to the disk being captured.

fdisk -l
screen -S image
./live-response.sh > CASE123_live.txt
./dcfldd if=/dev/vda hash=md5,sha256 hashwindow=1G \
    md5log=CASE123_MD5_vda.txt sha256log=CASE123_SHA256_vda.txt \
    hashconv=after bs=512 conv=noerror,sync \
  | ssh -i ./investigator.pem -l investigator forensics.example.com "cat > CASE123_vda.dd"

What each part is doing:

fdisk -l confirms which block device is the system disk. On a KVM guest it is usually /dev/vda.
screen because imaging a disk can take hours, and you do not want a dropped SSH session to kill it. Detach with Ctrl-A D and reattach with screen -r image.
dcfldd is dd with hashing built in. hash=md5,sha256 hashes the stream as it goes, and hashwindow=1G writes a hash for every gigabyte as well as the whole disk, so a damaged section of the copy can be pinned down without throwing away the rest.
conv=noerror,sync carries on past read errors and pads the bad blocks, so the offsets in the image still line up with the disk.
Piping to ssh means the image never lands on the local disk.

My shell history shows several runs before one finished cleanly, so expect to repeat it.

Working out the way in

I had already been through the logs before the investigator was involved, and went back to them after the image was taken. Three sources mattered.

The FTP transfer log

ProFTPD writes an xferlog entry for every file transferred. One line stood out:

Mon Jul 02 14:02:46 2018 0 203.0.113.45 2891 /home/example/public_html/app/etc/local.xml a _ o r example ftp 0 * c

Reading the fields left to right: the date, the transfer time in seconds, the remote host, the bytes, the file, a for an ASCII transfer, _ for no special action, o for outgoing (a download), r for a real local user, the user name, the service, 0 for no authentication method, * for no auth user id, and c for complete.

On Magento 1, app/etc/local.xml holds the database host, user and password. Someone had logged in over FTP as the site's own account and downloaded it. The FTP log also showed two successful logins for that account from the same address within the same minute.

The web access log

Searching the Apache logs for the same address gave about thirty requests over two minutes, and they tell the story:

203.0.113.45 - - [02/Jul/2018:15:01:40 +0100] "GET /index.php/backend HTTP/1.1" 200 5053
203.0.113.45 - - [02/Jul/2018:15:01:47 +0100] "POST /index.php/backend HTTP/1.1" 200 1802
203.0.113.45 - - [02/Jul/2018:15:02:30 +0100] "GET /adminer.php HTTP/1.1" 200 2269
203.0.113.45 - - [02/Jul/2018:15:02:55 +0100] "POST /adminer.php HTTP/1.1" 302 670
203.0.113.45 - - [02/Jul/2018:15:02:59 +0100] "GET /adminer.php?username=exampleuser&db=exampledb HTTP/1.1" 200 48760
203.0.113.45 - - [02/Jul/2018:15:03:02 +0100] "GET /adminer.php?username=exampleuser&db=exampledb&select=admin_user HTTP/1.1" 200 16138
203.0.113.45 - - [02/Jul/2018:15:03:15 +0100] "GET /adminer.php?username=exampleuser&db=exampledb&select=sales_flat_order HTTP/1.1" 200 52367
203.0.113.45 - - [02/Jul/2018:15:03:21 +0100] "GET /adminer.php?username=exampleuser&db=exampledb&select=sales_flat_order&page=last HTTP/1.1" 200 37731

They went straight to the shop's custom admin URL with no guessing, which suggests this was not their first look at the site.
The admin login POST came back as the login page again with an error image loaded straight after: a failed login.
A copy of Adminer, the single-file database tool, was sitting in the web root and answered.
They logged into it with the site's database user, then looked at the admin users table and paged through the orders table.

Lining up the clocks

At first the FTP download looked like it happened an hour before the web activity. It did not. Apache logs local time with the offset (+0100 here, British Summer Time). ProFTPD writes its own logs in GMT by default (its TimesGMT setting is on unless you turn it off). Corrected to the same zone, the order is:

Failed admin login.
Opens Adminer.
FTP login and download of local.xml.
Nine seconds later, logs into Adminer with the credentials from that file.

Always normalise every log to UTC before building a timeline. Two log sources an hour apart can turn a clear sequence into two unrelated events.

The PHP error log

I also went through the PHP error log for anything touching the SOAP API, and read the engine files of a third-party bulk product importer that lived in the web root. Import tools like that were a common way in on Magento 1 at the time; at least one widely used one had a file download hole that was exploited to read local.xml. In this case the FTP log answered the question first. Once I had read the error log I cleared it so I could watch fresh errors, which is fine after imaging and a mistake before.

Telling noise from signal

Any public site's logs are full of automated attacks for software it does not run. A few weeks later this one showed requests with a long URL-encoded PHP string in a ?1= parameter, trying to write a tiny eval file into the web root, with a serialised PHP object stuffed into the User-Agent. That is the 2015 Joomla session object injection (CVE-2015-8562) being sprayed at everything. Against a Magento site it does nothing; the 200 response is just the home page, with the home page's usual size.

Two quick checks separate noise from a real hit: does the request target software you actually run, and does the response size differ from what that URL normally returns?

There was one more odd entry: the theme's CSS being requested with a referrer on a lookalike host name. That is what you see when someone has cloned a site for phishing and the copy still pulls its stylesheets from the original. It is worth reporting the clone to its host.

Clean-up and prevention

Rotate everything the attacker could have seen: the FTP password, the database password, Magento admin passwords, API keys, and the encryption key in local.xml if card or token data was ever stored.
Remove database tools from the web root. If you need Adminer, put it behind HTTP authentication and an IP allow list, and delete it afterwards.
Replace plain FTP with SFTP using keys, and limit it by source IP. FTP passwords leak from developer machines and saved client configs, and you will never know which one did.
Keep local.xml (or wp-config.php, or .env) out of reach of any account that does not need it.
Keep logs long enough to answer questions months later, and ship a copy off the server so an attacker cannot edit them.
Keep every service's clock on NTP, and know which zone each log writes in.