Dealing with Ambiguity

CloudWatch Agent に救われた話

July 20, 2019
AWS

背景

近頃、家で飼っているマシンの調子が悪く、何故か突然 Web コンテンツが 403 Forbidden を返し始める、SSH による接続もできなくなる (RST が返される)、ただ ICMP ping の応答はある、という事象に見舞われることが 2 週間に 1 度程発生していました。当該マシンを reboot すると回復するものの、/var/log/messages 、/var/log/dmesg を見ても事象発生時以降から再起動前までこれといった記録はなく、Apache のログや sshd のログ等を見ても手がかりとなるようなものはありませんでした。

そもそも、HTTP による接続で 403 Forbidden を返される (ということは TCP ESTABLISHED) という事象と、SSH で RST が返される、という事象が同時に発生していること自体があまり直感的ではなく、自体を全般的に把握するために、CloudWatch Agent をインストールし、事象発生直前の OS メトリクスを確認することにしました。

SSM Agent の設定

まずはじめに、SSM Agent を設定します。これにより、CloudWatch Agent のインストールをマネジメントコンソールから行えたり、マネージドインスタンスとしてマシンを管理、セッションマネージャーによる接続等のメリットが生まれます。

1. アクティベーションの作成

まずはアクティベーションを作成しましょう。 Systems Manager コンソールの左ペインにある [アクティベーション] から [アクティベーションの作成] をクリックします。 インスタンス数や説明を記入し、IAM ロールを選択したらアクティベーションを作成します。

f:id:shiro_kochi:2018××××××××:plain:w100:left

作成したらコンソールに表示される Activation Code と Activation ID をメモしておきましょう。

2. SSM Agent のインストール

次に SSM Agent のインストールを行います。 管理対象のサーバーへログインし、rpm ファイルをダウンロード、インストールします。

$ mkdir /tmp/ssm
$ curl https://s3.amazonaws.com/ec2-downloads-windows/SSMAgent/latest/linux_amd64/amazon-ssm-agent.rpm -o /tmp/ssm/amazon-ssm-agent.rpm
% Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Dload  Upload   Total   Spent    Left  Speed
100 18.9M  100 18.9M    0     0  11.7M      0  0:00:01  0:00:01 --:--:-- 11.7M
$ sudo yum install -y /tmp/ssm/amazon-ssm-agent.rpm
3. アクティベーションの登録

1 で取得した Activation Code と Activation ID を登録します。

$ sudo systemctl stop amazon-ssm-agent
$ sudo amazon-ssm-agent -register -code "activation-code" -id "activation-id" -region "region"
$ sudo systemctl start amazon-ssm-agent
4. マネージドインスタンスの確認

終わったら、マネージドインスタンスとして、監視対象のサーバーが一覧に表示されるか確認します。

必要に応じて Name タグを設定しましょう。

f:id:shiro_kochi:2018××××××××:plain:w100:left

CloudWatch Agent の設定

いよいよ CloudWatch Agent の設定です。

1. CloudWatch Agent のインストール

こちらは Systems Manager のランコマンドから行います。

[コマンドの実行] をクリックし、[AWS-ConfigureAWSPackage] を選択します。Name には “AmazonCloudWatchAgent” を入力し、ターゲットとして、先ほどマネージドインスタンスとして登録したものを選択します。

入力が終わったらコマンドを実行しましょう。

f:id:shiro_kochi:2018××××××××:plain:w100:left

f:id:shiro_kochi:2018××××××××:plain:w100:left

コマンドのステータスが成功になったら完了です。

2. パラメータストアの作成

既に他のサーバー用に CloudWatch Agent のパラメータストアが設定されているのであれば、こちらの方が早いです。 既存のパラメータを多少いじって再度新規のパラメータとして登録しましょう。 今回は以下のようなパラメータで登録を行いました。

{
	"agent": {
		"metrics_collection_interval": 1,
		"run_as_user": "root"
	},
	"logs": {
		"logs_collected": {
			"files": {
				"collect_list": [
					{
						"file_path": "/var/log/messages",
						"log_group_name": "CentOS7",
						"log_stream_name": "/var/log/messages"
					},
					{
						"file_path": "/var/log/dmesg",
						"log_group_name": "CentOS7",
						"log_stream_name": "/var/log/dmesg"
					},
					{
						"file_path": "/var/log/boot.log",
						"log_group_name": "CentOS7",
						"log_stream_name": "/var/log/boot.log"
					},
					{
						"file_path": "/var/log/secure",
						"log_group_name": "CentOS7",
						"log_stream_name": "/var/log/secure"

					},
					{
						"file_path": "/var/log/yum.log",
						"log_group_name": "CentOS7",
						"log_stream_name": "/var/log/yum.log"
					},
					{
						"file_path": "/var/log/amazon/ssm/errors.log",
						"log_group_name": "CentOS7",
					        "log_stream_name": "/var/log/amazon/ssm/errors.log"
					},
					{
						"file_path": "/var/log/amazon/ssm/amazon-ssm-agent.log",
						"log_group_name": "CentOS7",
					        "log_stream_name": "/var/log/amazon/ssm/amazon-ssm-agent.log"
					}
				]
			}
		}
	},
	"metrics": {
		"metrics_collected": {
			"collectd": {
				"metrics_aggregation_interval": 0
			},
			"cpu": {
				"measurement": [
					"cpu_usage_idle",
					"cpu_usage_iowait",
					"cpu_usage_steal",
					"cpu_usage_guest",
					"cpu_usage_user",
					"cpu_usage_system"
				],
				"metrics_collection_interval": 1,
				"resources": [
					"*"
				],
				"totalcpu": true
			},
			"disk": {
				"measurement": [
					"used_percent"
				],
				"metrics_collection_interval": 1,
				"resources": [
					"*"
				]
			},
			"diskio": {
				"measurement": [
					"io_time",
					"write_bytes",
					"read_bytes",
					"writes",
					"reads"
				],
				"metrics_collection_interval": 1,
				"resources": [
					"*"
				]
			},
			"mem": {
				"measurement": [
					"mem_used_percent"
				],
				"metrics_collection_interval": 1
			},
			"net": {
				"measurement": [
					"bytes_sent",
					"bytes_recv",
					"packets_sent",
					"packets_recv"
				],
				"metrics_collection_interval": 1,
				"resources": [
					"*"
				]
			},
			"netstat": {
				"measurement": [
					"tcp_established",
					"tcp_time_wait"
				],
				"metrics_collection_interval": 1
			},
			"statsd": {
				"metrics_aggregation_interval": 0,
				"metrics_collection_interval": 10,
				"service_address": ":8125"
			},
			"swap": {
				"measurement": [
					"swap_used_percent"
				],
				"metrics_collection_interval": 1
			}
		}
	}
}
3. パラメータの適用

