FreshSource code fixes

In this post, I’ll talk about how someone was able to use SQL injection to spin up the database server to 100% utilization. I found the queries in the logs, duplicated the situation on dev, patched the code, and updated the website.

See also SQL inejection issues fixed.

In this post:

  • FreeBSD 13.1
  • PostgreSQL server 12.11 (running under RDS)

The first hint

On Thursday morning, I read an email:

From:AWS Notifications <no-reply@sns.amazonaws.com>
To:dan@langille.org
Subject:ALARM: "awsrds-pg01-CPU-Utilization" in US East (N. Virginia)
Date:Thursday, March 23, 2023 1:44 AM
Size:11 KB

You are receiving this email because your Amazon CloudWatch Alarm "awsrds-pg01-CPU-Utilization" in the 
US East (N. Virginia) region has entered the ALARM state, because "Threshold Crossed: 1 datapoint
[75.43258754427714 (23/03/23 04:43:00)] was greater than or equal to the threshold (75.0)." at 
"Thursday 23 March, 2023 05:44:40 UTC".

View this alarm in the AWS Management Console:
[redacted]

Alarm Details:
- Name:                       awsrds-pg01-CPU-Utilization
- Description:                
- State Change:               OK -> ALARM
- Reason for State Change:    Threshold Crossed: 1 datapoint [75.43258754427714 (23/03/23 
                              04:43:00)] was greater than or equal to the threshold (75.0).
- Timestamp:                  Thursday 23 March, 2023 05:44:40 UTC
- AWS Account:                782398408597
- Alarm Arn:                  arn:aws:cloudwatch:us-east-1:782398408597:alarm:awsrds-pg01-CPU-Utilization

Threshold:
- The alarm is in the ALARM state when the metric is GreaterThanOrEqualToThreshold 75.0 for
  at least 1 of the last 1 period(s) of 3600 seconds. 

Monitored Metric:
- MetricNamespace:                     AWS/RDS
- MetricName:                          CPUUtilization
- Dimensions:                          [DBInstanceIdentifier = pg01]
- Period:                              3600 seconds
- Statistic:                           Average
- Unit:                                not specified



State Change Actions:
- OK: 
- ALARM: [arn:aws:sns:us-east-1:782398408597:FreshPorts_AWS_DB_alarm]
- INSUFFICIENT_DATA: 


--
If you wish to stop receiving notifications from this topic, please click or visit the link below to unsubscribe:
[redacted]
Please do not reply directly to this email. If you have any questions or comments regarding this email,
please contact us at https://aws.amazon.com/support

Ahh, the website got slammed again. OK, I’ll look at that later.

… later

I went into the RDS console to see what was going on. This showed me it was mainly four queries:

Amazon Web Services web page showing four identical queries
Amazon Web Services web page showing four identical queries

That doesn’t show me the full details of the query.

Next, I connected directly to the database server via psql to find out what was being run.

See pg_stat_activity for more information.

[14:16 aws-1 dan ~] % psql -h [redacted].us-east-1.rds.amazonaws.com -U postgres freshports.org
Password for user postgres: 
psql (12.14, server 12.11)
SSL connection (protocol: TLSv1.2, cipher: ECDHE-RSA-AES256-GCM-SHA384, bits: 256, compression: off)
Type "help" for help.

freshports.org=> select * from pg_stat_activity ;

What I saw was the usual queries with unusual content.

The screen shots

Here are the screen shots of what I saw. The webserver address is redacted.

pg_stat_activity output showing GENERATE_SERIES
pg_stat_activity output showing GENERATE_SERIES – image #1
pg_stat_activity output showing GENERATE_SERIES
pg_stat_activity output showing GENERATE_SERIES – image #2
pg_stat_activity output showing PG_SLEEP
pg_stat_activity output showing PG_SLEEP – image #3
pg_stat_activity output showing PG_SLEEP
pg_stat_activity output showing PG_SLEEP – image #4
pg_stat_activity output showing GENERATE_SERIES
pg_stat_activity output showing GENERATE_SERIES – image #5

Mitigate first

What I did first was kill those backend processes. The numbers used below are from the pid column in the screen shots above. See the Server Signaling Functions for more information.

freshports.org=>  select pg_cancel_backend(12759);
 pg_cancel_backend 
-------------------
 t
(1 row)

freshports.org=>  select pg_cancel_backend(13230);
 pg_cancel_backend 
-------------------
 t
(1 row)

freshports.org=>  select pg_cancel_backend(12918);
 pg_cancel_backend 
-------------------
 t
(1 row)

freshports.org=>  select pg_cancel_backend(13071);
 pg_cancel_backend 
-------------------
 t
(1 row)

Short term fix

It took me a while to figure out where this was being invoked from. I had assumed FreshPorts. I was wrong. I was FreshSource.

I put this at the top of commit.php:

<?php
if ($_SERVER['REMOTE_ADDR'] != '[redacted]') {
    echo 'We know. Thanks for letting us know. We will fix this up as soon as we can. :)';
    exit;
}

That IP address was me at home. That allowed me to test, but kept everyone else out.

The logs

I am not sure what alerted me to it being FreshSource. I think it was this command:

