CloudWatch エージェントで既存ログの収集を開始した時の挙動

CloudWatch エージェントで既存ログの収集を開始した時の挙動

既存ログが全て取り込まれるわけではありません。
#CloudWatch Agent
#CloudWatch Logs
#Amazon CloudWatch
#AWS
なおにし

なおにし

facebook logohatena logotwitter logo
Clock Icon2025.01.24

こんにちは、なおにしです。

統合 CloudWatch エージェントを使用して複数のローテート済みの既存ログ(example.log-yyyy-mm-ddのような)が存在するような場合にログ収集を開始したときの挙動を確認してみたのでご紹介します。

はじめに

EC2インスタンスからCloudWatch Logs に対してログを送信する場合、基本的にはCloudWatch エージェントを使用するかと思います。以前はCloudWatch Logs エージェントが使用されていましたが、現在は非推奨となっており、ログの読み取りの制御に使われていたパラメータ「file_fingerprint_lines」や「initial_position」も統合 CloudWatch エージェントでは廃止されています。

https://dev.classmethod.jp/articles/comparing-cloudwatch-agents-then-and-now/

では統合 CloudWatch エージェントにおいてログの読み取りはどのように制御されているのかというと、ドキュメントには以下の記載があります。

標準のアスタリスクを標準のワイルドカードとして使用することもできます。例えば、/var/log/system.log* は、/var/log 内の、system.log_1111、system.log_2222 などのファイルに一致します。

ファイルの変更時間に基づいて、最新のファイルのみが CloudWatch Logs にプッシュされます。access_log.2018-06-01-01 と access_log.2018-06-01-02 など同じ形式の一連のファイルを指定するにはワイルドカードの使用をお勧めします。ただし、access_log_80 と access_log_443 のように複数の種類のファイルには使用しないでください。

結論から言うと記載どおりの挙動となるわけですが、太字の一文しか挙動に関する説明を見つけられなかったことの不安から、イメージどおりなのか実際に確認してみることと併せて、既存ログを更新したり諸々試してみました。

やってみた

前提

検証環境は以下のとおりです。

# cat /etc/os-release 
NAME="Amazon Linux"
VERSION="2023"
ID="amzn"
ID_LIKE="fedora"
VERSION_ID="2023"
PLATFORM_ID="platform:al2023"
PRETTY_NAME="Amazon Linux 2023.6.20241010"
（略）
# cat /opt/aws/amazon-cloudwatch-agent/bin/CWAGENT_VERSION
1.300044.0

監視対象のテストログは以下の内容で準備しています。

# ls -l /var/log/httpd/test_log*
-rw-r--r--. 1 root root 104 Jan 23 12:00 /var/log/httpd/test_log
-rw-r--r--. 1 root root 104 Jan 20 12:00 /var/log/httpd/test_log-2025-01-20
-rw-r--r--. 1 root root 104 Jan 23 18:00 /var/log/httpd/test_log-2025-01-21 ←タイムスタンプを意図的に変更
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-22

# cat /var/log/httpd/test_log
[Thu Jan 23 00:00:00.123456 2025] [test] Test Log 1
[Thu Jan 23 12:00:00.123456 2025] [test] Test Log 2
# cat /var/log/httpd/test_log-2025-01-22 
[Wed Jan 22 00:00:00.123456 2025] [test] Test Log 3
[Wed Jan 22 12:00:00.123456 2025] [test] Test Log 4
# cat /var/log/httpd/test_log-2025-01-21 
[Tue Jan 21 00:00:00.123456 2025] [test] Test Log 5
[Tue Jan 21 12:00:00.123456 2025] [test] Test Log 6
# cat /var/log/httpd/test_log-2025-01-20 
[Mon Jan 20 00:00:00.123456 2025] [test] Test Log 7
[Mon Jan 20 12:00:00.123456 2025] [test] Test Log 8

注目していただきたいのはテストログ「test_log-2025-01-21」です。こちらはファイル名やファイルの内容に反してタイムスタンプを意図的に4つのファイルの中で一番新しい状態にしています。

また、今回はログ収集のみを確認したかったので、初期設定ファイルは以下のようにウィザードで作成しました。

