From 8ab00424bc1e458534e59e87f5073e199904a63e Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 14 Mar 2023 17:35:17 +0100 Subject: [PATCH 1/9] podman-mac-helper: exit 1 on error We should return a proper exit code to signal the failure. [NO NEW TESTS NEEDED] We do have any tests on macOS. Fixes #17785 Signed-off-by: Paul Holzinger --- cmd/podman-mac-helper/main.go | 1 + 1 file changed, 1 insertion(+) diff --git a/cmd/podman-mac-helper/main.go b/cmd/podman-mac-helper/main.go index ef57341bcd..d3e5310929 100644 --- a/cmd/podman-mac-helper/main.go +++ b/cmd/podman-mac-helper/main.go @@ -53,6 +53,7 @@ func main() { if err := rootCmd.Execute(); err != nil { fmt.Fprintf(os.Stderr, "Error: %s\n", err.Error()) + os.Exit(1) } } From bd65bf2ed150f9ce9644cc252ab82f35a0c87885 Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 14 Mar 2023 14:15:46 +0100 Subject: [PATCH 2/9] system service --log-level=trace: support hijack When the service is running with trace log level it wraps the `http.ResponseWriter` to log extra information. The problem is that the new type does not keep all the functions from the embedded type. Instead we have to implement them ourselves, however only Write() was implemented. Thus `Hijack()`could not be called on the writer. To prevent these issues we would implement all the interfaces that the inner type supports (Header, WriteHeader, Flush, Hijack). Fixes #17749 Signed-off-by: Paul Holzinger --- pkg/api/server/handler_logging.go | 25 +++++++++++++++++++++++++ test/system/251-system-service.bats | 19 +++++++++++++++++++ 2 files changed, 44 insertions(+) diff --git a/pkg/api/server/handler_logging.go b/pkg/api/server/handler_logging.go index 38ee8321c1..2f62a28fd3 100644 --- a/pkg/api/server/handler_logging.go +++ b/pkg/api/server/handler_logging.go @@ -1,7 +1,10 @@ package server import ( + "bufio" + "errors" "io" + "net" "net/http" "time" @@ -33,6 +36,28 @@ func (l responseWriter) Write(b []byte) (int, error) { return l.ResponseWriter.Write(b) } +func (l responseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) { + if wrapped, ok := l.ResponseWriter.(http.Hijacker); ok { + return wrapped.Hijack() + } + + return nil, nil, errors.New("ResponseWriter does not support hijacking") +} + +func (l responseWriter) Header() http.Header { + return l.ResponseWriter.Header() +} + +func (l responseWriter) WriteHeader(statusCode int) { + l.ResponseWriter.WriteHeader(statusCode) +} + +func (l responseWriter) Flush() { + if wrapped, ok := l.ResponseWriter.(http.Flusher); ok { + wrapped.Flush() + } +} + func loggingHandler() mux.MiddlewareFunc { return func(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { diff --git a/test/system/251-system-service.bats b/test/system/251-system-service.bats index b4bc6ceaad..7a772e2ef4 100644 --- a/test/system/251-system-service.bats +++ b/test/system/251-system-service.bats @@ -69,3 +69,22 @@ function teardown() { systemctl stop $SERVICE_NAME } + +# Regression test for https://github.com/containers/podman/issues/17749 +@test "podman-system-service --log-level=trace should be able to hijack" { + skip_if_remote "podman system service unavailable over remote" + + port=$(random_free_port) + URL=tcp://127.0.0.1:$port + + systemd-run --unit=$SERVICE_NAME $PODMAN --log-level=trace system service $URL --time=0 + wait_for_port 127.0.0.1 $port + + out=o-$(random_string) + cname=c-$(random_string) + run_podman --url $URL run --name $cname $IMAGE echo $out + assert "$output" == "$out" "service is able to hijack and stream output back" + + run_podman --url $URL rm $cname + systemctl stop $SERVICE_NAME +} From 1a3a5594a06cf2c7e589ad38469929789043969b Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 28 Feb 2023 13:24:23 +0100 Subject: [PATCH 3/9] fix "podman logs --since --follow" flake The test should make sure the logs --follow call will log entries that are created in the future when --since is used and doe not include the container start event. However it seems the timing is to tight. I think it was possible that CI logged the line before the logs call was made, thus it is missing because --since excluded it. I cannot reproduce so I am not 100% on this but we can reopen the issue if it still happens. Fixes #17616 Signed-off-by: Paul Holzinger --- test/system/035-logs.bats | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/system/035-logs.bats b/test/system/035-logs.bats index 8f378054af..e0ee3ed14d 100644 --- a/test/system/035-logs.bats +++ b/test/system/035-logs.bats @@ -319,14 +319,14 @@ function _log_test_follow_since() { # Now do the same with a running container to check #16950. run_podman ${events_backend} run --log-driver=$driver --name $cname -d $IMAGE \ - sh -c "sleep 0.5; while :; do echo $content && sleep 3; done" + sh -c "sleep 1; while :; do echo $content && sleep 5; done" # sleep is required to make sure the podman event backend no longer sees the start event in the log # This value must be greater or equal than the the value given in --since below sleep 0.2 # Make sure podman logs actually follows by giving a low timeout and check that the command times out - PODMAN_TIMEOUT=2 run_podman 124 ${events_backend} logs --since 0.1s -f $cname + PODMAN_TIMEOUT=3 run_podman 124 ${events_backend} logs --since 0.1s -f $cname assert "$output" =~ "^$content timeout: sending signal TERM to command.*" "logs --since -f on running container works" From d737a815a916946496409c9ccd1a96ac70ac16c2 Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 21 Feb 2023 16:55:27 +0100 Subject: [PATCH 4/9] compat API: network create return 409 for duplicate If the name already exists and CheckDuplicate is set we need to return 409, if CheckDuplicate is not set we return the network without error. Fixes #17585 Signed-off-by: Paul Holzinger --- pkg/api/handlers/compat/networks.go | 11 +++++++++-- test/apiv2/35-networks.at | 3 +++ 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/pkg/api/handlers/compat/networks.go b/pkg/api/handlers/compat/networks.go index 704af4b0e4..bb9cda8875 100644 --- a/pkg/api/handlers/compat/networks.go +++ b/pkg/api/handlers/compat/networks.go @@ -277,10 +277,17 @@ func CreateNetwork(w http.ResponseWriter, r *http.Request) { // FIXME can we use the IPAM driver and options? } + opts := nettypes.NetworkCreateOptions{ + IgnoreIfExists: !networkCreate.CheckDuplicate, + } ic := abi.ContainerEngine{Libpod: runtime} - newNetwork, err := ic.NetworkCreate(r.Context(), network, nil) + newNetwork, err := ic.NetworkCreate(r.Context(), network, &opts) if err != nil { - utils.InternalServerError(w, err) + if errors.Is(err, nettypes.ErrNetworkExists) { + utils.Error(w, http.StatusConflict, err) + } else { + utils.InternalServerError(w, err) + } return } diff --git a/test/apiv2/35-networks.at b/test/apiv2/35-networks.at index 07ba45efb2..dfa5b583b7 100644 --- a/test/apiv2/35-networks.at +++ b/test/apiv2/35-networks.at @@ -104,6 +104,9 @@ t GET networks/podman 200 \ # network create docker t POST networks/create Name=net3\ IPAM='{"Config":[]}' 201 +# create with same name should not error unless CheckDuplicate is set +t POST networks/create Name=net3 201 +t POST networks/create Name=net3\ CheckDuplicate=true 409 # network delete docker t DELETE networks/net3 204 From 6b19e1437c7cda02d8e6e9751f815124df363d47 Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Mon, 20 Feb 2023 14:36:34 +0100 Subject: [PATCH 5/9] netavark: only use aardvark ip as nameserver Since commit 06241077cc we use the aardvark per container dns functionality. This means we should only have the aardvark ip in resolv.conf otherwise the client resolver could skip aardvark, thus ignoring the special dns option for this container. Fixes #17499 Signed-off-by: Paul Holzinger --- libpod/container_internal_common.go | 6 +++++- test/system/500-networking.bats | 2 +- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/libpod/container_internal_common.go b/libpod/container_internal_common.go index f603c51dcf..3a0e46be7c 100644 --- a/libpod/container_internal_common.go +++ b/libpod/container_internal_common.go @@ -2012,7 +2012,11 @@ func (c *Container) generateResolvConf() error { // If the user provided dns, it trumps all; then dns masq; then resolv.conf keepHostServers := false if len(nameservers) == 0 { - keepHostServers = true + // when no network name servers or not netavark use host servers + // for aardvark dns we only want our single server in there + if len(networkNameServers) == 0 || networkBackend != string(types.Netavark) { + keepHostServers = true + } // first add the nameservers from the networks status nameservers = networkNameServers // slirp4netns has a built in DNS forwarder. diff --git a/test/system/500-networking.bats b/test/system/500-networking.bats index 3b797be089..29c28173d3 100644 --- a/test/system/500-networking.bats +++ b/test/system/500-networking.bats @@ -663,7 +663,7 @@ EOF is "$output" "search example.com.*" "correct search domain" local store=$output if is_netavark; then - is "$store" ".*nameserver $subnet.1.*" "integrated dns nameserver is set" + assert "$store" == "search example.com${nl}nameserver $subnet.1" "only integrated dns nameserver is set" else is "$store" ".*nameserver 1.1.1.1${nl}nameserver $searchIP${nl}nameserver 1.0.0.1${nl}nameserver 8.8.8.8" "nameserver order is correct" fi From c5fa9c50f394b1f3bdb1ac7a8b955bff85c9dc1b Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Wed, 15 Feb 2023 21:00:26 +0100 Subject: [PATCH 6/9] journald: remove initializeJournal() This was added as hack in commit 6b06e9b77c because the journald logs code was not able to handle an empty journal. But since commit 767947ab88 this is no longer the case, we correctly use the sd_journal API and know when the journal is empty. Therefore we no longer need this hack and it should be removed because it just adds overhead and an empty journal entry for no good reason. [NO NEW TESTS NEEDED] Signed-off-by: Paul Holzinger --- libpod/container_log_linux.go | 16 ---------------- libpod/container_log_unsupported.go | 4 ---- libpod/runtime_ctr.go | 6 +----- 3 files changed, 1 insertion(+), 25 deletions(-) diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go index de5a66dee1..dc305fabfd 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -15,7 +15,6 @@ import ( "github.com/containers/podman/v4/libpod/events" "github.com/containers/podman/v4/libpod/logs" "github.com/containers/podman/v4/pkg/rootless" - "github.com/coreos/go-systemd/v22/journal" "github.com/coreos/go-systemd/v22/sdjournal" "github.com/sirupsen/logrus" ) @@ -32,21 +31,6 @@ func init() { logDrivers = append(logDrivers, define.JournaldLogging) } -// initializeJournal will write an empty string to the journal -// when a journal is created. This solves a problem when people -// attempt to read logs from a container that has never had stdout/stderr -func (c *Container) initializeJournal(ctx context.Context) error { - m := make(map[string]string) - m["SYSLOG_IDENTIFIER"] = "podman" - m["PODMAN_ID"] = c.ID() - history := events.History - m["PODMAN_EVENT"] = history.String() - container := events.Container - m["PODMAN_TYPE"] = container.String() - m["PODMAN_TIME"] = time.Now().Format(time.RFC3339Nano) - return journal.Send("", journal.PriInfo, m) -} - func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOptions, logChannel chan *logs.LogLine, colorID int64) error { // We need the container's events in the same journal to guarantee // consistency, see #10323. diff --git a/libpod/container_log_unsupported.go b/libpod/container_log_unsupported.go index bb74a810d5..cdce820b4f 100644 --- a/libpod/container_log_unsupported.go +++ b/libpod/container_log_unsupported.go @@ -14,7 +14,3 @@ import ( func (c *Container) readFromJournal(_ context.Context, _ *logs.LogOptions, _ chan *logs.LogLine, colorID int64) error { return fmt.Errorf("journald logging only enabled with systemd on linux: %w", define.ErrOSNotSupported) } - -func (c *Container) initializeJournal(ctx context.Context) error { - return fmt.Errorf("journald logging only enabled with systemd on linux: %w", define.ErrOSNotSupported) -} diff --git a/libpod/runtime_ctr.go b/libpod/runtime_ctr.go index 33e31c63e3..b9e9a27b9e 100644 --- a/libpod/runtime_ctr.go +++ b/libpod/runtime_ctr.go @@ -541,12 +541,8 @@ func (r *Runtime) setupContainer(ctx context.Context, ctr *Container) (_ *Contai } switch ctr.config.LogDriver { - case define.NoLogging, define.PassthroughLogging: + case define.NoLogging, define.PassthroughLogging, define.JournaldLogging: break - case define.JournaldLogging: - if err := ctr.initializeJournal(ctx); err != nil { - return nil, fmt.Errorf("failed to initialize journal: %w", err) - } default: if ctr.config.LogPath == "" { ctr.config.LogPath = filepath.Join(ctr.config.StaticDir, "ctr.log") From 54b070ee6aadab48df444237fdc19c9a55e512e8 Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 14 Feb 2023 15:59:10 +0100 Subject: [PATCH 7/9] podman logs: read journald with passthrough The passthrough driver is designed for use in systemd units. By default we can expect systemd to log the output on journald unless the unit sets differen StandardOutput/StandardError settings. At the moment podman logs just errors out when the passthrough driver is used. With this change we will read the journald for the unit messages. The logic is actually very similar to the existing one, we just need to change the filter. We now filter by SYSTEMD_UNIT wich equals to the contianer cgroup, this allows us the actually filter on a per contianer basis even when multiple contianers are started in the same unit, i.e. via podman-kube@.service. The only difference a user will see is that journald will merge stdout/err into one stream so we loose the separation there. Signed-off-by: Paul Holzinger --- libpod/container_log.go | 7 ++++++- libpod/container_log_linux.go | 27 +++++++++++++++++++++++---- libpod/container_log_unsupported.go | 2 +- test/system/250-systemd.bats | 12 ++++++++++-- 4 files changed, 40 insertions(+), 8 deletions(-) diff --git a/libpod/container_log.go b/libpod/container_log.go index e33ede5dd1..680adfd389 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 _, ok := c.config.Labels[systemdDefine.EnvVariable]; ok { + return c.readFromJournal(ctx, options, logChannel, colorID, true) + } 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, false) 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..1e4e5c198a 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, isPassthrough bool) 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,28 @@ 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 isPassthrough { + // 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" + } + // FIXME: It looks like it is hardcoded to libpod-ID.scope but I am not + // sure were we set this with all the different cgroup modes??? + match = sdjournal.Match{Field: unitTypeName, Value: "libpod-" + c.ID() + ".scope"} + 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) } diff --git a/libpod/container_log_unsupported.go b/libpod/container_log_unsupported.go index cdce820b4f..736378a6b7 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, _ bool) error { return fmt.Errorf("journald logging only enabled with systemd on linux: %w", define.ErrOSNotSupported) } diff --git a/test/system/250-systemd.bats b/test/system/250-systemd.bats index d928596890..1409c1b317 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,6 +422,10 @@ 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 # Add a simple `auto-update --dry-run` test here to avoid too much redundancy From a0fad9f8ca6a63976b47df0a4ac0675c9da5d124 Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Tue, 14 Feb 2023 16:39:14 +0100 Subject: [PATCH 8/9] journald logs: simplify entry parsing It makes little sense to create a log line string from the entry just to parse it again into a LogLine. We have the typed fields so we can assemble the logLine direclty, this makes things simpler and more efficient. Also entries from the passthrough driver do not use the CONTAINER_ID_FULL field, instead we can just access c.ID() directly. Signed-off-by: Paul Holzinger --- libpod/container_log_linux.go | 94 +++++++++-------------------------- libpod/logs/log.go | 30 ----------- test/system/250-systemd.bats | 6 +++ 3 files changed, 29 insertions(+), 101 deletions(-) diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go index 1e4e5c198a..7d1e360b2b 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -181,26 +181,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() } @@ -215,76 +206,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 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 journalToLogLine(entry *sdjournal.JournalEntry) (*logs.LogLine, error) { + line := &logs.LogLine{} -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/logs/log.go b/libpod/logs/log.go index 43da8d904d..664e467067 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 considerred 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 1409c1b317..837d3a6192 100644 --- a/test/system/250-systemd.bats +++ b/test/system/250-systemd.bats @@ -428,6 +428,12 @@ EOF $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}}" From 9c0d2dc2f0cc141832917fad0b2fd05f1954caed Mon Sep 17 00:00:00 2001 From: Paul Holzinger Date: Wed, 15 Feb 2023 19:23:58 +0100 Subject: [PATCH 9/9] podman logs passthrough driver support --cgroups=split When run with --cgroups=split mode (e.g. quadlet) we do not use the a separate cgroup for the container and just run in the unit cgroup. When we filter logs we thus must match the unit name. Added a small test to the quadlet test to make sure it will work. Signed-off-by: Paul Holzinger --- libpod/container_log.go | 6 +++--- libpod/container_log_linux.go | 17 ++++++++++++----- libpod/container_log_unsupported.go | 2 +- test/system/252-quadlet.bats | 6 +++++- 4 files changed, 21 insertions(+), 10 deletions(-) diff --git a/libpod/container_log.go b/libpod/container_log.go index 680adfd389..3ae0c70e84 100644 --- a/libpod/container_log.go +++ b/libpod/container_log.go @@ -38,14 +38,14 @@ func (c *Container) ReadLog(ctx context.Context, options *logs.LogOptions, logCh switch c.LogDriver() { case define.PassthroughLogging: // if running under systemd fallback to a more native journald reading - if _, ok := c.config.Labels[systemdDefine.EnvVariable]; ok { - return c.readFromJournal(ctx, options, logChannel, colorID, true) + 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, false) + 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 7d1e360b2b..a708ad46da 100644 --- a/libpod/container_log_linux.go +++ b/libpod/container_log_linux.go @@ -32,7 +32,7 @@ func init() { } func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOptions, - logChannel chan *logs.LogLine, colorID int64, isPassthrough bool) error { + 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" { @@ -69,7 +69,7 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption return fmt.Errorf("adding filter disjunction to journald logger: %w", err) } - if isPassthrough { + 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. @@ -77,9 +77,16 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption if rootless.IsRootless() { unitTypeName = "_SYSTEMD_USER_UNIT" } - // FIXME: It looks like it is hardcoded to libpod-ID.scope but I am not - // sure were we set this with all the different cgroup modes??? - match = sdjournal.Match{Field: unitTypeName, Value: "libpod-" + c.ID() + ".scope"} + // 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) } diff --git a/libpod/container_log_unsupported.go b/libpod/container_log_unsupported.go index 736378a6b7..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, _ int64, _ bool) 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/test/system/252-quadlet.bats b/test/system/252-quadlet.bats index 1dc54a1bc4..d85f30057a 100644 --- a/test/system/252-quadlet.bats +++ b/test/system/252-quadlet.bats @@ -117,7 +117,7 @@ function service_cleanup() { cat > $quadlet_file <