containers
/
automation-tests
mirror of https://github.com/containers/automation-tests.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

journald: podman logs --until --follow exit after time 

When you use podman logs with --until and --follow it should exit after
the requested until time and not keep hanging forever.

To make this work I reworked the code to use the better journald event
reading code for logs as well. this correctly uses the sd_journal API
without having to compare the cursors to find the EOF.

The same problems exists for the k8s-file driver, I will fix this in the
next commit.

Signed-off-by: Paul Holzinger <pholzing@redhat.com>
This commit is contained in:
Paul Holzinger 2023-01-04 18:52:42 +01:00
parent c674b3dd83
commit 767947ab88
No known key found for this signature in database
GPG Key ID: EB145DD938A3CAF2
3 changed files with 47 additions and 81 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

87
libpod/container_log_linux.go
View File

@ -90,20 +90,6 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption
return err
}
}
// API requires Next() immediately after SeekHead().
if _, err := journal.Next(); err != nil {
return fmt.Errorf("next journal: %w", err)
}
// API requires a next|prev before getting a cursor.
if _, err := journal.Previous(); err != nil {
return fmt.Errorf("previous journal: %w", err)
}
// Note that the initial cursor may not yet be ready, so we'll do an
// exponential backoff.
var cursor string
var cursorError error
c.lock.Lock()
if err := c.syncContainer(); err != nil {
@ -116,22 +102,6 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption
containerCouldBeLogging := c.ensureState(define.ContainerStateRunning, define.ContainerStateStopping)
c.lock.Unlock()
for i := 1; i <= 3; i++ {
cursor, cursorError = journal.GetCursor()
hundreds := 1
for j := 1; j < i; j++ {
hundreds *= 2
}
if cursorError != nil {
time.Sleep(time.Duration(hundreds*100) * time.Millisecond)
continue
}
break
}
if cursorError != nil {
return fmt.Errorf("initial journal cursor: %w", cursorError)
}
options.WaitGroup.Add(1)
go func() {
defer func() {
@ -160,59 +130,20 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption
tailQueue = nil
doTail = false
}
lastReadCursor := ""
for {
select {
case <-ctx.Done():
// Remote client may have closed/lost the connection.
return
default:
// Fallthrough
}
if lastReadCursor != "" {
// Advance to next entry if we read this one.
if _, err := journal.Next(); err != nil {
logrus.Errorf("Failed to move journal cursor to next entry: %v", err)
return
}
}
// Fetch the location of this entry, presumably either
// the one that follows the last one we read, or that
// same last one, if there is no next entry (yet).
cursor, err = journal.GetCursor()
if err != nil {
logrus.Errorf("Failed to get journal cursor: %v", err)
return
}
// Hit the end of the journal (so far?).
if cursor == lastReadCursor {
if doTail {
doTailFunc()
}
// Unless we follow, quit.
if !options.Follow || !containerCouldBeLogging {
return
}
// journal.Wait() is blocking, this would cause the goroutine to hang forever
// if no more journal entries are generated and thus if the client
// has closed the connection in the meantime to leak memory.
// Waiting only 5 seconds makes sure we can check if the client closed in the
// meantime at least every 5 seconds.
journal.Wait(5 * time.Second)
continue
}
lastReadCursor = cursor
// Read the journal entry.
entry, err := journal.GetEntry()
entry, err := events.GetNextEntry(ctx, journal, !doTail && options.Follow && containerCouldBeLogging, options.Until)
if err != nil {
logrus.Errorf("Failed to get journal entry: %v", err)
return
}
// entry nil == EOF in journal
if entry == nil {
if doTail {
doTailFunc()
continue
}
return
}
entryTime := time.Unix(0, int64(entry.RealtimeTimestamp)*int64(time.Microsecond))
if (entryTime.Before(options.Since) && !options.Since.IsZero()) || (entryTime.After(options.Until) && !options.Until.IsZero()) {

6
libpod/events/journal_linux.go
View File

@ -133,7 +133,7 @@ func (e EventJournalD) Read(ctx context.Context, options ReadOptions) error {
}
for {
entry, err := getNextEntry(ctx, j, options.Stream, untilTime)
entry, err := GetNextEntry(ctx, j, options.Stream, untilTime)
if err != nil {
return err
}
@ -219,10 +219,10 @@ func (e EventJournalD) String() string {
return Journald.String()
}
// getNextEntry returns the next entry in the journal. If the end of the
// GetNextEntry returns the next entry in the journal. If the end of the
// journal is reached and stream is not set or the current time is after
// the until time this function return nil,nil.
func getNextEntry(ctx context.Context, j *sdjournal.Journal, stream bool, untilTime time.Time) (*sdjournal.JournalEntry, error) {
func GetNextEntry(ctx context.Context, j *sdjournal.Journal, stream bool, untilTime time.Time) (*sdjournal.JournalEntry, error) {
for {
select {
case <-ctx.Done():

35
test/system/035-logs.bats
View File

@ -344,4 +344,39 @@ timeout: sending signal TERM to command.*" "logs --since -f on running container
_log_test_follow_since journald
}
function _log_test_follow_until() {
local driver=$1
cname=$(random_string)
content=$(random_string)
local events_backend=$(_additional_events_backend $driver)
if [[ -n "${events_backend}" ]]; then
skip_if_remote "remote does not support --events-backend"
fi
run_podman ${events_backend} run --log-driver=$driver --name $cname -d $IMAGE \
sh -c "while :; do echo $content && sleep 2; done"
t0=$SECONDS
# The logs command should exit after the until time even when follow is set
PODMAN_TIMEOUT=10 run_podman ${events_backend} logs --until 3s -f $cname
t1=$SECONDS
# The delta should be 3 but because it could be a bit longer on a slow system such as CI we also accept 4.
delta_t=$(( $t1 - $t0 ))
assert $delta_t -gt 2 "podman logs --until: exited too early!"
assert $delta_t -lt 5 "podman logs --until: exited too late!"
assert "$output" == "$content
$content" "logs --until -f on running container works"
run_podman ${events_backend} rm -t 0 -f $cname
}
@test "podman logs - --until --follow journald" {
# We can't use journald on RHEL as rootless: rhbz#1895105
skip_if_journald_unavailable
_log_test_follow_until journald
}
# vim: filetype=sh