SSMセッションマネージャーのセッションログの出力先は用途によって使い分けよう

SSMセッションマネージャーのセッションログの出力先は用途によって使い分けよう

SSMセッションマネージャーのセッションログの出力先をS3バケットにすると、ログが出力されないことがあるかも
Clock Icon2023.07.24

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

え! セッションログがS3バケットに出力されていない!

こんにちは、のんピ(@non____97)です。

皆さんはSSMセッションマネージャーのセッションログがS3バケットに出力されていないと経験をしたことはありますか? 私はあります。

SSMセッションマネージャーのセッションログはS3バケットやCloudWatch Logsに出力することが可能です。具体的な出力方法は以下記事をご覧ください。

CloudWatch Logsにログ出力をすると、以下のようにJSON形式のログが出力されます。

{
    "eventVersion": "1.0",
    "eventTime": "2023-07-18T10:24:19Z",
    "awsRegion": "us-east-1",
    "target": {
        "id": "i-0db2e26bb837c93b1"
    },
    "userIdentity": {
        "arn": "arn:aws:sts::<AWSアカウントID>:assumed-role/<IAMロール名>/<IAMユーザー名>"
    },
    "runAsUser": "ec2-user",
    "sessionId": "<IAMロール名>-05ba181f37a0fb8d2",
    "sessionData": [
        "\u001b[?2004l\u001b]0;@ip-10-0-1-11:~\u0007\u001b[?2004h[ec2-user@ip-10-0-1-11 ~]$ sudo dnf install httpd"
    ]
}
{
    "eventVersion": "1.0",
    "eventTime": "2023-07-18T10:24:20Z",
    "awsRegion": "us-east-1",
    "target": {
        "id": "i-0db2e26bb837c93b1"
    },
    "userIdentity": {
        "arn": "arn:aws:sts::<AWSアカウントID>:assumed-role/<IAMロール名>/<IAMユーザー名>"
    },
    "runAsUser": "ec2-user",
    "sessionId": "<IAMロール名>-05ba181f37a0fb8d2",
    "sessionData": [
        "Last metadata expiration check: 0:22:49 ago on Tue Jul 18 10:01:30 2023.",
        "Dependencies resolved.",
        "================================================================================================================================================================================================",
        " Package                                           Architecture                         Version                                                 Repository                                 Size",
        "================================================================================================================================================================================================",
        "Installing:",
        " \u001b[1m\u001b[32mhttpd                                            \u001b(B\u001b[m x86_64                               2.4.56-1.amzn2023                                       amazonlinux                                48 k",
        "Installing dependencies:",
        " \u001b[1m\u001b[32mapr                                              \u001b(B\u001b[m x86_64                               1.7.2-2.amzn2023.0.2                                    amazonlinux                               129 k",
        " \u001b[1m\u001b[32mapr-util                                         \u001b(B\u001b[m x86_64                               1.6.3-1.amzn2023.0.1                                    amazonlinux                                98 k",
        " \u001b[1m\u001b[32mgeneric-logos-httpd                              \u001b(B\u001b[m noarch                               18.0.0-12.amzn2023.0.3                                  amazonlinux                                19 k",
        " \u001b[1m\u001b[32mhttpd-core                                       \u001b(B\u001b[m x86_64                               2.4.56-1.amzn2023                                       amazonlinux                               1.4 M",
        " \u001b[1m\u001b[32mhttpd-filesystem                                 \u001b(B\u001b[m noarch                               2.4.56-1.amzn2023                                       amazonlinux                                15 k",
        " \u001b[1m\u001b[32mhttpd-tools                                      \u001b(B\u001b[m x86_64                               2.4.56-1.amzn2023                                       amazonlinux                                82 k",
        " \u001b[1m\u001b[32mlibbrotli                                        \u001b(B\u001b[m x86_64                               1.0.9-4.amzn2023.0.2                                    amazonlinux                               315 k",
        " \u001b[1m\u001b[32mmailcap                                          \u001b(B\u001b[m noarch                               2.1.49-3.amzn2023.0.3                                   amazonlinux                                33 k",
        "Installing weak dependencies:",
        " \u001b[1m\u001b[32mapr-util-openssl                                 \u001b(B\u001b[m x86_64                               1.6.3-1.amzn2023.0.1                                    amazonlinux                                17 k",
        " \u001b[1m\u001b[32mmod_http2                                        \u001b(B\u001b[m x86_64                               2.0.11-2.amzn2023                                       amazonlinux                               150 k",
        " \u001b[1m\u001b[32mmod_lua                                          \u001b(B\u001b[m x86_64                               2.4.56-1.amzn2023                                       amazonlinux                                62 k",
        "",
        "Transaction Summary",
        "================================================================================================================================================================================================",
        "Install  12 Packages",
        "",
        "Total download size: 2.3 M",
        "Installed size: 6.9 M"
    ]
}
{
    "eventVersion": "1.0",
    "eventTime": "2023-07-18T10:24:34Z",
    "awsRegion": "us-east-1",
    "target": {
        "id": "i-0db2e26bb837c93b1"
    },
    "userIdentity": {
        "arn": "arn:aws:sts::<AWSアカウントID>:assumed-role/<IAMロール名>/<IAMユーザー名>"
    },
    "runAsUser": "ec2-user",
    "sessionId": "<IAMロール名>-05ba181f37a0fb8d2",
    "sessionData": [
        "Is this ok [y/N]: N",
        "Operation aborted."
    ]
}

コマンド実行及び何か出力がある都度、このようなJSONが出力されるとなると結構なログ量になることが予想されます。加えて、CloudWatch Logsのログ取り込み料金が気になるところです。