# /opt/aws/amazon-cloudwatch-agent/bin/amazon-cloudwatch-agent-config-wizard 
================================================================
= Welcome to the Amazon CloudWatch Agent Configuration Manager =
=                                                              =
= CloudWatch Agent allows you to collect metrics and logs from =
= your host and send them to CloudWatch. Additional CloudWatch =
= charges may apply.                                           =
================================================================
On which OS are you planning to use the agent?
1. linux
2. windows
3. darwin
default choice: [1]:

Trying to fetch the default region based on ec2 metadata...
I! imds retry client will retry 1 timesAre you using EC2 or On-Premises hosts?
1. EC2
2. On-Premises
default choice: [1]:

Which user are you planning to run the agent?
1. cwagent
2. root
3. others
default choice: [1]:
2
Do you want to turn on StatsD daemon?
1. yes
2. no
default choice: [1]:
2
Do you want to monitor metrics from CollectD? WARNING: CollectD must be installed or the Agent will fail to start
1. yes
2. no
default choice: [1]:
2
Do you want to monitor any host metrics? e.g. CPU, memory, etc.
1. yes
2. no
default choice: [1]:
2
Do you have any existing CloudWatch Log Agent (http://docs.aws.amazon.com/AmazonCloudWatch/latest/logs/AgentReference.html) configuration file to import for migration?
1. yes
2. no
default choice: [2]:

Do you want to monitor any log files?
1. yes
2. no
default choice: [1]:

Log file path:
/var/log/httpd/test_log*
Log group name:
default choice: [test_log*]
naonishi-test-test_log                
Log group class:
1. STANDARD
2. INFREQUENT_ACCESS
default choice: [1]:

Log stream name:
default choice: [{instance_id}]

Log Group Retention in days
1. -1
2. 1
3. 3
4. 5
5. 7
6. 14
7. 30
8. 60
9. 90
10. 120
11. 150
12. 180
13. 365
14. 400
15. 545
16. 731
17. 1096
18. 1827
19. 2192
20. 2557
21. 2922
22. 3288
23. 3653
default choice: [1]:
2
Do you want to specify any additional log files to monitor?
1. yes
2. no
default choice: [1]:
2
Do you want the CloudWatch agent to also retrieve X-ray traces?
1. yes
2. no
default choice: [1]:
2
Existing config JSON identified and copied to:  /opt/aws/amazon-cloudwatch-agent/etc/backup-configs
Saved config file to /opt/aws/amazon-cloudwatch-agent/bin/config.json successfully.
Current config as follows:
{
	"agent": {
		"run_as_user": "root"
	},
	"logs": {
		"logs_collected": {
			"files": {
				"collect_list": [
					{
						"file_path": "/var/log/httpd/test_log*",
						"log_group_class": "STANDARD",
						"log_group_name": "naonishi-test-test_log",
						"log_stream_name": "{instance_id}",
						"retention_in_days": 1
					}
				]
			}
		}
	}
}
Please check the above content of the config.
The config file is also located at /opt/aws/amazon-cloudwatch-agent/bin/config.json.
Edit it manually if needed.
Do you want to store the config in the SSM parameter store?
1. yes
2. no
default choice: [1]:
2
Program exits now.

CloudWatch エージェントはsystemctlで起動させるため、所定のパスに配置します。作成されたコンフィグはウィザードで表示されたとおりです。

# cp -p /opt/aws/amazon-cloudwatch-agent/bin/config.json /opt/aws/amazon-cloudwatch-agent/etc/amazon-cloudwatch-agent.json 
# cat /opt/aws/amazon-cloudwatch-agent/etc/amazon-cloudwatch-agent.json 
{
	"agent": {
		"run_as_user": "root"
	},
	"logs": {
		"logs_collected": {
			"files": {
				"collect_list": [
					{
						"file_path": "/var/log/httpd/test_log*",
						"log_group_class": "STANDARD",
						"log_group_name": "naonishi-test-test_log",
						"log_stream_name": "{instance_id}",
						"retention_in_days": 1
					}
				]
			}
		}
	}
}

挙動の確認結果

それではCloudWatch エージェントを起動します。

# systemctl start amazon-cloudwatch-agent.service

マネジメントコンソールを確認すると、指定したロググループが作成されていました。

20250124_naonishi_behavior-collecting-logs-with-cwagent_1.jpg

ログストリームはインスタンスIDとなっているので、開いてみます。

20250124_naonishi_behavior-collecting-logs-with-cwagent_2.png

準備していた4つのログファイルのうち、タイムスタンプが最も新しかった「/var/log/httpd/test_log-2025-01-21」のみが取り込まれたことを確認できました。タイムスタンプのフィールドはログを取り込んだ時刻が反映されているので、メッセージ内のタイムスタンプとは一致していません。

CloudWatch エージェントのプロセスによって開かれているファイルを確認してみます。

# lsof /var/log/httpd/test_log*
COMMAND     PID USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
amazon-cl 17124 root    7r   REG  259,1      104 33554975 /var/log/httpd/test_log-2025-01-21
#

現状ではログが取り込まれたファイルのみを見ているようです。対象のログをどこまで読み込んだのかという情報は以下で管理されています。

# ls -l /opt/aws/amazon-cloudwatch-agent/logs/state/
total 4
-rw-r--r--. 1 root root 38 Jan 23 19:19 _var_log_httpd_test_log-2025-01-21

# cat /opt/aws/amazon-cloudwatch-agent/logs/state/_var_log_httpd_test_log-2025-01-21 
104
/var/log/httpd/test_log-2025-01-21
#

それでは、取り込まれていなかった「test_log」に追加のログを書き込んでみます。

# echo '[Thu Jan 23 18:00:00.123456 2025] [test] Test Log 9' >> /var/log/httpd/test_log
# cat /var/log/httpd/test_log
[Thu Jan 23 00:00:00.123456 2025] [test] Test Log 1
[Thu Jan 23 12:00:00.123456 2025] [test] Test Log 2
[Thu Jan 23 18:00:00.123456 2025] [test] Test Log 9
#

再度マネジメントコンソールから確認すると、既存の内容も含めて「test_log」の中身が全て書き込まれていました。

20250124_naonishi_behavior-collecting-logs-with-cwagent_3.png

CloudWatch エージェントのプロセスも「test_log」を開いた状態となり、読み込み位置の情報も追加されました。

# lsof /var/log/httpd/test_log*
COMMAND     PID USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
amazon-cl 17124 root    7r   REG  259,1      104 33554975 /var/log/httpd/test_log-2025-01-21
amazon-cl 17124 root    8r   REG  259,1      156 33554972 /var/log/httpd/test_log
# 
# ls -l /opt/aws/amazon-cloudwatch-agent/logs/state/
total 8
-rw-r--r--. 1 root root 27 Jan 23 19:45 _var_log_httpd_test_log
-rw-r--r--. 1 root root 38 Jan 23 19:19 _var_log_httpd_test_log-2025-01-21
#

続いて、touchコマンドで「/var/log/httpd/test_log-2025-01-20」のタイムスタンプを「/var/log/httpd/test_log-2025-01-22」と同じにしてみましたが、今回はファイル自体に実際に書き込みがなされていないためか既存ログはロググループに送信されませんでした。

# ls -l /var/log/httpd/test_log*
-rw-r--r--. 1 root root 156 Jan 23 19:45 /var/log/httpd/test_log
-rw-r--r--. 1 root root 104 Jan 20 12:00 /var/log/httpd/test_log-2025-01-20
-rw-r--r--. 1 root root 104 Jan 23 18:00 /var/log/httpd/test_log-2025-01-21
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-22
# 
# touch -t 202501221200.00 /var/log/httpd/test_log-2025-01-20 
# 
# ls -l /var/log/httpd/test_log*
-rw-r--r--. 1 root root 156 Jan 23 19:45 /var/log/httpd/test_log
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-20
-rw-r--r--. 1 root root 104 Jan 23 18:00 /var/log/httpd/test_log-2025-01-21
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-22
# 
# lsof /var/log/httpd/test_log*
COMMAND     PID USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
amazon-cl 17124 root    7r   REG  259,1      104 33554975 /var/log/httpd/test_log-2025-01-21
amazon-cl 17124 root    8r   REG  259,1      156 33554972 /var/log/httpd/test_log
#

最後に、読み取り位置の管理ファイル「_var_log_httpd_test_log-2025-01-21」を削除してCloudWatch エージェントを再起動させてみます。

# ls -l /var/log/httpd/test_log*
-rw-r--r--. 1 root root 156 Jan 23 19:45 /var/log/httpd/test_log
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-20
-rw-r--r--. 1 root root 104 Jan 23 18:00 /var/log/httpd/test_log-2025-01-21
-rw-r--r--. 1 root root 104 Jan 22 12:00 /var/log/httpd/test_log-2025-01-22
# 
# cat /var/log/httpd/test_log
[Thu Jan 23 00:00:00.123456 2025] [test] Test Log 1
[Thu Jan 23 12:00:00.123456 2025] [test] Test Log 2
[Thu Jan 23 18:00:00.123456 2025] [test] Test Log 9
# 
# cat /var/log/httpd/test_log-2025-01-21
[Tue Jan 21 00:00:00.123456 2025] [test] Test Log 5
[Tue Jan 21 12:00:00.123456 2025] [test] Test Log 6
# 
# ls -l /opt/aws/amazon-cloudwatch-agent/logs/state/
total 8
-rw-r--r--. 1 root root 27 Jan 23 19:45 _var_log_httpd_test_log
-rw-r--r--. 1 root root 38 Jan 23 19:19 _var_log_httpd_test_log-2025-01-21
# 
# systemctl stop amazon-cloudwatch-agent.service 
# 
# rm -f /opt/aws/amazon-cloudwatch-agent/logs/state/_var_log_httpd_test_log-2025-01-21
# rm -f /opt/aws/amazon-cloudwatch-agent/logs/state/_var_log_httpd_test_log
#
# systemctl start amazon-cloudwatch-agent.service 
#
# lsof /var/log/httpd/test_log*
COMMAND     PID USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
amazon-cl 20059 root    7r   REG  259,1      156 33554972 /var/log/httpd/test_log
# 
# ls -l /opt/aws/amazon-cloudwatch-agent/logs/state/
total 4
-rw-r--r--. 1 root root 27 Jan 23 20:08 _var_log_httpd_test_log
#

今回は4つのファイルの中で「test_log」のタイムスタンプが最も新しかったため読み込まれたようです。
マネジメントコンソールで確認すると、「test_log」の内容が全て再送信されていることが確認できました。

20250124_naonishi_behavior-collecting-logs-with-cwagent_4.jpg

補足

ここまでマネジメントコンソールで表示されているとおり、[タイムスタンプ]フィールドの時刻と[メッセージ]フィールド内の時刻は異なっています。実際の運用では[メッセージ]フィールド内の時刻をタイムスタンプとして取り扱う方が都合の良い場面も多いかと思いますので、設定が必要な場合は以下の記事もご参照ください。

https://dev.classmethod.jp/articles/cwagent-timestamp-format/

記載されているtimestamp_formatを試すために、ちょうど手元にあった以下のApache(httpd)ログを指定して挙動を確認してみました。直近の2025年のログと、2024年のログが存在しています。

# cat /var/log/httpd/error_log 
[Thu Oct 17 10:19:08.374921 2024] [core:notice] [pid 26081:tid 26081] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[Thu Oct 17 10:21:50.222209 2024] [mpm_event:notice] [pid 26081:tid 26081] AH00492: caught SIGWINCH, shutting down gracefully
[Thu Jan 23 06:27:38.521362 2025] [suexec:notice] [pid 1476:tid 1476] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu Jan 23 06:27:38.594362 2025] [lbmethod_heartbeat:notice] [pid 1476:tid 1476] AH02282: No slotmem from mod_heartmonitor
[Thu Jan 23 06:27:38.595824 2025] [systemd:notice] [pid 1476:tid 1476] SELinux policy enabled; httpd running as context system_u:system_r:httpd_t:s0
[Thu Jan 23 06:27:38.602045 2025] [mpm_event:notice] [pid 1476:tid 1476] AH00489: Apache/2.4.62 (Amazon Linux) OpenSSL/3.0.8 configured -- resuming normal operations
[Thu Jan 23 06:27:38.602069 2025] [core:notice] [pid 1476:tid 1476] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'

