From 55f77dc37a8d5f3eaaf11531841fdc78d11c0596 Mon Sep 17 00:00:00 2001 From: Hayato Kiwata Date: Wed, 13 Nov 2024 00:12:31 +0900 Subject: [PATCH] fix: add fields such as CONTAINER_NAME to journald log entries sent to by containers MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit In the current implementation, containers running by `nerdctl` dose not export entries containing fields such as `CONTAINER_NAME`, `IMAGE_NAME` , and etc to the journald log like containers running by `docker cli`. At this time, the journald log entry describes below when sending to the journald log using nerdctl. ``` > nerdctl run -d --name nginx-nerdctl --log-driver=journald nginx bb7df47d27fd73426cec286ed88c5abf1443e74df637e2440d2dbca7229a84dc > nerdctl ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES bb7df47d27fd docker.io/library/nginx:latest "/docker-entrypoint.…" 3 seconds ago Up nginx-nerdctl > sudo journalctl SYSLOG_IDENTIFIER=bb7df47d27fd -a -n 1 -o json-pretty { "__CURSOR" : "???", "__REALTIME_TIMESTAMP" : "1730899940827182", "__MONOTONIC_TIMESTAMP" : "10815937979908", "_BOOT_ID" : "???", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "1ffffffffff", "_MACHINE_ID" : "???", "_HOSTNAME" : "???.us-west-2.amazon.com", "_TRANSPORT" : "journal", "_SYSTEMD_SLICE" : "system.slice", "PRIORITY" : "3", "_SYSTEMD_CGROUP" : "/system.slice/containerd.service", "_SYSTEMD_UNIT" : "containerd.service", "_COMM" : "nerdctl", "_EXE" : "/usr/local/bin/nerdctl", "_CMDLINE" : "/usr/local/bin/nerdctl _NERDCTL_INTERNAL_LOGGING /var/lib/nerdctl/1935db59", "SYSLOG_IDENTIFIER" : "bb7df47d27fd", "_PID" : "8118", "MESSAGE" : "2024/11/06 13:32:20 [notice] 1#1: start worker process 44", "_SOURCE_REALTIME_TIMESTAMP" : "1730899940825905" } ``` On the other hand, the output fields are listed below when we use the journald logging driver with docker cli. - https://docs.docker.com/engine/logging/drivers/journald/ As you can see, some entries are not output by nerdctl and are incompatible with the docker cli. This feature request is reported in the following: - https://github.com/containerd/nerdctl/issues/3486 Therefore, in this pull request, we will add the fields to be output in the journald log. After applying this fix, the journald log will output the following fields. ``` { "__CURSOR": "???", "__REALTIME_TIMESTAMP": "1731385591671422", "__MONOTONIC_TIMESTAMP": "11301588824148", "_BOOT_ID": "???", "_MACHINE_ID": "???", "_HOSTNAME": "???.us-west-2.amazon.com", "PRIORITY": "3", "_TRANSPORT": "journal", "_UID": "0", "_GID": "0", "_COMM": "nerdctl", "_EXE": "/usr/local/bin/nerdctl", "_CMDLINE": "/usr/local/bin/nerdctl _NERDCTL_INTERNAL_LOGGING /var/lib/nerdctl/1935db59", "_CAP_EFFECTIVE": "1ffffffffff", "_SYSTEMD_CGROUP": "/system.slice/containerd.service", "_SYSTEMD_UNIT": "containerd.service", "_SYSTEMD_SLICE": "system.slice", "CONTAINER_NAME": "nginx-nerdctl", "IMAGE_NAME": "nginx", "CONTAINER_ID_FULL": "fe22eccbd704ba799785999079ac465ed067d5914e9e3f1020e769921d5a83c5", "SYSLOG_IDENTIFIER": "fe22eccbd704", "CONTAINER_TAG": "fe22eccbd704", "CONTAINER_ID": "fe22eccbd704", "_PID": "31643", "MESSAGE": "2024/11/12 04:26:31 [notice] 1#1: start worker process 44", "_SOURCE_REALTIME_TIMESTAMP": "1731385591669765" } ``` Signed-off-by: Hayato Kiwata --- cmd/nerdctl/container/container_run_test.go | 47 ++++++++++++++++----- pkg/cmd/container/create.go | 13 +++--- pkg/logging/fluentd_logger.go | 3 +- pkg/logging/journald_logger.go | 35 +++++++++++++-- pkg/logging/json_logger.go | 2 +- pkg/logging/logging.go | 32 +++++++------- pkg/logging/logging_test.go | 2 +- pkg/logging/none_logger.go | 4 +- pkg/logging/none_logger_test.go | 4 +- pkg/logging/syslog_logger.go | 3 +- 10 files changed, 105 insertions(+), 40 deletions(-) diff --git a/cmd/nerdctl/container/container_run_test.go b/cmd/nerdctl/container/container_run_test.go index a727a68ea45..9a22aded3b0 100644 --- a/cmd/nerdctl/container/container_run_test.go +++ b/cmd/nerdctl/container/container_run_test.go @@ -329,19 +329,44 @@ func TestRunWithJournaldLogDriver(t *testing.T) { time.Sleep(3 * time.Second) journalctl, err := exec.LookPath("journalctl") assert.NilError(t, err) + inspectedContainer := base.InspectContainer(containerName) - found := 0 - check := func(log poll.LogT) poll.Result { - res := icmd.RunCmd(icmd.Command(journalctl, "--no-pager", "--since", "2 minutes ago", fmt.Sprintf("SYSLOG_IDENTIFIER=%s", inspectedContainer.ID[:12]))) - assert.Equal(t, 0, res.ExitCode, res) - if strings.Contains(res.Stdout(), "bar") && strings.Contains(res.Stdout(), "foo") { - found = 1 - return poll.Success() - } - return poll.Continue("reading from journald is not yet finished") + + type testCase struct { + name string + filter string + } + testCases := []testCase{ + { + name: "filter journald logs using SYSLOG_IDENTIFIER field", + filter: fmt.Sprintf("SYSLOG_IDENTIFIER=%s", inspectedContainer.ID[:12]), + }, + { + name: "filter journald logs using CONTAINER_NAME field", + filter: fmt.Sprintf("CONTAINER_NAME=%s", containerName), + }, + { + name: "filter journald logs using IMAGE_NAME field", + filter: fmt.Sprintf("IMAGE_NAME=%s", testutil.CommonImage), + }, + } + for _, tc := range testCases { + tc := tc + t.Run(tc.name, func(t *testing.T) { + found := 0 + check := func(log poll.LogT) poll.Result { + res := icmd.RunCmd(icmd.Command(journalctl, "--no-pager", "--since", "2 minutes ago", tc.filter)) + assert.Equal(t, 0, res.ExitCode, res) + if strings.Contains(res.Stdout(), "bar") && strings.Contains(res.Stdout(), "foo") { + found = 1 + return poll.Success() + } + return poll.Continue("reading from journald is not yet finished") + } + poll.WaitOn(t, check, poll.WithDelay(100*time.Microsecond), poll.WithTimeout(20*time.Second)) + assert.Equal(t, 1, found) + }) } - poll.WaitOn(t, check, poll.WithDelay(100*time.Microsecond), poll.WithTimeout(20*time.Second)) - assert.Equal(t, 1, found) } func TestRunWithJournaldLogDriverAndLogOpt(t *testing.T) { diff --git a/pkg/cmd/container/create.go b/pkg/cmd/container/create.go index c5c6e222820..42ba43cb4f3 100644 --- a/pkg/cmd/container/create.go +++ b/pkg/cmd/container/create.go @@ -158,6 +158,7 @@ func Create(ctx context.Context, client *containerd.Client, args []string, netMa } var ensuredImage *imgutil.EnsuredImage + var rawImageRef string if !options.Rootfs { var platformSS []string // len: 0 or 1 if options.Platform != "" { @@ -167,13 +168,13 @@ func Create(ctx context.Context, client *containerd.Client, args []string, netMa if err != nil { return nil, generateRemoveStateDirFunc(ctx, id, internalLabels), err } - rawRef := args[0] + rawImageRef = args[0] options.ImagePullOpt.Mode = options.Pull options.ImagePullOpt.OCISpecPlatform = ocispecPlatforms options.ImagePullOpt.Unpack = nil - ensuredImage, err = image.EnsureImage(ctx, client, rawRef, options.ImagePullOpt) + ensuredImage, err = image.EnsureImage(ctx, client, rawImageRef, options.ImagePullOpt) if err != nil { return nil, generateRemoveStateDirFunc(ctx, id, internalLabels), err } @@ -218,7 +219,7 @@ func Create(ctx context.Context, client *containerd.Client, args []string, netMa // 1, nerdctl run --name demo -it imagename // 2, ctrl + c to stop demo container // 3, nerdctl start/restart demo - logConfig, err := generateLogConfig(dataStore, id, options.LogDriver, options.LogOpt, options.GOptions.Namespace) + logConfig, err := generateLogConfig(dataStore, id, options.LogDriver, options.LogOpt, options.GOptions.Namespace, options.GOptions.Address, rawImageRef) if err != nil { return nil, generateRemoveStateDirFunc(ctx, id, internalLabels), err } @@ -819,12 +820,14 @@ func writeCIDFile(path, id string) error { } // generateLogConfig creates a LogConfig for the current container store -func generateLogConfig(dataStore string, id string, logDriver string, logOpt []string, ns string) (logConfig logging.LogConfig, err error) { +func generateLogConfig(dataStore string, id string, logDriver string, logOpt []string, ns, address, rawImageRef string) (logConfig logging.LogConfig, err error) { var u *url.URL if u, err = url.Parse(logDriver); err == nil && u.Scheme != "" { logConfig.LogURI = logDriver } else { logConfig.Driver = logDriver + logConfig.Address = address + logConfig.RawImageRef = rawImageRef logConfig.Opts, err = parseKVStringsMapFromLogOpt(logOpt, logDriver) if err != nil { return logConfig, err @@ -834,7 +837,7 @@ func generateLogConfig(dataStore string, id string, logDriver string, logOpt []s logConfigB []byte lu *url.URL ) - logDriverInst, err = logging.GetDriver(logDriver, logConfig.Opts) + logDriverInst, err = logging.GetDriver(logDriver, logConfig.Opts, logConfig.Address, logConfig.RawImageRef) if err != nil { return logConfig, err } diff --git a/pkg/logging/fluentd_logger.go b/pkg/logging/fluentd_logger.go index 0f9fc762053..c0a7d579fdb 100644 --- a/pkg/logging/fluentd_logger.go +++ b/pkg/logging/fluentd_logger.go @@ -17,6 +17,7 @@ package logging import ( + "context" "fmt" "math" "net/url" @@ -99,7 +100,7 @@ func (f *FluentdLogger) Init(dataStore, ns, id string) error { return nil } -func (f *FluentdLogger) PreProcess(_ string, config *logging.Config) error { +func (f *FluentdLogger) PreProcess(_ context.Context, _ string, config *logging.Config) error { if runtime.GOOS == "windows" { // TODO: support fluentd on windows return fmt.Errorf("logging to fluentd is not supported on windows") diff --git a/pkg/logging/journald_logger.go b/pkg/logging/journald_logger.go index e2242af73c3..8e670abb193 100644 --- a/pkg/logging/journald_logger.go +++ b/pkg/logging/journald_logger.go @@ -18,6 +18,7 @@ package logging import ( "bytes" + "context" "errors" "fmt" "io" @@ -35,6 +36,8 @@ import ( "github.com/containerd/containerd/v2/core/runtime/v2/logging" "github.com/containerd/log" + "github.com/containerd/nerdctl/v2/pkg/clientutil" + "github.com/containerd/nerdctl/v2/pkg/containerutil" "github.com/containerd/nerdctl/v2/pkg/strutil" ) @@ -52,8 +55,10 @@ func JournalLogOptsValidate(logOptMap map[string]string) error { } type JournaldLogger struct { - Opts map[string]string - vars map[string]string + Opts map[string]string + vars map[string]string + Address string + RawImageRef string } type identifier struct { @@ -66,7 +71,7 @@ func (journaldLogger *JournaldLogger) Init(dataStore, ns, id string) error { return nil } -func (journaldLogger *JournaldLogger) PreProcess(dataStore string, config *logging.Config) error { +func (journaldLogger *JournaldLogger) PreProcess(ctx context.Context, dataStore string, config *logging.Config) error { if !journal.Enabled() { return errors.New("the local systemd journal is not available for logging") } @@ -95,9 +100,33 @@ func (journaldLogger *JournaldLogger) PreProcess(dataStore string, config *loggi syslogIdentifier = b.String() } } + + client, ctx, cancel, err := clientutil.NewClient(ctx, config.Namespace, journaldLogger.Address) + if err != nil { + return err + } + defer func() { + cancel() + client.Close() + }() + containerID := config.ID + container, err := client.LoadContainer(ctx, containerID) + if err != nil { + return err + } + containerLabels, err := container.Labels(ctx) + if err != nil { + return err + } + // construct log metadata for the container vars := map[string]string{ "SYSLOG_IDENTIFIER": syslogIdentifier, + "CONTAINER_TAG": syslogIdentifier, + "CONTAINER_ID": shortID, + "CONTAINER_ID_FULL": containerID, + "CONTAINER_NAME": containerutil.GetContainerName(containerLabels), + "IMAGE_NAME": journaldLogger.RawImageRef, } journaldLogger.vars = vars return nil diff --git a/pkg/logging/json_logger.go b/pkg/logging/json_logger.go index 05d1c19c8c1..988e847d5e9 100644 --- a/pkg/logging/json_logger.go +++ b/pkg/logging/json_logger.go @@ -78,7 +78,7 @@ func (jsonLogger *JSONLogger) Init(dataStore, ns, id string) error { return nil } -func (jsonLogger *JSONLogger) PreProcess(dataStore string, config *logging.Config) error { +func (jsonLogger *JSONLogger) PreProcess(ctx context.Context, dataStore string, config *logging.Config) error { var jsonFilePath string if logPath, ok := jsonLogger.Opts[LogPath]; ok { jsonFilePath = logPath diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go index 318e3496e6b..ea545f348b2 100644 --- a/pkg/logging/logging.go +++ b/pkg/logging/logging.go @@ -49,12 +49,12 @@ const ( type Driver interface { Init(dataStore, ns, id string) error - PreProcess(dataStore string, config *logging.Config) error + PreProcess(ctx context.Context, dataStore string, config *logging.Config) error Process(stdout <-chan string, stderr <-chan string) error PostProcess() error } -type DriverFactory func(map[string]string) (Driver, error) +type DriverFactory func(map[string]string, string, string) (Driver, error) type LogOptsValidateFunc func(logOptMap map[string]string) error var drivers = make(map[string]DriverFactory) @@ -81,28 +81,28 @@ func Drivers() []string { return ss } -func GetDriver(name string, opts map[string]string) (Driver, error) { +func GetDriver(name string, opts map[string]string, address, rawImageRef string) (Driver, error) { driverFactory, ok := drivers[name] if !ok { return nil, fmt.Errorf("unknown logging driver %q: %w", name, errdefs.ErrNotFound) } - return driverFactory(opts) + return driverFactory(opts, address, rawImageRef) } func init() { - RegisterDriver("none", func(opts map[string]string) (Driver, error) { + RegisterDriver("none", func(opts map[string]string, address, rawImageRef string) (Driver, error) { return &NoneLogger{}, nil }, NoneLogOptsValidate) - RegisterDriver("json-file", func(opts map[string]string) (Driver, error) { + RegisterDriver("json-file", func(opts map[string]string, address, rawImageRef string) (Driver, error) { return &JSONLogger{Opts: opts}, nil }, JSONFileLogOptsValidate) - RegisterDriver("journald", func(opts map[string]string) (Driver, error) { - return &JournaldLogger{Opts: opts}, nil + RegisterDriver("journald", func(opts map[string]string, address, rawImageRef string) (Driver, error) { + return &JournaldLogger{Opts: opts, Address: address, RawImageRef: rawImageRef}, nil }, JournalLogOptsValidate) - RegisterDriver("fluentd", func(opts map[string]string) (Driver, error) { + RegisterDriver("fluentd", func(opts map[string]string, address, rawImageRef string) (Driver, error) { return &FluentdLogger{Opts: opts}, nil }, FluentdLogOptsValidate) - RegisterDriver("syslog", func(opts map[string]string) (Driver, error) { + RegisterDriver("syslog", func(opts map[string]string, address, rawImageRef string) (Driver, error) { return &SyslogLogger{Opts: opts}, nil }, SyslogOptsValidate) } @@ -121,9 +121,11 @@ func Main(argv2 string) error { // LogConfig is marshalled as "log-config.json" type LogConfig struct { - Driver string `json:"driver"` - Opts map[string]string `json:"opts,omitempty"` - LogURI string `json:"-"` + Driver string `json:"driver"` + Opts map[string]string `json:"opts,omitempty"` + LogURI string `json:"-"` + Address string `json:"address"` + RawImageRef string `json:"image"` } // LogConfigFilePath returns the path of log-config.json @@ -149,7 +151,7 @@ func LoadLogConfig(dataStore, ns, id string) (LogConfig, error) { } func loggingProcessAdapter(ctx context.Context, driver Driver, dataStore string, config *logging.Config) error { - if err := driver.PreProcess(dataStore, config); err != nil { + if err := driver.PreProcess(ctx, dataStore, config); err != nil { return err } @@ -215,7 +217,7 @@ func loggerFunc(dataStore string) (logging.LoggerFunc, error) { if err != nil { return err } - driver, err := GetDriver(logConfig.Driver, logConfig.Opts) + driver, err := GetDriver(logConfig.Driver, logConfig.Opts, logConfig.Address, logConfig.RawImageRef) if err != nil { return err } diff --git a/pkg/logging/logging_test.go b/pkg/logging/logging_test.go index 4cec4c868cc..175f1b3e64b 100644 --- a/pkg/logging/logging_test.go +++ b/pkg/logging/logging_test.go @@ -38,7 +38,7 @@ func (m *MockDriver) Init(dataStore, ns, id string) error { return nil } -func (m *MockDriver) PreProcess(dataStore string, config *logging.Config) error { +func (m *MockDriver) PreProcess(ctx context.Context, dataStore string, config *logging.Config) error { return nil } diff --git a/pkg/logging/none_logger.go b/pkg/logging/none_logger.go index 57d7e1c1b34..8d316c32465 100644 --- a/pkg/logging/none_logger.go +++ b/pkg/logging/none_logger.go @@ -17,6 +17,8 @@ package logging import ( + "context" + "github.com/containerd/containerd/v2/core/runtime/v2/logging" ) @@ -28,7 +30,7 @@ func (n *NoneLogger) Init(dataStore, ns, id string) error { return nil } -func (n *NoneLogger) PreProcess(dataStore string, config *logging.Config) error { +func (n *NoneLogger) PreProcess(ctx context.Context, dataStore string, config *logging.Config) error { return nil } diff --git a/pkg/logging/none_logger_test.go b/pkg/logging/none_logger_test.go index 88e35b72d3c..59e967bc5e1 100644 --- a/pkg/logging/none_logger_test.go +++ b/pkg/logging/none_logger_test.go @@ -17,6 +17,7 @@ package logging import ( + "context" "os" "testing" "time" @@ -29,6 +30,7 @@ import ( func TestNoneLogger(t *testing.T) { // Create a temporary directory for potential log files tmpDir := t.TempDir() + ctx := context.Background() logger := &NoneLogger{ Opts: map[string]string{}, @@ -40,7 +42,7 @@ func TestNoneLogger(t *testing.T) { // Run all logger methods logger.Init(tmpDir, "namespace", "id") - logger.PreProcess(tmpDir, &logging.Config{}) + logger.PreProcess(ctx, tmpDir, &logging.Config{}) stdout := make(chan string) stderr := make(chan string) diff --git a/pkg/logging/syslog_logger.go b/pkg/logging/syslog_logger.go index 154478cad2a..460caf5313a 100644 --- a/pkg/logging/syslog_logger.go +++ b/pkg/logging/syslog_logger.go @@ -17,6 +17,7 @@ package logging import ( + "context" "crypto/tls" "errors" "fmt" @@ -122,7 +123,7 @@ func (sy *SyslogLogger) Init(dataStore string, ns string, id string) error { return nil } -func (sy *SyslogLogger) PreProcess(dataStore string, config *logging.Config) error { +func (sy *SyslogLogger) PreProcess(ctx context.Context, dataStore string, config *logging.Config) error { logger, err := parseSyslog(config.ID, sy.Opts) if err != nil { return err