2 で設定したパラメータを CloudWatch Agent に適用します。 /root/.aws/config 及び /root/.aws/cretdentials に AmazonCloudWatchAgent プロファイルを設定しておきます。

$ cat /root/.aws/config
[default]
output = json
region = us-west-2

[AmazonCloudWatchAgent]
output = json
region = us-west-2

$ sudo cat /root/.aws/credentials
[default]
aws_access_key_id = xxxxxxxxxxxxxxxxxxxxxx
aws_secret_access_key = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

[AmazonCloudWatchAgent]
aws_access_key_id = xxxxxxxxxxxxxxxxxxxxxx
aws_secret_access_key = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

その後、以下のコマンドでパラメータを適用します。

なお、collectd がインストールされていない場合は、ひとまずディレクトリとかを作っておきます。(え

$ mkdir /usr/share/collectd/
$ touch /usr/share/collectd/types.db
$ /opt/aws/amazon-cloudwatch-agent/bin/amazon-cloudwatch-agent-ctl -a fetch-config -m onPremise -c ssm:CentOS -s

これで準備は完了です。

結果

CloudWatch Agent をインストールしてから 2 日後、例の事象が再び発生しました。

ここでメトリクスを見てみると、やはりメトリクスも PUT できていないようです。ただ、CPU 、メモリ、ディスク、ネットワーク等、どのリソースもほとんど使用されていないような状況でした。

f:id:shiro_kochi:2018××××××××:plain:w100:left

ここで、ダメ元でログを見てみると、なんとメトリクスが取れなくなる直前に以下のエントリがありました。

Jul 12 01:39:50 CentOS-KVM kernel: [159934.785444] ata1.00: exception Emask 0x50 SAct 0x20000000 SErr 0x40d0802 action 0xe frozen
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785454] ata1.00: irq_stat 0x00400040, connection status changed
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785463] ata1: SError: { RecovComm HostInt PHYRdyChg CommWake 10B8B DevExch }
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785471] ata1.00: failed command: WRITE FPDMA QUEUED
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785487] ata1.00: cmd 61/18:e8:00:f4:c6/00:00:09:00:00/40 tag 29 ncq dma 12288 out
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785487] res 40/00:e8:00:f4:c6/00:00:09:00:00/40 Emask 0x50 (ATA bus error)
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785495] ata1.00: status: { DRDY }
Jul 12 01:39:50 CentOS-KVM kernel: [159934.785503] ata1: hard resetting link
Jul 12 01:39:51 CentOS-KVM kernel: [159935.499483] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Jul 12 01:39:51 CentOS-KVM kernel: [159935.499564] ata1.00: model number mismatch 'INTEL SSDSC2BW180H6' != 'SandForce{200026BB}'
Jul 12 01:39:51 CentOS-KVM kernel: [159935.499570] ata1.00: revalidation failed (errno=-19)
Jul 12 01:39:51 CentOS-KVM kernel: [159935.499579] ata1: limiting SATA link speed to 1.5 Gbps
Jul 12 01:39:56 CentOS-KVM kernel: [159940.517528] ata1: hard resetting link
Jul 12 01:39:56 CentOS-KVM kernel: [159940.835281] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Jul 12 01:39:56 CentOS-KVM kernel: [159940.835372] ata1.00: model number mismatch 'INTEL SSDSC2BW180H6' != 'SandForce{200026BB}'
Jul 12 01:39:56 CentOS-KVM kernel: [159940.835376] ata1.00: revalidation failed (errno=-19)

SATA3 -> SATA1 に落ちてますね…。どうやら最後は完全に Disk I/O を発行できなくなっていたようです。どうりで再起動後にログ確認しても見えないわけだ…。

403 Forbidden もこれが原因でしょう。コンテンツにアクセスできなくなったようです。SSH が何故 Initial SYN に対して RST を返したのかは少し謎ですが、ひとまずディスクもしくは SATA ケーブル、端子の問題であることがわかりました。

CloudWatch Agent はディスクに flush される前に、メモリ上のファイルシステムキャッシュからログを引っ張ってきて、CloudWatch Logs に送ってくれてたようです。出来た子です。

皆さんも CloudWatch Agent をインストールしましょう。

(ちなみにこれ以上の切り分けは面倒なので大人しく新しい PC を買いました)

　© 2023, Dealing with Ambiguity