CloudWatch エージェントの設定ファイルは以下のとおりです。

/opt/aws/amazon-cloudwatch-agent/etc/amazon-cloudwatch-agent.json
{
	"agent": {
		"run_as_user": "root"
	},
	"logs": {
		"logs_collected": {
			"files": {
				"collect_list": [
					{
						"file_path": "/var/log/httpd/error_log",
						"timestamp_format": "[%a %b %d %H:%M:%S.%f %Y]",
						"log_group_class": "STANDARD",
						"log_group_name": "naonishi-test-error_log",
						"log_stream_name": "{instance_id}",
						"retention_in_days": 1
					}
				]
			}
		}
	}
}

マネジメントコンソールで確認したところ、以下のとおり直近のログしか取り込まれていませんでした。

20250124_naonishi_behavior-collecting-logs-with-cwagent_5.png

CloudWatch エージェントのログを確認したところ、以下の出力がありました。

/opt/aws/amazon-cloudwatch-agent/logs/amazon-cloudwatch-agent.log
2025-01-23T08:20:55Z E! [outputs.cloudwatchlogs] The log entry in (naonishi-test-error_log/i-065133e6e3d9b9f41) with timestamp (2024-10-17 10:19:08.374 +0000 UTC) comparing to the current time (2025-01-23 08:20:55.95556649 +0000 UTC m=+1.191629713) is out of accepted time range. Discard the log entry.
2025-01-23T08:20:55Z E! [outputs.cloudwatchlogs] The log entry in (naonishi-test-error_log/i-065133e6e3d9b9f41) with timestamp (2024-10-17 10:21:50.222 +0000 UTC) comparing to the current time (2025-01-23 08:20:55.955614661 +0000 UTC m=+1.191677889) is out of accepted time range. Discard the log entry.

