Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

podman events duplicates events after rotation #17665

Closed
mgjm opened this issue Feb 28, 2023 · 7 comments · Fixed by #17771
Closed

podman events duplicates events after rotation #17665

mgjm opened this issue Feb 28, 2023 · 7 comments · Fixed by #17771
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Comments

@mgjm
Copy link

mgjm commented Feb 28, 2023

Issue Description

When the libpod events file gets rotated in libpod/events/logfile.go, the log file gets truncated by discarding the older half of all events.

But the podman events command reads all events again after a log rotation has occurred.

Therefore, the newer half of the logs (which is not discarded) is printed again.

Steps to reproduce the issue

Steps to reproduce the issue

  1. Set events_logfile_max_size = "4k" in the [engine] section in the containers.conf file
  2. Watch the events with podman events
  3. In another terminal: Generate some events (e.g. podman run --rm hello-world)

Describe the results you received

After the second or third podman run invocation, the file gets rotated and some events, which have already been printed, get printed again.

Describe the results you expected

Each event should be printed exactly once. Even after rotating the events file.

podman info output

podman version 4.3.1, alpine 3.17, x86_64

Podman in a container

No

Privileged Or Rootless

None

Upstream Latest Release

No

Additional environment details

No response

Additional information

No response

@mgjm mgjm added the kind/bug Categorizes issue or PR as related to a bug. label Feb 28, 2023
@Luap99
Copy link
Member

Luap99 commented Mar 1, 2023

@vrothberg PTAL

@vrothberg
Copy link
Member

I started working on it and found a solution. Writing tests at this moment.

@mgjm
Copy link
Author

mgjm commented Mar 3, 2023

@vrothberg Awesome, I know it's still a WIP, but just a heads up: the inode number doesn't have to change, if the file isn't renamed, there's os.Create as a fallback, so it just truncates the existing file.

@vrothberg
Copy link
Member

@vrothberg Awesome, I know it's still a WIP, but just a heads up: the inode number doesn't have to change, if the file isn't renamed, there's os.Create as a fallback, so it just truncates the existing file.

Thanks for checking, @mgjm!

What's happening during rotation is that a new tempfile is created with the rotated content. Then it's getting renamed to the previous path.

After that, the inode number of the previous path should be changed, shouldn't it?

@vrothberg
Copy link
Member

@mgjm
Copy link
Author

mgjm commented Mar 3, 2023

That's the normal operation, but if the temp file is created in a different file system there is a fallback to use os.Create:
libpod/events/logfile.go#L329-L353

@vrothberg
Copy link
Member

vrothberg commented Mar 3, 2023

Nice catch, thank you! Note that I will be largely out of office next week; just in case you wonder about the progress.

vrothberg added a commit to vrothberg/libpod that referenced this issue Mar 15, 2023
When streaming events, prevent returning duplicates after a log rotation
by marking a beginning and an end for rotated events.  Before starting to
stream, get a timestamp while holding the event lock.  The timestamp
allows for detecting whether a rotation event happened while reading the
log file and to skip all events between the begin and end rotation
event.

In an ideal scenario, we could detect rotated events by enforcing a
chronological order when reading and skip those detected to not be more
recent than the last read event.  However, events are not always
_written_ in chronological order.  While this can be changed, existing
event files could not be read correctly anymore.

Fixes: containers#17665
Signed-off-by: Valentin Rothberg <[email protected]>
@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Aug 30, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Aug 30, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants