こんにちは。utsugiです。今回は、db.t2.microのRDS for SQL ServerのCPUが、接続数0でも高騰してしまう事象に直面したので、内容について記録します。 ユーザ操作等によりCPU使用率が高騰する場合は対策の方針も立てやすいのですが、アイドル状態で高騰してしまうと少し戸惑ってしまうこともあるかと思いますので、少しでも、どなたかのご参考になれば幸いです。
目次
- RDS for SQL ServerのCPUが高騰した事象について
- RDS for SQL ServerのCPU高騰の原因 - RESOURCE MONITOR
- RESOURCE MONITORがCPUを高騰させる理由
- RESOURCE MONITORによるCPU高騰を解決する方法
- まとめ
RDS for SQL ServerのCPUが高騰した事象について
RDS for SQL ServerのCPU使用率が高騰した事象について、改めて、事象発生時の状況を記載致します。 表: RDS for SQL Serverの情報
| 項目 | 内容 |
|---|---|
| エンジン | SQL Server Express Edition |
| エンジンバージョン | 13.00.5216.0.v1(※2016 SP2を指します) |
| インスタンスクラス | db.t2.micro |
事象が確認できたRDS for SQL Serverの情報です。なお、SQL Server 2008からアップグレードを実施して2016にしたインスタンスです。
図: RDS for SQL ServerのCPU使用率高騰
一時的にCPU使用率が低下することもありますが、基本的に40%台を記録し続けているような状況です。
その他CPU高騰時の状況
- SQL Serverに対する接続: 無し
- アクティブなユーザ操作: 無し
- ハードウェア障害: 無し
- 再起動による改善: 無し
ユーザによる操作が一切ないにも関わらずCPUが高騰し続けているという状況で、かつ、再起動によっても改善しないという形です。なお、ハードウェア障害が発生していないことは、AWSサポートにより確認できています。
RDS for SQL ServerのCPU高騰の原因 - RESOURCE MONITOR
結論としましては、SQL Serverのバックグラウンドプロセスの1つである「RESOURCE MONITOR」がCPUを高騰させていることが分かりました。
特定に至った経緯を以下に記載致します。
OSとSQL ServerのどちらがCPUを高騰させているかの切り分け
まずは、大きく分類して、OSとDBのどちらがCPUを高騰させているのかを確認するところから始めました。拡張モニタリングでも確認することができますが、今回は無効であったため、RDS for SQL Serverのパフォーマンス ダッシュボードを確認するところから始めました。
図: パフォーマンス ダッシュボードの表示
パフォーマンス ダッシュボードは、SSMSで該当のインスタンスを右クリックし、レポート > 標準レポート > パフォーマンス ダッシュボード と進めることで表示することができます。
図: パフォーマンス ダッシュボードの状況
CPU使用率について「その他」よりも「SQL」の方が高く、CPUリソースについてはSQL Serverが消費していることが分かりました。
CPUを高騰させているDBプロセスの特定
OSとDB側だと、DB側がCPUを高騰させていることが分かりました。
したがって、実際にCPUを高騰させているDBプロセスについて特定することにしました。
そのために、以下のSQL文を発行しました。
プロセスを確認するSQL
SELECT * FROM sys.sysprocesses ORDER BY kpid;
sys.sysprocessesはSQL Serverで動作しているプロセスの情報を表示する動的管理ビューです。
これにより、バックグラウンドプロセスも含めて、プロセスの状態を把握することができます。
プロセスを確認するSQLの結果
spid kpid blocked waittype waittime lastwaittype waitresource dbid uid cpu physical_io memusage login_time last_batch ecid open_tran status program_name hostprocess cmd nt_domain nt_username net_address net_library loginame context_info sql_handle stmt_start stmt_end request_id ------ ------ ------- -------- -------------------- -------------------------------- ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------ ----------- -------------------- ----------- ----------------------- ----------------------- ------ --------- ------------------------------ -------------------------------------------------------------------------------------------------------------------------------- ----------- ---------------- -------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------- ------------ ------------ -------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ ------------------------------------------ ----------- ----------- ----------- 8 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-14 12:25:24.330 2019-05-14 12:25:24.330 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 14 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:58:26.273 2019-05-17 09:58:26.273 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 24 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:59:26.607 2019-05-17 09:59:26.607 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 25 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:08:32.070 2019-05-17 10:08:32.070 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 26 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:59:26.607 2019-05-17 09:59:26.607 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 27 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:08:32.070 2019-05-17 10:08:32.070 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 28 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:08:32.070 2019-05-17 10:08:32.070 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 29 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:59:26.607 2019-05-17 09:59:26.607 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 30 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:09:32.957 2019-05-17 10:09:32.957 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 31 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:03:29.253 2019-05-17 10:03:29.253 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 32 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:55:24.647 2019-05-17 09:55:24.647 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 33 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:49:22.023 2019-05-17 09:49:22.023 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 34 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:09:32.957 2019-05-17 10:09:32.957 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 35 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:09:32.957 2019-05-17 10:09:32.957 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 36 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:11:33.817 2019-05-17 10:11:33.817 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 37 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:05:29.977 2019-05-17 10:05:29.977 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 39 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:55:24.647 2019-05-17 09:55:24.647 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 51 0 0 0x0000 0 MISCELLANEOUS 5 1 0 0 3 2019-05-17 10:14:22.167 2019-05-17 10:14:22.163 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001000374860B608125A7DA01000000000000 -1 -1 0 52 0 0 0x0000 0 MISCELLANEOUS 1 1 250 15 3 2019-05-14 12:25:45.630 2019-05-14 12:25:48.597 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100F90B920720E42EB4DA01000000000000 -1 -1 0 53 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-14 12:28:00.510 2019-05-14 12:28:00.510 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D TCP/IP NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001005CBDC00F30E22EB4DA01000000000000 -1 -1 0 54 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-14 12:26:45.523 2019-05-14 12:26:45.523 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 55 0 0 0x0000 0 MISCELLANEOUS 1 1 0 6 3 2019-05-14 12:25:45.647 2019-05-14 12:25:45.927 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 56 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-17 10:11:00.290 2019-05-17 10:11:00.287 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001001770392F609E25A7DA01000000000000 -1 -1 0 57 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-17 10:14:15.537 2019-05-17 10:14:15.533 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D TCP/IP NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001005CBDC00F30E22EB4DA01000000000000 -1 -1 0 58 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-16 02:00:30.530 2019-05-16 02:00:30.530 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 59 0 0 0x0000 0 MISCELLANEOUS 5 1 0 0 3 2019-05-17 10:11:22.040 2019-05-17 10:11:22.040 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001000374860B608125A7DA01000000000000 -1 -1 0 60 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-16 01:12:45.520 2019-05-16 01:12:45.520 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 61 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-17 06:21:45.520 2019-05-17 06:21:45.520 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 62 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-16 01:17:15.530 2019-05-16 01:17:15.530 0 0 sleeping RdsAdminService 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100122A0516B0E62EB4DA01000000000000 -1 -1 0 63 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 3 2019-05-17 10:07:40.603 2019-05-17 10:07:40.600 0 0 sleeping SQL Management 3532 AWAITING COMMAND NT AUTHORITY SYSTEM F26CD55EA53D LPC NT AUTHORITY\SYSTEM 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001002A9D442490E92EB4DA01000000000000 -1 -1 0 64 0 0 0x0000 0 MISCELLANEOUS 1 2 0 23 3 2019-05-17 10:13:17.837 2019-05-17 10:13:18.193 0 0 sleeping Microsoft SQL Server Management Studio 2932 AWAITING COMMAND 049A334D1477 TCP/IP sa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100DEB3382C608E25A7DA01000000000000 -1 -1 0 21 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 09:53:23.873 2019-05-17 09:53:23.873 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 22 0 0 0x0000 0 MISCELLANEOUS 1 1 0 0 0 2019-05-17 10:08:32.070 2019-05-17 10:08:32.070 0 0 sleeping TASK MANAGER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 66 164 0 0x0042 0 PAGEIOLATCH_SH 32767:1:1395 1 2 954 5354 4 2019-05-17 10:14:17.247 2019-05-17 10:14:22.493 0 0 suspended Microsoft SQL Server Management Studio - Transact-SQL IntelliSense 2932 SELECT 049A334D1477 TCP/IP sa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x010001001C70C614409C25A7DA01000000000000 164 2188 0 10 632 0 0x0000 0 MEMORY_ALLOCATION_EXT 0 1 0 1 0 2019-05-14 12:25:24.377 2019-05-14 12:25:24.377 0 0 background RECEIVE rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 3 996 0 0x0060 44 LAZYWRITER_SLEEP 0 1 263734 0 0 2019-05-14 12:25:24.190 2019-05-14 12:25:24.190 0 0 background LAZY WRITER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 15 1472 0 0x00AC 251322628 BROKER_TRANSMITTER 1 1 0 0 0 2019-05-14 12:25:25.707 2019-05-14 12:25:25.707 0 0 background BRKR TASK rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 18 1892 0 0x019A 67770 XE_DISPATCHER_WAIT 0 1 125 0 0 2019-05-14 12:25:24.833 2019-05-14 12:25:24.833 0 0 background XE DISPATCHER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 17 1912 0 0x0198 13559 XE_TIMER_EVENT 0 1 5203 0 0 2019-05-14 12:25:24.833 2019-05-14 12:25:24.833 0 0 background XE TIMER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 1 2068 0 0x0082 44 LOGMGR_QUEUE 0 1 1109 0 0 2019-05-14 12:25:24.177 2019-05-14 12:25:24.177 0 0 background LOG WRITER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 13 2168 0 0x0081 59 ONDEMAND_TASK_QUEUE 1 1 375 0 0 2019-05-14 12:25:24.723 2019-05-14 12:25:24.723 0 0 background RESOURCE MONITOR rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 16 2496 0 0x006C 59 SLEEP_TASK 0 1 44480656 0 0 2019-05-14 12:25:24.833 2019-05-14 12:25:24.833 0 0 background RESOURCE MONITOR rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 6 2504 0 0x038D 251323488 WAIT_XTP_HOST_WAIT 0 1 0 0 0 2019-05-14 12:25:24.190 2019-05-14 12:25:24.190 0 0 background XTP_CKPT_AGENT rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 19 2756 0 0x00B1 251322363 BROKER_EVENTHANDLER 1 1 0 32 0 2019-05-14 12:25:25.690 2019-05-14 12:25:25.690 0 0 background BRKR EVENT HNDLR rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 11 2832 0 0x0084 259777 CHECKPOINT_QUEUE 1 1 9468 24718 0 2019-05-14 12:25:24.723 2019-05-14 12:25:24.723 0 0 background CHECKPOINT rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 65 2884 0 0x0000 0 RESERVED_MEMORY_ALLOCATION_EXT 1 2 0 0 4 2019-05-17 10:14:14.950 2019-05-17 10:14:24.267 0 0 runnable Microsoft SQL Server Management Studio - クエリ 2932 SELECT 049A334D1477 TCP/IP sa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x01000100449FC308408025A7DA01000000000000 0 86 0 2 2888 0 0x0336 44 DIRTY_PAGE_POLL 0 1 937 0 0 2019-05-14 12:25:24.190 2019-05-14 12:25:24.190 0 0 background RECOVERY WRITER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 5 2948 0 0x00A0 251322551 KSOURCE_WAKEUP 1 1 0 0 4 2019-05-14 12:25:24.190 2019-05-14 12:25:24.190 0 0 background SIGNAL HANDLER rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 23 3040 0 0x0327 390 HADR_FILESTREAM_IOMGR_IOCOMPLETI 1 1 421 0 0 2019-05-14 12:25:25.707 2019-05-14 12:25:25.707 0 0 background BRKR TASK rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 20 3092 0 0x019E 390 BROKER_TO_FLUSH 1 1 312 0 0 2019-05-14 12:25:25.707 2019-05-14 12:25:25.707 0 0 background BRKR TASK rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 7 3208 0 0x00AC 251322613 BROKER_TRANSMITTER 1 1 0 0 0 2019-05-14 12:25:25.707 2019-05-14 12:25:25.707 0 0 background BRKR TASK rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 4 3300 0 0x0083 2849 REQUEST_FOR_DEADLOCK_SEARCH 0 1 859 0 0 2019-05-14 12:25:24.190 2019-05-14 12:25:24.190 0 0 background LOCK MONITOR rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 12 3388 0 0x028E 251323628 FT_IFTSHC_MUTEX 0 1 0 0 0 2019-05-14 12:25:24.707 2019-05-14 12:25:24.707 0 0 background UNKNOWN TOKEN rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 9 3448 0 0x00A5 3479 SQLTRACE_INCREMENTAL_FLUSH_SLEEP 1 1 78 0 0 2019-05-14 12:25:24.363 2019-05-14 12:25:24.363 0 0 background TRACE QUEUE TASK rdsa 0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 0x0000000000000000000000000000000000000000 0 0 0 (54 行処理されました)
※「sid」「hostname」列の情報は消去しています。
表: cpu列が高いlastwaittypeおよびそのcmdの抜粋
| lastwaittype | cpu | cmd |
|---|---|---|
| SLEEP_TASK | 44480656 | RESOURCE MONITOR |
| LAZYWRITER_SLEEP | 263734 | LAZY WRITER |
| CHECKPOINT_QUEUE | 9468 | CHECKPOINT |
「cpu」列で「SLEEP_TASK」が逸脱した値を記録しています。「cmd」列は「RESOURCE MONITOR」です。これにより、バックグラウンドで動作中のRESOURCE MONITORがCPUを高騰させているのではないかという判断に至りました。
なお、「cpu」列は累積のCPU使用時間であるため、必ずしもこの列の値が高いプロセスが、現在もCPU使用率を高騰させているとは限りません。今回は、再起動後、ユーザによる操作がない状態でこの値が逸脱していたため、異常だと判断しました。
RESOURCE MONITORがCPUを使用していることの確認
念のため、最後にRESOURCE MONITORによるCPU使用状況を確かめるスクリプトを実行しました。
実行するSQL文はHigh CPU consumed by Resource Monitor due to low virtual memory - CSS SQL Server Engineersに記載されています。
RESOURCE MONITORのCPU使用を確認するSQL文
declare @curCPU int, @prevCPU int, @delta int, @msg varchar(max) set @curCPU =0 set @prevCPU = 0 while 1 = 1 begin select @curCPU = SUM(cpu_time) from sys.dm_exec_requests where command like '%Resource%Monitor%' set @delta = @curCPU - @prevCPU set @prevCPU = @curCPU set @msg = CAST(GETDATE() as varchar(20)) + ' -- delta in CPU in sec (wait time 60 sec, ignore first run): ' + CAST((@delta / 1000.00) as varchar(max)) raiserror (@msg, 10, 1) with nowait waitfor delay '0:1:0' end
正常に動作している場合、0、または0に近い値が出ますが、問題が生じている場合、それよりも高い数値が出力されます。なお、初回実行時の値は無視します(2回目以降の値を判定値として用います)。
通常のインスタンスでの実行結果
May 17 2019 5:26PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 62.0150000 May 17 2019 5:27PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 0.0000000 May 17 2019 5:28PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 0.0000000 May 17 2019 5:29PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 0.0000000
問題が発生しているインスタンスでの実行結果
May 17 2019 4:58PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 49448.7020000 May 17 2019 4:59PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 13.0000000 May 17 2019 5:00PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 12.7030000 May 17 2019 5:01PM -- delta in CPU in sec (wait time 60 sec, ignore first run): 13.9530000
表: 実行結果まとめ
| 計測 | 通常 | 異常 |
|---|---|---|
| 1回目 | 0 | 13.000 |
| 2回目 | 0 | 12.703 |
| 3回目 | 0 | 13.953 |
| 平均 | 0 | 13.219 |
今回は、問題が発生しているインスタンスは13前後の値を示していることが確認できました。以上のことより、RESOURCE MONITORがCPUを高騰させているという判断になりました。
RESOURCE MONITORがCPUを高騰させる理由
結論としては、メモリの量が少ないと本事象が発生する可能性があります。
先ほどCPU使用状況について確認する際に利用したSQLが載っているHigh CPU consumed by Resource Monitor due to low virtual memory - CSS SQL Server Engineersには以下の記載があります。
The root cause is that something like extended procedure, or COM (loaded by sp_OACreate) exhausted virtual address space of SQL SErver. SQL Server then is under a low virtual memory state. This cause Resource Monitor to do extra work.
拡張プロシージャやCOM等がメモリを消費することで、RESOURCE MONITORが余計な処理を実行しなければならない状態となり、結果として、CPUの高騰につながったという形です。
本事象はSQL Server 2008での事象、かつ、フィックスされているとアナウンスされてはいますが、2012/2014/2016/2019でも同様の事象が非公式(コメント欄)で報告されていることも確認できます。
RESOURCE MONITORによるCPU高騰を解決する方法
根本的に事象を解決するための最も確実な方法は、インスタンスクラスを上位のもの(db.t2.small・db.t2.medium)に変更することです。
と言いますのも、本事象の根本原因はメモリ不足にあるためです。
今回遭遇した事象は、db.t2.mediumに変更することにより恒久的に改善しました。また、AWSサポートからも、本事象はdb.t2.small以上では確認できていないと回答がありました(※あくまで問い合わせ時点でのものです)。
元も子もなくコストも増える解決策ですが、仮にインスタンスを再起動、あるいは、再作成し、一時的に事象を回避できたとしても、潜在的なCPU高騰のリスクを抱えたままであることに変わりありません。例えば、インスタンスに対して変更をかけたタイミングで事象が再現する可能性も否定しきれません。
そうであれば、根本原因に対処するのが確実です。
また、本事象についてはAWS Developer Forums: SQL Server EX: High CPU Usage since 2018-11-19でも活発に議論されていましたが、一時的に事象が改善しても再発するケースの報告も見受けられます。
私個人と致しましても、インスタンスクラスの変更により事象が解決したという前例を経験したため、こちらを恒久的な対策として推奨させていただきます。
まとめ
検証目的、あるいは、軽い負荷のみが予測される場合、db.t2.microを利用してSQL Serverを利用することもあるかと存じます。必ず再現するわけではありませんが、RESOURCE MONITORによってCPUが高騰する事象は発生し得ます。
基本的にコストを抑えるためにdb.t2.microを利用していることが多いと考えられるため、「インスタンスクラスを上げる」というコストが増加してしまう対策はイマイチとはなってしまいますが、少しでも、どなたかのお役に立てたら幸いです。