上記はCloudWatch LogsのPutLogEvents APIの仕様によるものです。

  • バッチ内のログ イベントはいずれも 2 時間以上先のものであってはなりません。
  • バッチ内のログ イベントはいずれも 14 日以上前のものであってはなりません。また、ロググループの保持期間より前のログ イベントもあってはなりません。

https://docs.aws.amazon.com/AmazonCloudWatchLogs/latest/APIReference/API_PutLogEvents.html

このため、もし既存ログを取り込む際にCloudWatch エージェントの設定でtimestamp_formatを使用していて、かつ対象ログのローテート間隔が長い場合はご注意ください。

まとめ

CloudWatch エージェントでのログ収集を使い慣れた方にとっては馴染みのある挙動かもしれませんが、特に初期導入の際には気になる部分かと思いますのでまとめてみました。

本記事がどなたかのお役に立てれば幸いです。

参考

Share this article

facebook logohatena logotwitter logo

関連記事

EC2 マネジメントコンソール画面より、CloudWatch エージェントをインストールしてカスタムメトリクス設定 ~ 取得まで可能になっていたのでやってみた

EC2 マネジメントコンソール画面より、CloudWatch エージェントをインストールしてカスタムメトリクス設定 ~ 取得まで可能になっていたのでやってみた

User avatar
片方 裕人
2024.12.22
CloudWatch エージェントの StatsD プロトコルを利用して Windows のサービス監視を実施する仕組みを構築してみた

CloudWatch エージェントの StatsD プロトコルを利用して Windows のサービス監視を実施する仕組みを構築してみた

User avatar
Shiina
2024.10.21
運用を自動化！ CloudWatch と Systems Manager オートメーションでプロセス監視＆自動復旧をやってみた

運用を自動化！ CloudWatch と Systems Manager オートメーションでプロセス監視＆自動復旧をやってみた

User avatar
Shiina
2024.10.08
CloudWatch エージェントのインストール時に EC2 の再起動は発生しますか？

CloudWatch エージェントのインストール時に EC2 の再起動は発生しますか？

User avatar
m.hayakawa
2024.09.02
Classmethod's white logo
Facebook's logo
X's logo
YouTube's logo

© Classmethod, Inc. All rights reserved.