diff --git a/libpod/container_log.go b/libpod/container_log.go index e33ede5dd1..3ae0c70e84 100644 --- a/libpod/container_log.go +++ b/libpod/container_log.go @@ -10,6 +10,7 @@ import ( "github.com/containers/podman/v4/libpod/define" "github.com/containers/podman/v4/libpod/events" "github.com/containers/podman/v4/libpod/logs" + systemdDefine "github.com/containers/podman/v4/pkg/systemd/define" "github.com/nxadm/tail" "github.com/nxadm/tail/watch" "github.com/sirupsen/logrus" @@ -36,11 +37,15 @@ func (r *Runtime) Log(ctx context.Context, containers []*Container, options *log func (c *Container) ReadLog(ctx context.Context, options *logs.LogOptions, logChannel chan *logs.LogLine, colorID int64) error { switch c.LogDriver() { case define.PassthroughLogging: + // if running under systemd fallback to a more native journald reading + if unitName, ok := c.config.Labels[systemdDefine.EnvVariable]; ok { + return c.readFromJournal(ctx, options, logChannel, colorID, unitName) + } return fmt.Errorf("this container is using the 'passthrough' log driver, cannot read logs: %w", define.ErrNoLogs) case define.NoLogging: return fmt.Errorf("this container is using the 'none' log driver, cannot read logs: %w", define.ErrNoLogs) case define.JournaldLogging: - return c.readFromJournal(ctx, options, logChannel, colorID) + return c.readFromJournal(ctx, options, logChannel, colorID, "") case define.JSONLogging: // TODO provide a separate implementation of this when Conmon // has support. diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go index dc305fabfd..a708ad46da 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -31,7 +31,8 @@ func init() { logDrivers = append(logDrivers, define.JournaldLogging) } -func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOptions, logChannel chan *logs.LogLine, colorID int64) error { +func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOptions, + logChannel chan *logs.LogLine, colorID int64, passthroughUnit string) error { // We need the container's events in the same journal to guarantee // consistency, see #10323. if options.Follow && c.runtime.config.Engine.EventsLogger != "journald" { @@ -67,10 +68,35 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption if err := journal.AddDisjunction(); err != nil { return fmt.Errorf("adding filter disjunction to journald logger: %w", err) } - match = sdjournal.Match{Field: "CONTAINER_ID_FULL", Value: c.ID()} - if err := journal.AddMatch(match.String()); err != nil { - return fmt.Errorf("adding filter to journald logger: %v: %w", match, err) + + if passthroughUnit != "" { + // Match based on systemd unit which is the container is cgroup + // so we get the exact logs for a single container even in the + // play kube case where a single unit starts more than one container. + unitTypeName := "_SYSTEMD_UNIT" + if rootless.IsRootless() { + unitTypeName = "_SYSTEMD_USER_UNIT" + } + // By default we will have our own systemd cgroup with the name libpod-.scope. + value := "libpod-" + c.ID() + ".scope" + if c.config.CgroupsMode == cgroupSplit { + // If cgroup split the container runs in the unit cgroup so we use this for logs, + // the good thing is we filter the podman events already out below. + // Thus we are left with the real container log and possibly podman output (e.g. logrus). + value = passthroughUnit + } + + match = sdjournal.Match{Field: unitTypeName, Value: value} + if err := journal.AddMatch(match.String()); err != nil { + return fmt.Errorf("adding filter to journald logger: %v: %w", match, err) + } + } else { + match = sdjournal.Match{Field: "CONTAINER_ID_FULL", Value: c.ID()} + if err := journal.AddMatch(match.String()); err != nil { + return fmt.Errorf("adding filter to journald logger: %v: %w", match, err) + } } + if err := journal.AddMatch(uidMatch.String()); err != nil { return fmt.Errorf("adding filter to journald logger: %v: %w", uidMatch, err) } @@ -162,26 +188,17 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption continue } - var message string - var formatError error - - if options.Multi { - message, formatError = journalFormatterWithID(entry) - } else { - message, formatError = journalFormatter(entry) - } - - if formatError != nil { - logrus.Errorf("Failed to parse journald log entry: %v", formatError) - return - } - - logLine, err := logs.NewJournaldLogLine(message, options.Multi) - logLine.ColorID = colorID + logLine, err := journalToLogLine(entry) if err != nil { - logrus.Errorf("Failed parse log line: %v", err) + logrus.Errorf("Failed parse journal entry: %v", err) return } + id := c.ID() + if len(id) > 12 { + id = id[:12] + } + logLine.CID = id + logLine.ColorID = colorID if options.UseName { logLine.CName = c.Name() } @@ -196,76 +213,37 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption return nil } -func journalFormatterWithID(entry *sdjournal.JournalEntry) (string, error) { - output, err := formatterPrefix(entry) - if err != nil { - return "", err - } - - id, ok := entry.Fields["CONTAINER_ID_FULL"] - if !ok { - return "", errors.New("no CONTAINER_ID_FULL field present in journal entry") - } - if len(id) > 12 { - id = id[:12] - } - output += fmt.Sprintf("%s ", id) - // Append message - msg, err := formatterMessage(entry) - if err != nil { - return "", err - } - output += msg - return output, nil -} +func journalToLogLine(entry *sdjournal.JournalEntry) (*logs.LogLine, error) { + line := &logs.LogLine{} -func journalFormatter(entry *sdjournal.JournalEntry) (string, error) { - output, err := formatterPrefix(entry) - if err != nil { - return "", err - } - // Append message - msg, err := formatterMessage(entry) - if err != nil { - return "", err - } - output += msg - return output, nil -} - -func formatterPrefix(entry *sdjournal.JournalEntry) (string, error) { usec := entry.RealtimeTimestamp - tsString := time.Unix(0, int64(usec)*int64(time.Microsecond)).Format(logs.LogTimeFormat) - output := fmt.Sprintf("%s ", tsString) + line.Time = time.Unix(0, int64(usec)*int64(time.Microsecond)) + priority, ok := entry.Fields["PRIORITY"] if !ok { - return "", errors.New("no PRIORITY field present in journal entry") + return nil, errors.New("no PRIORITY field present in journal entry") } switch priority { case journaldLogOut: - output += "stdout " + line.Device = "stdout" case journaldLogErr: - output += "stderr " + line.Device = "stderr" default: - return "", errors.New("unexpected PRIORITY field in journal entry") + return nil, errors.New("unexpected PRIORITY field in journal entry") } // if CONTAINER_PARTIAL_MESSAGE is defined, the log type is "P" if _, ok := entry.Fields["CONTAINER_PARTIAL_MESSAGE"]; ok { - output += fmt.Sprintf("%s ", logs.PartialLogType) + line.ParseLogType = logs.PartialLogType } else { - output += fmt.Sprintf("%s ", logs.FullLogType) + line.ParseLogType = logs.FullLogType } - return output, nil -} - -func formatterMessage(entry *sdjournal.JournalEntry) (string, error) { - // Finally, append the message - msg, ok := entry.Fields["MESSAGE"] + line.Msg, ok = entry.Fields["MESSAGE"] if !ok { - return "", errors.New("no MESSAGE field present in journal entry") + return nil, errors.New("no MESSAGE field present in journal entry") } - msg = strings.TrimSuffix(msg, "\n") - return msg, nil + line.Msg = strings.TrimSuffix(line.Msg, "\n") + + return line, nil } diff --git a/libpod/container_log_unsupported.go b/libpod/container_log_unsupported.go index cdce820b4f..d524561f42 100644 --- a/libpod/container_log_unsupported.go +++ b/libpod/container_log_unsupported.go @@ -11,6 +11,6 @@ import ( "github.com/containers/podman/v4/libpod/logs" ) -func (c *Container) readFromJournal(_ context.Context, _ *logs.LogOptions, _ chan *logs.LogLine, colorID int64) error { +func (c *Container) readFromJournal(_ context.Context, _ *logs.LogOptions, _ chan *logs.LogLine, _ int64, _ string) error { return fmt.Errorf("journald logging only enabled with systemd on linux: %w", define.ErrOSNotSupported) } diff --git a/libpod/logs/log.go b/libpod/logs/log.go index b053d91e18..552f0515a4 100644 --- a/libpod/logs/log.go +++ b/libpod/logs/log.go @@ -243,36 +243,6 @@ func NewLogLine(line string) (*LogLine, error) { return &l, nil } -// NewJournaldLogLine creates a LogLine from the specified line from journald. -// Note that if withID is set, the first item of the message is considered to -// be the container ID and set as such. -func NewJournaldLogLine(line string, withID bool) (*LogLine, error) { - splitLine := strings.Split(line, " ") - if len(splitLine) < 4 { - return nil, fmt.Errorf("'%s' is not a valid container log line", line) - } - logTime, err := time.Parse(LogTimeFormat, splitLine[0]) - if err != nil { - return nil, fmt.Errorf("unable to convert time %s from container log: %w", splitLine[0], err) - } - var msg, id string - if withID { - id = splitLine[3] - msg = strings.Join(splitLine[4:], " ") - } else { - msg = strings.Join(splitLine[3:], " ") - // NO ID - } - l := LogLine{ - Time: logTime, - Device: splitLine[1], - ParseLogType: splitLine[2], - Msg: msg, - CID: id, - } - return &l, nil -} - // Partial returns a bool if the log line is a partial log type func (l *LogLine) Partial() bool { return l.ParseLogType == PartialLogType diff --git a/test/system/250-systemd.bats b/test/system/250-systemd.bats index dad551b007..8c3064f9ef 100644 --- a/test/system/250-systemd.bats +++ b/test/system/250-systemd.bats @@ -383,11 +383,15 @@ metadata: spec: containers: - command: - - top + - sh + - -c + - echo a stdout; echo a stderr 1>&2; sleep inf image: $IMAGE name: a - command: - - top + - sh + - -c + - echo b stdout; echo b stderr 1>&2; sleep inf image: $IMAGE name: b EOF @@ -418,8 +422,18 @@ EOF for name in "a" "b"; do run_podman container inspect test_pod-${name} --format "{{.HostConfig.LogConfig.Type}}" assert $output != "passthrough" + # check that we can get the logs with passthrough when we run in a systemd unit + run_podman logs test_pod-$name + assert "$output" == "$name stdout +$name stderr" "logs work with passthrough" done + # we cannot assume the ordering between a b, this depends on timing and would flake in CI + # use --names so we do not have to get the ID + run_podman pod logs --names test_pod + assert "$output" =~ ".*^test_pod-a a stdout.*" "logs from container a shown" + assert "$output" =~ ".*^test_pod-b b stdout.*" "logs from container b shown" + # Add a simple `auto-update --dry-run` test here to avoid too much redundancy # with 255-auto-update.bats run_podman auto-update --dry-run --format "{{.Unit}},{{.Container}},{{.Image}},{{.Updated}},{{.Policy}}" diff --git a/test/system/252-quadlet.bats b/test/system/252-quadlet.bats index 12551c73b0..03b6497d7d 100644 --- a/test/system/252-quadlet.bats +++ b/test/system/252-quadlet.bats @@ -141,7 +141,7 @@ function remove_secret() { cat > $quadlet_file <