sudo grep e8cc50a10937e2df4b591c87217bf3dc6334c6d1 /var/log/nginx/*.log

You can see that commit id in the screen shots. Here are a few lines of what I saw:

[20:40 aws-1-nginx01 dan /usr/local/www/freshsource/www] % sudo grep commit.php /var/log/nginx/freshsource.org-access.log
141.98.83.236 - - [23/Mar/2023:04:26:07 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:22 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1 HTTP/1.1" 200 6506 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:33 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1&UeCa%3D3347%20AND%201%3D1%20UNION%20ALL%20SELECT%201%2CNULL%2C%27%3Cscript%3Ealert%28%22XSS%22%29%3C%2Fscript%3E%27%2Ctable_name%20FROM%20information_schema.tables%20WHERE%202%3E1--%2F%2A%2A%2F%3B%20EXEC%20xp_cmdshell%28%27cat%20..%2F..%2F..%2Fetc%2Fpasswd%27%29%23 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:34 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1&UeCa%3D3347%20AND%201%3D1%20UNION%20ALL%20SELECT%201%2CNULL%2C%27%3Cscript%3Ealert%28%22XSS%22%29%3C%2Fscript%3E%27%2Ctable_name%20FROM%20information_schema.tables%20WHERE%202%3E1--%2F%2A%2A%2F%3B%20EXEC%20xp_cmdshell%28%27cat%20..%2F..%2F..%2Fetc%2Fpasswd%27%29%23 HTTP/1.1" 200 6506 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:34 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:35 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1 HTTP/1.1" 200 6512 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:36 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%2C%28%27%22%2C%27%22%22%2C%28 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:37 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%2C%28%27%22%2C%27%22%22%2C%28 HTTP/1.1" 200 6156 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:37 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%27wTRixa%3C%27%22%3EnOcDhX HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:38 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%27wTRixa%3C%27%22%3EnOcDhX HTTP/1.1" 200 6154 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:45 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%29%20AND%209749%3D7105%20AND%20%288919%3D8919 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:46 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%29%20AND%209749%3D7105%20AND%20%288919%3D8919 HTTP/1.1" 200 4810 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:57 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%29%20AND%206118%3D6118%20AND%20%288487%3D8487 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:58 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%29%20AND%206118%3D6118%20AND%20%288487%3D8487 HTTP/1.1" 200 4810 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:26:58 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%20AND%205347%3D8036 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:27:00 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%20AND%205347%3D8036 HTTP/1.1" 200 4810 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:27:10 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%20AND%206118%3D6118 HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:27:10 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%20AND%206118%3D6118 HTTP/1.1" 200 4810 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"
141.98.83.236 - - [23/Mar/2023:04:27:11 +0000] "GET /commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%27%29%20AND%205149%3D1662%20AND%20%28%27XqbF%27%3D%27XqbF HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US) AppleWebKit/532.2 (KHTML, like Gecko) Chrome/4.0.222.12 Safari/532.2"

Here is the full record, about 1450 lines.

So what are they putting in there?

Here’s an example:

commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1%27%20AND%205291%3D%28SELECT%205291%20FROM%20PG_SLEEP%285%29%29--%20eEfz

Becomes:

commit.php?message_id=e8cc50a10937e2df4b591c87217bf3dc6334c6d1' AND 5291=(SELECT 5291 FROM PG_SLEEP(5))-- eEfz

That introduces a 5 second delay – enough for the attacker to know the query has been run.

That was the first query I found which worked. I used that as the starting point for my testing on dev. When setting out to solve a problem, I like to be able to reproduce it first. Otherwise, there is no proof that the problem has been solved.

The fix

The fix was to move the code into the 21st century. This was something written in June 2002. It now uses prepared statements, which go a long way towards avoiding SQL injections, and I think they are easier to use.

For example, here are some diffs from the fixed code:

-			   and  watch_list_element.watch_list_id = $WatchListID) ";
+			   and  watch_list_element.watch_list_id = $2) ";


...

-	$sql .= "
-	 where commit_log.message_id             = '$message_id'
+	$sql .= '
+	 where commit_log.message_id             = $1

...

-         $result = pg_exec($database, $sql);
+#         $result = pg_exec($database, $sql);
+         $result = pg_prepare($db, COMMIT_QUERY, $sql) or die('query failed ' . pg_last_error($db));
          if ($result) {
+            if ($WatchListID) {
+               $params = array($message_id, $WatchListID);
+            } else {I t
+               $params = array($message_id);
+            }
+            $result = pg_execute($db, COMMIT_QUERY, $params) or die('query failed ' . pg_last_error($db));
+         }
+         if ($result) { # yeah, I know there's a die above, but I didn't want to remove this if when going to prepared statements

This moves from using pg_exec (line 15) to pg_execute (line 16), which uses prepared statements (see the pg_prepare call on line 16). On lines 2 and 10 you can see the parameters to the query. WatchListID is optional and handled by the if on line 18.

I made my changes, tested them. Made more changes to other parts of FreshSource, pulling in updates from FreshPorts. The two are more similar now than before and share much more code and configuration.

This morning, I made some more changes after realizing some improvements could also apply to FreshPorts.

The changes were put production on March 24 2023 09:49:20 UTC.

Please change your password.

The things I missed

Back on Feb 13 of this year, I am sure the same thing happened. I took the service offline because it was so busy. That took about 10-15 minutes to fix. I assumed it was a fluke, the host got hit hard, and the database server could not keep up. I was alerted to the problem by a ‘slow website’ report.

I’m also convinced there was a previous incident (probably in Nov/Dec) which went totally unnoticed for several days.

Do the right thing

FreshSource and FreshPorts use the same database and the same logins. That’s why it’s relevant to FreshPort users. They are two different interfaces to the same data.

This code was outdated and long ignored. It should have been updated years ago. Sorry.

Website Pin Facebook Twitter Myspace Friendfeed Technorati del.icio.us Digg Google StumbleUpon Premium Responsive

Leave a Comment

Scroll to Top