そのため、個人的にはS3バケットへのログ出力をしたいところです。リアルタイムにログを確認したい場面もあまり考えにくいです。

そんな折、ふとS3バケット上のセッションログを確認すると一部ログファイルが出力されていないではありませんか。

なぜ、このような事象が発生したのか調査してみたので紹介します。

いきなりまとめ

  • EC2インスタンスを再起動した場合は、SSMセッションマネージャーのセッションログがS3バケットに出力できない
  • SSM Agentやssm-session-workerが停止した場合はセッションログをS3バケットに出力できる
    • ただし強制終了された場合は、セッションログをS3バケットに出力することはできない
  • セッションログの完全性が求められるのであれば、CloudWatch Logsにセッションログをストリーミングすることとなる
    • ただし対話型コマンドではセッションデータのストリーミングはサポートされていない
  • S3バケットへのログ出力をする場合は、上述のログ欠損のリスクを理解した上で設定する

SSM Agentのソースコードを眺めてみる

まず、S3バケットにセッションログが出力されるのはSSMセッションマネージャーのセッションが切断されたタイミングです。

出力されたセッションログの中身を確認してみましょう。

Script started on 2023-07-21 06:46:19+00:00 [<not executed on terminal>]
/bin/bash

cd /home/ec2-user

[?2004hsh-5.2$ /bin/bash

[?2004l
]0;@ip-10-0-1-11:/usr/bin[?2004h[ec2-user@ip-10-0-1-11 bin]$ cd /home/ec2-user

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ ls -l 

[?2004l
total 0

]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ cat /etc/os-release 

[?2004l
NAME="Amazon Linux"

VERSION="2023"

ID="amzn"

ID_LIKE="fedora"

VERSION_ID="2023"

PLATFORM_ID="platform:al2023"

PRETTY_NAME="Amazon Linux 2023"

ANSI_COLOR="0;33"

CPE_NAME="cpe:2.3:o:amazon:amazon_linux:2023"

HOME_URL="https://aws.amazon.com/linux/"

BUG_REPORT_URL="https://github.com/amazonlinux/amazon-linux-2023"

SUPPORT_END="2028-03-01"

]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ exit

[?2004l
exit

[?2004hsh-5.2$ exit

[?2004l
exit


Script done on 2023-07-21 06:46:19+00:00 [COMMAND_EXIT_CODE="0"]

scriptコマンドが裏で動いていそうですね。

ということでSSM Agentのソースコードを覗いて、scriptコマンドを叩いているところを確認します。

気合いでgrepすると、sciptを見つけました。

const (
	termEnvVariable       = "TERM=xterm-256color"
	langEnvVariable       = "LANG=C.UTF-8"
	langEnvVariableKey    = "LANG"
	startRecordSessionCmd = "script"
	newLineCharacter      = "\n"
	catCmd                = "cat"
	scriptFlag            = "-c"
	groupsIdentifier      = "groups="
)

こちらのscriptの変数startRecordSessionCmdを使っている箇所を探し出します。

// generateLogData generates a log file with the executed commands.
func (p *ShellPlugin) generateLogData(log log.T, config agentContracts.Configuration) error {
	var flagStderr bytes.Buffer
	loggerCmd := fmt.Sprintf("%s %s", catCmd, p.logger.ipcFilePath)

	// Sixty minutes is the maximum amount of time before the command is cancelled
	// If a command is running this long it is most likely a stuck process
	ctx, cancel := context.WithTimeout(context.Background(), 60*time.Minute)
	defer cancel()

	cmdWithFlag := exec.CommandContext(ctx, startRecordSessionCmd, p.logger.logFilePath, scriptFlag, loggerCmd)
	cmdWithFlag.Stderr = &flagStderr
	flagErr := cmdWithFlag.Run()
	if flagErr != nil {
		log.Debugf("Failed to generate transcript with -c flag: %v: %s", flagErr, flagStderr.String())

		var noFlagStderr bytes.Buffer

		// some versions of "script" does not take a -c flag when passing in commands.
		cmdWithoutFlag := exec.CommandContext(ctx, startRecordSessionCmd, p.logger.logFilePath, catCmd, p.logger.ipcFilePath)
		cmdWithoutFlag.Stderr = &noFlagStderr
		noFlagErr := cmdWithoutFlag.Run()
		if noFlagErr != nil {
			log.Debugf("Failed to generate transcript without -c flag: %v: %s", noFlagErr, noFlagStderr.String())
			return fmt.Errorf("Failed to generate transcript with the following errors:\n%v: %s\n%v:%s", flagErr, flagStderr.String(), noFlagErr, noFlagStderr.String())
		}
	}

	return nil
}

generateLogData()といういかにもな関数が見つかりました。

ここで、generateLogData()の構造体ShellPluginが何者か気になったので確認します。

// Plugin is the type for the plugin.
type ShellPlugin struct {
	context        context.T
	name           string
	stdin          *os.File
	stdout         *os.File
	stdoutPipe     io.Reader
	stderrPipe     io.Reader
	execCmd        execcmd.IExecCmd
	runAsUser      string
	dataChannel    datachannel.IDataChannel
	logger         logger
	separateOutput bool
	stdoutPrefix   string
	stderrPrefix   string
}

// logger is used for storing the information related to logging of session data to S3/CW
type logger struct {
	ipcFilePath                 string
	logFilePath                 string
	logFileName                 string
	transcriptDirPath           string
	ptyTerminated               chan bool
	cloudWatchStreamingFinished chan bool
	streamLogsToCloudWatch      bool
	s3Util                      s3util.IAmazonS3Util
	cwl                         cloudwatchlogsinterface.ICloudWatchLogsService
}

コメントからセッションログをS3バケットやCloudWatch Logsに出力する時に使いそうなのが伝わってきますね。

generateLogData()を呼び出している場所を探します。

// finishLogging generates and uploads logs to S3/CW, terminates streaming to CW if enabled
func (p *ShellPlugin) finishLogging(
	config agentContracts.Configuration,
	output iohandler.IOHandler,
	sessionPluginResultOutput mgsContracts.SessionPluginResultOutput,
	ipcFile *os.File) {
	log := p.context.Log()

	// Generate log data only if customer has either enabled S3 logging or CW logging with streaming disabled
	if config.OutputS3BucketName != "" || (config.CloudWatchLogGroup != "" && !config.CloudWatchStreamingEnabled) {
		log.Debugf("Creating log file for shell session id %s at %s", config.SessionId, p.logger.logFilePath)
		if err := p.generateLogData(log, config); err != nil {
			errorString := fmt.Errorf("unable to generate log data: %s", err)
			log.Error(errorString)
			output.MarkAsFailed(errorString)
			return
		}

		if config.OutputS3BucketName != "" {
			log.Debug("Starting S3 logging")
			s3KeyPrefix := fileutil.BuildS3Path(config.OutputS3KeyPrefix, p.logger.logFileName)
			p.uploadShellSessionLogsToS3(log, p.logger.s3Util, config, s3KeyPrefix)
			sessionPluginResultOutput.S3Bucket = config.OutputS3BucketName
			sessionPluginResultOutput.S3UrlSuffix = s3KeyPrefix
		}

		if config.CloudWatchLogGroup != "" && !config.CloudWatchStreamingEnabled {
			log.Debug("Starting CloudWatch logging")
			p.logger.cwl.StreamData(
				config.CloudWatchLogGroup,
				config.SessionId,
				p.logger.logFilePath,
				true,
				false,
				p.logger.ptyTerminated,
				false,
				false)
		}
	}

	// End streaming of logs since pty is terminated
	if p.logger.streamLogsToCloudWatch {
		p.logger.ptyTerminated <- true
		log.Debug("Waiting for streaming to finish")

		<-p.logger.cloudWatchStreamingFinished
		log.Debug("Streaming done, proceed to close session worker")

		p.cleanupLogFile(log, ipcFile)
	}

	// Populate CW log group information
	if config.CloudWatchLogGroup != "" {
		sessionPluginResultOutput.CwlGroup = config.CloudWatchLogGroup
		sessionPluginResultOutput.CwlStream = config.SessionId
	}
	output.SetOutput(sessionPluginResultOutput)
}

finishLogging()でログの生成とアップロードをしていそうですね。

finishLogging()を呼び出している場所を探します。

// execute starts command execution.
// It reads incoming message from data channel and executes it by either writing to pty.stdin or relying on exec.Cmd.
// It reads message from pty.stdout and writes to data channel.
func (p *ShellPlugin) execute(config agentContracts.Configuration,
	cancelFlag task.CancelFlag,
	output iohandler.IOHandler,
	shellProps mgsContracts.ShellProperties) {

	// Initialization
	log := p.context.Log()
	sessionPluginResultOutput := mgsContracts.SessionPluginResultOutput{}
	p.initializeLogger(log, config)

	// Validate session configuration before starting
	if err := p.validate(config); err != nil {
		output.SetExitCode(appconfig.ErrorExitCode)
		output.SetStatus(agentContracts.ResultStatusFailed)
		sessionPluginResultOutput.Output = err.Error()
		output.SetOutput(sessionPluginResultOutput)
		log.Errorf("Validation failed, err: %s", err)

		return
	}

	if appconfig.PluginNameNonInteractiveCommands == p.name {
		if err := p.setSeparateOutputStreamProperties(shellProps); err != nil {
			output.SetExitCode(appconfig.ErrorExitCode)
			output.SetStatus(agentContracts.ResultStatusFailed)
			sessionPluginResultOutput.Output = err.Error()
			output.SetOutput(sessionPluginResultOutput)
			log.Errorf("SeparateOutputStream properties validation failed, err: %s", err)
			return
		}
	}
	// Catch signals and send a signal to the "sigs" chan if it triggers
	sigs := make(chan os.Signal, 1)
	signal.Notify(sigs, syscall.SIGINT, syscall.SIGHUP, syscall.SIGTERM, syscall.SIGQUIT)

	// Setup cancellation flag for accepting TerminateSession requests and idle session timeout scenarios
	cancelled := make(chan bool, 1)
	go func() {
		sig := <-sigs
		log.Infof("caught signal to terminate: %v", sig)
		cancelled <- true
	}()

	// Get the command executor, which is either pseudo terminal or exec.Cmd depending on the plugin type
	if err := getCommandExecutor(log, shellProps, false, config, p); err != nil {
		errorString := fmt.Errorf("Unable to start command: %s\n", err)
		log.Error(errorString)
		time.Sleep(2 * time.Second)
		if appconfig.PluginNameNonInteractiveCommands == p.name {
			// Error started before exec.cmd starts needs to be explicitly propagated to data channel.
			p.sendErrorToDataChannel(log, errorString.Error())
		}
		output.MarkAsFailed(errorString)
		return
	}

	// Create ipcFile used for logging session data temporarily on disk
	ipcFile, err := os.Create(p.logger.ipcFilePath)
	if err != nil {
		errorString := fmt.Errorf("encountered an error while creating file %s: %s", p.logger.ipcFilePath, err)
		log.Error(errorString)
		output.MarkAsFailed(errorString)
		return
	}
	defer func() {
		if closeErr := ipcFile.Close(); closeErr != nil {
			log.Warnf("error occurred while closing ipcFile, %v", closeErr)
		}
	}()

	go func() {
		cancelState := cancelFlag.Wait()
		if cancelFlag.Canceled() {
			cancelled <- true
			log.Debug("Cancel flag set to cancelled in session")
		}
		log.Debugf("Cancel flag set to %v in session", cancelState)
	}()

	if appconfig.PluginNameNonInteractiveCommands == p.name {
		p.executeCommandsWithExec(config, cancelled, cancelFlag, output, ipcFile)
	} else {
		p.executeCommandsWithPty(config, cancelled, cancelFlag, output, ipcFile)
	}

	// Finish logger activity like uploading logs to S3/CW
	p.finishLogging(config, output, sessionPluginResultOutput, ipcFile)

	log.Debug("Shell session execution complete")
}

標準出力を読み込むexecute()から呼び出しているようです。

execute()を呼び出している場所を探します。

// Execute starts pseudo terminal.
// It reads incoming message from data channel and writes to pty.stdin.
// It reads message from pty.stdout and writes to data channel
func (p *ShellPlugin) Execute(
	config agentContracts.Configuration,
	cancelFlag task.CancelFlag,
	output iohandler.IOHandler,
	dataChannel datachannel.IDataChannel,
	shellProps mgsContracts.ShellProperties) {

	log := p.context.Log()
	p.dataChannel = dataChannel
	defer func() {
		if err := p.stop(log); err != nil {
			log.Errorf("Error occurred while closing pty: %v", err)
		}
		if err := recover(); err != nil {
			log.Errorf("Error occurred while executing plugin %s: \n%v", p.name, err)
			log.Errorf("Stacktrace:\n%s", debug.Stack())
			log.Flush()
			os.Exit(1)
		}
	}()

	if cancelFlag.ShutDown() {
		output.MarkAsShutdown()
	} else if cancelFlag.Canceled() {
		output.MarkAsCancelled()
	} else {
		p.execute(config, cancelFlag, output, shellProps)
	}
}

Execute()から呼び出しているようです。

Execute()の呼び出し先を探してみたのですが、私のGo力では見つけることはできませんでした...

ただ、取り敢えず何かをトリガーにscriptコマンドを実行してS3バケットにログをアップロードすることが分かりました。

他にもログを読み取るamazon-ssm-agent/agent/session/logging/main.goも眺めてみると、真相が分かる気がします。

// Copyright 2018 Amazon.com, Inc. or its affiliates. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License"). You may not
// use this file except in compliance with the License. A copy of the
// License is located at
//
// http://aws.amazon.com/apache2.0/
//
// or in the "license" file accompanying this file. This file is distributed
// on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
// either express or implied. See the License for the specific language governing
// permissions and limitations under the License.

// Package logging reads byte data from the log file and prints it on the console.
package main

import (
	"bufio"
	"os"
	"strconv"

	"github.com/aws/amazon-ssm-agent/agent/appconfig"
	"github.com/aws/amazon-ssm-agent/agent/context"
	"github.com/aws/amazon-ssm-agent/agent/log/ssmlog"
	"github.com/aws/amazon-ssm-agent/agent/session/logging/console"
	"github.com/aws/amazon-ssm-agent/agent/version"
)

const totalArguments = 2
const defaultSessionLoggerContextName = "[ssm-session-logger]"

func main() {
	args := os.Args
	argsLen := len(args) - 1

	logger := initializeLogger()
	log := logger.Log()
	log.Infof("ssm-session-logger - %v", version.String())

	// We need two arguments here.
	// First one is the name of the log file to read from.
	// Second one tells us whether to enable virtual terminal processing for newer versions of Windows.
	if argsLen != totalArguments {
		log.Error("Invalid number of arguments received while initializing session logger.")
		return
	}

	file, err := os.Open(args[1])
	if err != nil {
		log.Errorf("Failed to open log file %s", args[1])
		return
	}
	defer func() {
		if closeErr := file.Close(); closeErr != nil {
			log.Warnf("error occurred while closing file, %v", closeErr)
		}
	}()

	enableVirtualTerminalProcessingForWindows, err := strconv.ParseBool(args[2])
	if err != nil {
		log.Errorf("Invalid argument type received while initializing session logger %s", args[2])
		return
	}

	if enableVirtualTerminalProcessingForWindows {
		if err := console.InitDisplayMode(); err != nil {
			log.Errorf("Encountered an error while initializing console: %v", err)
			return
		}
	}

	scanner := bufio.NewScanner(file)
	scanner.Split(bufio.ScanBytes)
	for scanner.Scan() {
		os.Stdout.Write(scanner.Bytes())
	}
}

// initializeLogger initializes context logging for ssm session logger.
func initializeLogger() context.T {
	// initialize a light weight logger, use the default seelog config logger
	logger := ssmlog.SSMLogger(false)

	// initialize appconfig, use default config
	config := appconfig.DefaultConfig()

	// agentIdentity is nil because session-logger does not use instanceId/Region/Credentials
	return context.Default(logger, config, nil).With(defaultSessionLoggerContextName)
}

セッションログが正しくS3バケットに出力される条件を探ってみる

EC2インスタンスをマネジメントコンソールから再起動

結局SSM Agentのソースコードを読んでも確認しが持てなかったので、セッションログが正しくS3バケットに出力される条件を実際に動作確認して探ってみます。

まず、SSMセッションマネージャー接続中に、EC2インスタンスをマネジメントコンソールから再起動をした場合にセッションログが出力されるか確認します。

再起動して数分経つと、セッション履歴にこちらのセッションが表示されました。ステータスは終了済みで、出力場所にS3へのリンクがありました。

EC2インスタンスをマネジメントコンソールから再起動した場合

こちらのリンクをクリックしても、「そんなオブジェクトはない」と怒られてしまいました。

セッションログが存在しないことを確認

EC2インスタンスをマネジメントコンソールから再起動する場合はS3バケットにログ出力できないようです。

EC2インスタンスをOS内から再起動

続いて、SMセッションマネージャー接続中に、OSから再起動をした場合にセッションログが出力されるか確認します。

結果は、先ほどと同じでS3バケットにログ出力されていませんでした。

SSM Agentを再起動

続いて、SSMセッションマネージャー接続中に、SSM Agentを再起動をした場合にセッションログが出力されるか確認します。

# SSM Agentのステータス確認
$ systemctl status amazon-ssm-agent.service
● amazon-ssm-agent.service - amazon-ssm-agent
     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)
     Active: active (running) since Fri 2023-07-21 08:31:08 UTC; 2min 28s ago
   Main PID: 1478 (amazon-ssm-agen)
      Tasks: 34 (limit: 1061)
     Memory: 88.6M
        CPU: 1.003s
     CGroup: /system.slice/amazon-ssm-agent.service
             ├─1478 /usr/bin/amazon-ssm-agent
             ├─1523 /usr/bin/ssm-agent-worker
             ├─1616 /usr/bin/ssm-session-worker <IAMロール名>-018f2151098de1933
             ├─1629 sh
             ├─1630 /bin/bash
             ├─1798 systemctl status amazon-ssm-agent.service
             └─1799 less

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [EC2Identity] Checking disk for registration info
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [EC2Identity] Registration info found for ec2 instance
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [amazon-ssm-agent] Registration attempted. Resuming core agent startup.
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] credentialRefresher has started
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Credentials ready
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Starting credentials refresher loop
Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Next credential rotation will be in 13.057146873516666 minutes
Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker is not running, starting worker process
Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker (pid:1523) started
Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Monitor long running worker health every 60 seconds

# SSM Agentの再起動
$ sudo systemctl restart amazon-ssm-agent.service

# セッションの切断
$ exit
$ exit

セッション切断後、S3バケットを確認すると、以下のようなセッションログが出力されていました。

Script started on 2023-07-21 08:35:03+00:00 [<not executed on terminal>]
/bin/bash

cd /home/ec2-user

[?2004hsh-5.2$ /bin/bash

[?2004l
]0;@ip-10-0-1-11:/usr/bin[?2004h[ec2-user@ip-10-0-1-11 bin]$ cd /home/ec2-user

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ ssm [K[K[K[Ksystemctl s[K[C[1@s[1@u[1@d[1@o[1@ [C[C[C[C[C[C[C[C[C[C[K[K[K[K[K[Kl[Ksu[K[Ksystemctl status ssm-agent

[?2004l
[?1h=
Unit ssm-agent.service could not be found.[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ systemctl status ssm-agent.ser[Kre[K[K[K[K[K[K[K[K[K[K[K[K[K[K[K ss

sshd-keygen.service          sshd-keygen@rsa.service      sssd-autofs.socket           sssd-nss.socket              sssd-pam.service             sssd-sudo.service            

sshd-keygen.target           sshd.service                 sssd-kcm.service             sssd-pac.service             sssd-pam.socket              sssd-sudo.socket             

sshd-keygen@ecdsa.service    sshd.socket                  sssd-kcm.socket              sssd-pac.socket              sssd-ssh.service             sssd.service                 

sshd-keygen@ed25519.service  sssd-autofs.service          sssd-nss.service             sssd-pam-priv.socket         sssd-ssh.socket              

[ec2-user@ip-10-0-1-11 ~]$ systemctl status ssm-[K[K[K[Kamazon-ssm-agent.service 

[?2004l
[?1h=
● amazon-ssm-agent.service - amazon-ssm-agent[m

     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)[m

     Active: active (running) since Fri 2023-07-21 08:31:08 UTC; 2min 28s ago[m

   Main PID: 1478 (amazon-ssm-agen)[m

      Tasks: 34 (limit: 1061)[m

     Memory: 88.6M[m

        CPU: 1.003s[m

     CGroup: /system.slice/amazon-ssm-agent.service[m

             ├─1478 /usr/bin/amazon-ssm-agent[m

             ├─1523 /usr/bin/ssm-agent-worker[m

             ├─1616 /usr/bin/ssm-session-worker <IAMロール名>-018f2151098de1933[m

             ├─1629 sh[m

             ├─1630 /bin/bash[m

             ├─1798 systemctl status amazon-ssm-agent.service[m

             └─1799 less[m

[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [EC2Identity] Checking disk for registration info[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [EC2Identity] Registration info found for ec2 instance[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [amazon-ssm-agent] Registration attempted. Resuming core agent startup.[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] credentialRefresher has started[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Credentials ready[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Starting credentials refresher loop[m

Jul 21 08:31:08 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:08 INFO [CredentialRefresher] Next credential rotation will be in 13.057146873516666 minutes[m

Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker is not running, starting worker process[m

Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker (pid:1523) started[m

Jul 21 08:31:09 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1478]: 2023-07-21 08:31:09 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Monitor long running worker health every 60 seconds[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ systemctl status amazon-ssm-agent.service [C[1P[1P[1P[1P[1P[1P[1@r[1@e[1@s[1@t[1@a[1@r[1@t[C[1@s[1@u[1@d[1@o[1@ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ exit

[?2004l
exit

[?2004hsh-5.2$ exit

[?2004l
exit


Script done on 2023-07-21 08:35:03+00:00 [COMMAND_EXIT_CODE="0"]

SSM Agentを停止

続いて、SSMセッションマネージャー接続中に、SSM Agentを停止した場合にセッションログが出力されるか確認します。

$ systemctl status amazon-ssm-agent
● amazon-ssm-agent.service - amazon-ssm-agent
     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)
     Active: active (running) since Fri 2023-07-21 08:34:40 UTC; 6min ago
   Main PID: 1873 (amazon-ssm-agen)
      Tasks: 32 (limit: 1061)
     Memory: 89.0M
        CPU: 615ms
     CGroup: /system.slice/amazon-ssm-agent.service
             ├─1873 /usr/bin/amazon-ssm-agent
             ├─1882 /usr/bin/ssm-agent-worker
             ├─2077 /usr/bin/ssm-session-worker <IAMロール名>-074476b4c740e445f
             ├─2090 sh
             ├─2091 /bin/bash
             ├─2110 systemctl status amazon-ssm-agent
             └─2111 less

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [EC2Identity] Checking disk for registration info
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [EC2Identity] Registration info found for ec2 instance
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [amazon-ssm-agent] Registration attempted. Resuming core agent startup.
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] credentialRefresher has started
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Credentials ready
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Starting credentials refresher loop
Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Next credential rotation will be in 9.527221276283333 minutes
Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker is not running, starting worker process
Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker (pid:1882) started
Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Monitor long running worker health every 60 seconds

$ sudo systemctl stop amazon-ssm-agent.service

$ systemctl status amazon-ssm-agent
○ amazon-ssm-agent.service - amazon-ssm-agent
     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)
     Active: inactive (dead) since Fri 2023-07-21 08:41:46 UTC; 9s ago
   Duration: 6min 59.574s
    Process: 1873 ExecStart=/usr/bin/amazon-ssm-agent (code=exited, status=0/SUCCESS)
   Main PID: 1873 (code=exited, status=0/SUCCESS)
      Tasks: 13 (limit: 1061)
     Memory: 68.9M
        CPU: 908ms
     CGroup: /system.slice/amazon-ssm-agent.service
             ├─2077 /usr/bin/ssm-session-worker <IAMロール名>-074476b4c740e445f
             ├─2090 sh
             ├─2091 /bin/bash
             ├─2203 systemctl status amazon-ssm-agent
             └─2204 less

Jul 21 08:41:39 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:39 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Receiving stop signal, stop worker monitor
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [CredentialRefresher] Sending credential refresher stop signal
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [Registrar] Registrar is already stopped
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [amazon-ssm-agent] Bye.
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [CredentialRefresher] Stopping credentials refresher
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Deactivated successfully.
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2077 (ssm-session-wor) remains running after unit stopped.
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2090 (sh) remains running after unit stopped.
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2091 (bash) remains running after unit stopped.
Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: Stopped amazon-ssm-agent.service - amazon-ssm-agent.

# セッションの切断
$ exit
$ exit

SSM Agentのサービスは停止していますが、ssm-session-workerのプロセスは動いているのでSSM Agent停止後も継続してSSMセッションマネージャーで接続できていました。

なお、SSMセッションマネージャー切断後は再接続できませんでした。SSM Agentのサービスが停止されており、新しくssm-session-workerのプロセスの起動ができないためと考えます。

S3バケットを確認すると、以下のようなセッションログが出力されていました。

Script started on 2023-07-21 08:42:24+00:00 [<not executed on terminal>]
/bin/bash

cd /home/ec2-user

[?2004hsh-5.2$ /bin/bash

[?2004l
]0;@ip-10-0-1-11:/usr/bin[?2004h[ec2-user@ip-10-0-1-11 bin]$ cd /home/ec2-user

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ [7msystemctl status ssm[27msystemctl status ssm[K[K[K[7mamazon-ssm-agent[27mamazon-ssm-agent

[?2004l
[?1h=
● amazon-ssm-agent.service - amazon-ssm-agent[m

     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)[m

     Active: active (running) since Fri 2023-07-21 08:34:40 UTC; 6min ago[m

   Main PID: 1873 (amazon-ssm-agen)[m

      Tasks: 32 (limit: 1061)[m

     Memory: 89.0M[m

        CPU: 615ms[m

     CGroup: /system.slice/amazon-ssm-agent.service[m

             ├─1873 /usr/bin/amazon-ssm-agent[m

             ├─1882 /usr/bin/ssm-agent-worker[m

             ├─2077 /usr/bin/ssm-session-worker <IAMロール名>-074476b4c740e445f[m

             ├─2090 sh[m

             ├─2091 /bin/bash[m

             ├─2110 systemctl status amazon-ssm-agent[m

             └─2111 less[m

[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [EC2Identity] Checking disk for registration info[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [EC2Identity] Registration info found for ec2 instance[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [amazon-ssm-agent] Registration attempted. Resuming core agent startup.[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] credentialRefresher has started[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Credentials ready[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Starting credentials refresher loop[m

Jul 21 08:34:40 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:40 INFO [CredentialRefresher] Next credential rotation will be in 9.527221276283333 minutes[m

Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker is not running, starting worker process[m

Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker (pid:1882) started[m

Jul 21 08:34:41 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:34:41 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Monitor long running worker health every 60 seconds[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ s[Ks[Ksudo systemctl stp[Kop amazon-ssm-agent.service 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ sudo systemctl stop amazon-ssm-agent.service 
[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[12Pystemctl status amazon-ssm-agent

[?2004l
[?1h=
○ amazon-ssm-agent.service - amazon-ssm-agent[m

     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)[m

     Active: inactive (dead) since Fri 2023-07-21 08:41:46 UTC; 9s ago[m

   Duration: 6min 59.574s[m

    Process: 1873 ExecStart=/usr/bin/amazon-ssm-agent (code=exited, status=0/SUCCESS)[m

   Main PID: 1873 (code=exited, status=0/SUCCESS)[m

      Tasks: 13 (limit: 1061)[m

     Memory: 68.9M[m

        CPU: 908ms[m

     CGroup: /system.slice/amazon-ssm-agent.service[m

             ├─2077 /usr/bin/ssm-session-worker <IAMロール名>-074476b4c740e445f[m

             ├─2090 sh[m

             ├─2091 /bin/bash[m

             ├─2203 systemctl status amazon-ssm-agent[m

             └─2204 less[m

[m

Jul 21 08:41:39 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:39 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Receiving stop signal, stop worker monitor[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [CredentialRefresher] Sending credential refresher stop signal[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [Registrar] Registrar is already stopped[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [amazon-ssm-agent] Bye.[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1873]: 2023-07-21 08:41:46 INFO [CredentialRefresher] Stopping credentials refresher[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Deactivated successfully.[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2077 (ssm-session-wor) remains running after unit stopped.[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2090 (sh) remains running after unit stopped.[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 2091 (bash) remains running after unit stopped.[m

Jul 21 08:41:46 ip-10-0-1-11.ec2.internal systemd[1]: Stopped amazon-ssm-agent.service - amazon-ssm-agent.[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ ls -[K[K[K[Kexit

[?2004l
exit

[?2004hsh-5.2$ exit

[?2004l
exit


Script done on 2023-07-21 08:42:24+00:00 [COMMAND_EXIT_CODE="0"]

SSM Agentの子プロセスでセッションログをS3バケットにアップロードしていそうですね。

ssm-session-workerをKillした場合

次に、SSM Agent停止後にssm-session-workerをKillした場合の挙動を確認します。

sudo kill ssm-session-workerのPIDssm-session-workerのプロセスを停止させます。

プロセス停止後10分ほどセッションは切れず、ログ出力されませんでした。

しょうがないので、EC2インスタンスを再起動します。

すると、以下のようなセッションログがS3バケットに出力されました。

Script started on 2023-07-21 08:49:28+00:00 [<not executed on terminal>]
/bin/bash

cd /home/ec2-user

[?2004hsh-5.2$ /bin/bash

[?2004l
]0;@ip-10-0-1-11:/usr/bin[?2004h[ec2-user@ip-10-0-1-11 bin]$ cd /home/ec2-user

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 
[K
[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ cd /home/ec2-userexit[K/bin/bash[5Pexitsystemctl status amazon-ssm-agent
[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[Cudo systemctl stop amazon-ssm-agent.service 
[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[12Pystemctl status amazon-ssm-agent

[?2004l
[?1h=
● amazon-ssm-agent.service - amazon-ssm-agent[m

     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)[m

     Active: active (running) since Fri 2023-07-21 08:45:56 UTC; 1min 59s ago[m

   Main PID: 1479 (amazon-ssm-agen)[m

      Tasks: 32 (limit: 1061)[m

     Memory: 125.2M[m

        CPU: 2.067s[m

     CGroup: /system.slice/amazon-ssm-agent.service[m

             ├─1479 /usr/bin/amazon-ssm-agent[m

             ├─1524 /usr/bin/ssm-agent-worker[m

             ├─1626 /usr/bin/ssm-session-worker <IAMロール名>-05fd2d85e2c60477e[m

             ├─1639 sh[m

             ├─1640 /bin/bash[m

             ├─1659 systemctl status amazon-ssm-agent[m

             └─1660 less[m

[m

Jul 21 08:45:56 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] credentialRefresher has started[m

Jul 21 08:45:56 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] Credentials ready[m

Jul 21 08:45:56 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] Starting credentials refresher loop[m

Jul 21 08:45:57 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] Next credential rotation will be in -1.7492776498 minutes[m

Jul 21 08:45:57 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO EC2RoleProvider Successfully connected with instance profile role credentials[m

Jul 21 08:45:57 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] Credentials ready[m

Jul 21 08:45:57 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:56 INFO [CredentialRefresher] Next credential rotation will be in 29.999996065716665 minutes[m

Jul 21 08:45:57 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:57 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker is not running, starting worker process[m

Jul 21 08:45:58 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:57 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] [WorkerProvider] Worker ssm-agent-worker (pid:1524) started[m

Jul 21 08:45:58 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:45:57 INFO [amazon-ssm-agent] [LongRunningWorkerContainer] Monitor long running worker health every 60 seconds[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ systemctl status amazon-ssm-agent
[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[1P amazon-ssm-agent[1P amazon-ssm-agent[1P amazon-ssm-agent[1P amazon-ssm-agent[1P amazon-ssm-agentt amazon-ssm-agento amazon-ssm-agentp amazon-ssm-agent[C[1@s[1@u[1@d[1@o[1@ [C[C[C[C[C[C

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ sudo systemctl stop amazon-ssm-agent
[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[3Pystemctl status[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C[C

[?2004l
[?1h=
○ amazon-ssm-agent.service - amazon-ssm-agent[m

     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)[m

     Active: inactive (dead) since Fri 2023-07-21 08:48:18 UTC; 5s ago[m

   Duration: 2min 15.126s[m

    Process: 1479 ExecStart=/usr/bin/amazon-ssm-agent (code=exited, status=0/SUCCESS)[m

   Main PID: 1479 (code=exited, status=0/SUCCESS)[m

      Tasks: 13 (limit: 1061)[m

     Memory: 102.3M[m

        CPU: 2.245s[m

     CGroup: /system.slice/amazon-ssm-agent.service[m

             ├─1626 /usr/bin/ssm-session-worker <IAMロール名>-05fd2d85e2c60477e[m

             ├─1639 sh[m

             ├─1640 /bin/bash[m

             ├─1735 systemctl status amazon-ssm-agent[m

             └─1736 less[m

[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:48:18 INFO [CredentialRefresher] Sending credential refresher stop signal[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:48:18 INFO [CredentialRefresher] Stopping credentials refresher[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:48:18 INFO [Registrar] Registrar is already stopped[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1479]: 2023-07-21 08:48:18 INFO [amazon-ssm-agent] Bye.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Deactivated successfully.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1626 (ssm-session-wor) remains running after unit stopped.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1639 (sh) remains running after unit stopped.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1640 (bash) remains running after unit stopped.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: Stopped amazon-ssm-agent.service - amazon-ssm-agent.[m

Jul 21 08:48:18 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Consumed 2.227s CPU time.[m


[K[?1l>]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ 

[?2004l
]0;@ip-10-0-1-11:~[?2004h[ec2-user@ip-10-0-1-11 ~]$ sudo kill 172[K[K626

[?2004l
]0;@ip-10-0-1-11:~
Script done on 2023-07-21 08:49:28+00:00 [COMMAND_EXIT_CODE="0"]

プロセスを停止させた際のログも出力されていますね。

ついでに、プロセスを強制停止させた場合の挙動も確認します。

$ sudo systemctl stop amazon-ssm-agent.service

$ systemctl status amazon-ssm-agent
○ amazon-ssm-agent.service - amazon-ssm-agent
     Loaded: loaded (/etc/systemd/system/amazon-ssm-agent.service; enabled; preset: enabled)
     Active: inactive (dead) since Mon 2023-07-24 00:43:46 UTC; 2s ago
   Duration: 38.770s
    Process: 1490 ExecStart=/usr/bin/amazon-ssm-agent (code=exited, status=0/SUCCESS)
   Main PID: 1490 (code=exited, status=0/SUCCESS)
      Tasks: 12 (limit: 1061)
     Memory: 300.3M
        CPU: 11.507s
     CGroup: /system.slice/amazon-ssm-agent.service
             ├─1585 /usr/bin/ssm-session-worker <IAMロール名>-0be8a4ea273eb5792
             ├─1600 sh
             ├─1601 /bin/bash
             ├─1826 systemctl status amazon-ssm-agent
             └─1827 less

Jul 24 00:43:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1490]: 2023-07-24 00:43:46 INFO [CredentialRefresher] Sending credential refresher stop signal
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1490]: 2023-07-24 00:43:46 INFO [Registrar] Registrar is already stopped
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1490]: 2023-07-24 00:43:46 INFO [amazon-ssm-agent] Bye.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal amazon-ssm-agent[1490]: 2023-07-24 00:43:46 INFO [CredentialRefresher] Stopping credentials refresher
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Deactivated successfully.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1585 (ssm-session-wor) remains running after unit stopped.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1600 (sh) remains running after unit stopped.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Unit process 1601 (bash) remains running after unit stopped.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: Stopped amazon-ssm-agent.service - amazon-ssm-agent.
Jul 24 00:43:46 ip-10-0-1-11.ec2.internal systemd[1]: amazon-ssm-agent.service: Consumed 11.493s CPU time.

$ sudo kill -9 1585

こちらの場合もプロセスを強制停止させて20分近く経っても、セッションは切れませんでした。

SSMセッションマネージャーのコンソールからセッションを停止させてみます。20分ほど待ちましたが、SSMセッションマネージャーのセッションの状態も終了中のままです。

試しに一度EC2インスタンスを停止させてみます。

停止したタイミングではまだ、S3バケットにセッションログは出力されず、SSMセッションマネージャーのセッションの状態も終了中のままです。10分ほど待ちましたが変わらずです。

EC2インスタンスを起動させてみます。

起動したタイミングでセッションのステータスは終了済みになりましたがセッションログはS3バケットに出力されませんでした。

つまりはssm-agent-workerが正常に停止されなければならないようです。

セッションログの完全性が求められるのであれば、CloudWatch Logsにセッションログをストリーミングさせよう

SSMセッションマネージャー接続中にEC2インスタンスを停止させた場合、セッションログはS3バケットに出力されない事象を紹介しました。

S3バケットへのログ出力をする場合は、ログ欠損のリスクを理解した上で設定しましょう。

なお、CloudWatch Logsにはストリーミングでログ出力することが可能です。そのため、以下のようにOS停止をするコマンドを叩いた場合もログ出力されています。

{
    "eventVersion": "1.0",
    "eventTime": "2023-07-24T02:08:21Z",
    "awsRegion": "us-east-1",
    "target": {
        "id": "i-0db2e26bb837c93b1"
    },
    "userIdentity": {
        "arn": "arn:aws:sts::<AWSアカウントID>:assumed-role/<IAMロール名>/<IAMユーザー名>"
    },
    "runAsUser": "ec2-user",
    "sessionId": "<IAMロール名>-034a918b79ad11968",
    "sessionData": [
        "\u001b[?2004l\u001b]0;@ip-10-0-1-11:~\u0007\u001b[?2004h[ec2-user@ip-10-0-1-11 ~]$ sudo systemctl \u001b[7mpoweroff\u001b[27m\b\b\b\b\b\b\b\bpoweroff",
        "Terminated"
    ]
}

ただし、対話型コマンドではセッションデータのストリーミングはサポートされていません。ドキュメントをよく確認した上で設定をしましょう。

この記事が誰かの助けになれば幸いです。

以上、AWS事業本部 コンサルティング部の のんピ(@non____97)でした!

Share this article

facebook logohatena logotwitter logo

© Classmethod, Inc. All rights reserved.