RDS High CPU and Slow Queries

Sign in, start the SQL lab and add the helpers. Start-Load runs two clients for a few minutes; Get-QueryStats reads Query Store per plan:

cd C:\aws-lab
aws login --profile saat-admin
$env:AWS_PROFILE = 'saat-admin'
.\Start-SqlLab.ps1
function Get-SqlPw([string]$Db) {
  $a = aws rds describe-db-instances --db-instance-identifier $Db --query "DBInstances[0].MasterUserSecret.SecretArn" --output text
  (aws secretsmanager get-secret-value --secret-id $a --query SecretString --output text | ConvertFrom-Json).password
}
$csb = New-Object System.Data.SqlClient.SqlConnectionStringBuilder
$csb['Data Source'] = '127.0.0.1,11433'; $csb['Initial Catalog'] = 'SaatShop'; $csb['User ID'] = 'saatadmin'; $csb['Password'] = (Get-SqlPw saat-sql); $csb['Encrypt'] = $true; $csb['TrustServerCertificate'] = $true
$load = {
  param($cs, $sql, $type, $prefix, $seconds)
  $end = (Get-Date).AddSeconds($seconds)
  $cn = New-Object System.Data.SqlClient.SqlConnection $cs; $cn.Open()
  $cm = $cn.CreateCommand(); $cm.CommandText = $sql
  $p = $cm.Parameters.Add('@v', [System.Data.SqlDbType]$type, 100)
  while ((Get-Date) -lt $end) { $p.Value = $prefix + (Get-Random -Minimum 1 -Maximum 100000); [void]$cm.ExecuteScalar() }
  $cn.Close()
}
function Start-Load([string]$Sql, [string]$Type = 'NVarChar', [string]$Prefix = 'Customer ', [int]$Seconds = 300) {
  1..2 | ForEach-Object { Start-Job -ScriptBlock $load -ArgumentList $csb.ConnectionString, $Sql, $Type, $Prefix, $Seconds } | Out-Null
  Get-Job | Wait-Job | Receive-Job; Get-Job | Remove-Job
}
function Get-QueryStats {
  sqlcmd -S "127.0.0.1,11433" -U saatadmin -C -d SaatShop -W -Q "SET NOCOUNT ON; SELECT RIGHT(qt.query_sql_text, 34) AS query_end, p.plan_id, CASE WHEN p.query_plan LIKE '%Index Seek%' THEN 'seek' ELSE 'scan' END AS op, CASE WHEN p.query_plan LIKE '%CONVERT_IMPLICIT%' THEN 'yes' ELSE 'no' END AS conversion, SUM(rs.count_executions) AS execs, CAST(SUM(rs.avg_cpu_time * rs.count_executions) / NULLIF(SUM(rs.count_executions), 0) / 1000.0 AS decimal(10,2)) AS avg_cpu_ms, CAST(SUM(rs.avg_logical_io_reads * rs.count_executions) / NULLIF(SUM(rs.count_executions), 0) AS int) AS avg_reads FROM sys.query_store_query_text qt JOIN sys.query_store_query q ON q.query_text_id = qt.query_text_id JOIN sys.query_store_plan p ON p.query_id = q.query_id JOIN sys.query_store_runtime_stats rs ON rs.plan_id = p.plan_id WHERE qt.query_sql_text LIKE '%dbo.Orders WHERE%' AND qt.query_sql_text NOT LIKE '%query_store%' GROUP BY qt.query_sql_text, p.plan_id, p.query_plan ORDER BY p.plan_id"
}
function Get-CpuMax([int]$Minutes = 6) {
  $e = (Get-Date).ToUniversalTime(); $s = $e.AddMinutes(-$Minutes)
  aws cloudwatch get-metric-statistics --namespace AWS/RDS --metric-name CPUUtilization --dimensions Name=DBInstanceIdentifier,Value=saat-sql --start-time $s.ToString('o') --end-time $e.ToString('o') --period 60 --statistics Maximum --query "max(Datapoints[].Maximum)" --output text
}
sqlcmd -S "127.0.0.1,11433" -U saatadmin -C -d SaatShop -Q "ALTER DATABASE SaatShop SET QUERY_STORE = ON (OPERATION_MODE = READ_WRITE); ALTER DATABASE SaatShop SET QUERY_STORE CLEAR; SELECT COUNT(*) AS orders FROM dbo.Orders;"

You should see something like this:

orders
-----------
     100003

1Run a lookup workload and watch CPU

Paste this whole block. Two clients look up random customers for 5 minutes:

Start-Load 'SELECT COUNT(*), SUM(Amount) FROM dbo.Orders WHERE Customer = @v'
"CPU max in the last 6 minutes: $(Get-CpuMax)%"

You should see something like this:

CPU max in the last 6 minutes: 94.2%

saat-sql’s CPU went close to 100% for a lookup that returns one row each time. Open CloudWatch > Database Insights for saat-sql: DB load sits near the vCPU line, almost all of it CPU, and one statement dominates the top SQL list.

2Prove the cost with Query Store

Paste this:

Get-QueryStats

You should see something like this:

query_end                          plan_id op   conversion execs avg_cpu_ms avg_reads
---------------------------------- ------- ---- ---------- ----- ---------- ---------
dbo.Orders WHERE Customer = @v           1 scan no          2412      38.71       812

About 40 ms of CPU and 812 page reads per execution to find one customer: the whole table, every time. That’s what “high CPU” usually looks like up close.

3Fix it with an index and measure again

Paste this whole block:

sqlcmd -S "127.0.0.1,11433" -U saatadmin -C -d SaatShop -Q "CREATE INDEX IX_Orders_Customer ON dbo.Orders (Customer) INCLUDE (Amount);"
Start-Load 'SELECT COUNT(*), SUM(Amount) FROM dbo.Orders WHERE Customer = @v' -Seconds 180
"CPU max in the last 4 minutes: $(Get-CpuMax 4)%"
Get-QueryStats

You should see something like this:

CPU max in the last 4 minutes: 23.5%
query_end                          plan_id op   conversion execs avg_cpu_ms avg_reads
---------------------------------- ------- ---- ---------- ----- ---------- ---------
dbo.Orders WHERE Customer = @v           1 scan no          2412      38.71       812
dbo.Orders WHERE Customer = @v           2 seek no         61530       0.05         3

The same query got a new plan: a seek with 3 reads and a twentieth of a millisecond of CPU, so the clients ran 25 times as many lookups at a quarter of the CPU. No instance change, no downtime.

✅ Checkpoint: CPU was over 90% under the lookup workload, Query Store showed a scan with about 800 reads per run, and after the index the new plan seeks with about 3 reads.