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

logs: k8s-file: fix race #10600

Merged
merged 1 commit into from
Jun 8, 2021

Conversation

vrothberg
Copy link
Member

@vrothberg vrothberg commented Jun 8, 2021

Fix a race in the k8s-file logs driver. When "following" the logs,
Podman will print the container's logs until the end. Previously,
Podman logged until the state transitioned into something non-running
which opened up a race with the container still running, possibly in
the "stopping" state.

To fix the race, log until we've seen the wait event for the specific
container. In that case, conmon will have finished writing all logs to
the file, and Podman will read it until EOF.

Further tweak the integration tests for testing logs -f on a running
container. Previously, the test only checked for one of two lines
stating that there was a race. Indeed the race was in using run --rm
where a log file may be removed before we could fully read it.

Fixes: #10596
Signed-off-by: Valentin Rothberg [email protected]

@openshift-ci openshift-ci bot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jun 8, 2021
Copy link
Member

@Luap99 Luap99 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think this works.

Comment on lines 113 to 123
eventChannel := make(chan *events.Event)
errorChannel := make(chan error)
eventOptions := events.ReadOptions{
EventChannel: eventChannel,
Filters: []string{"event=died", "container=" + c.ID()},
FromStart: true,
Stream: true,
}
go func() {
errorChannel <- c.runtime.Events(ctx, eventOptions)
}()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't understand this. You never read the event channel and this will just hang forever and never exit.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Absolutely, thanks! Took a phone call and thought I added the remaining bits :^)

@Luap99
Copy link
Member

Luap99 commented Jun 8, 2021

Also take a look at the following for a possible test:

// TODO: we should actually check for two podman lines,
// but as of 2020-06-17 there's a race condition in which
// 'logs -f' may not catch all output from a container
Expect(results.OutputToString()).To(ContainSubstring("podman"))
// Container should now be terminatING or terminatED, but we
// have no guarantee of which: 'logs -f' does not necessarily
// wait for cleanup. Run 'inspect' and accept either state.

@vrothberg
Copy link
Member Author

Also take a look at the following for a possible test:

// TODO: we should actually check for two podman lines,
// but as of 2020-06-17 there's a race condition in which
// 'logs -f' may not catch all output from a container
Expect(results.OutputToString()).To(ContainSubstring("podman"))
// Container should now be terminatING or terminatED, but we
// have no guarantee of which: 'logs -f' does not necessarily
// wait for cleanup. Run 'inspect' and accept either state.

Good catch. With the recent fixes in the journald logger and this PR, we should be good to go. I'll take a look.

Fix a race in the k8s-file logs driver.  When "following" the logs,
Podman will print the container's logs until the end.  Previously,
Podman logged until the state transitioned into something non-running
which opened up a race with the container still running, possibly in
the "stopping" state.

To fix the race, log until we've seen the wait event for the specific
container.  In that case, conmon will have finished writing all logs to
the file, and Podman will read it until EOF.

Further tweak the integration tests for testing `logs -f` on a  running
container.  Previously, the test only checked for one of two lines
stating that there was a race.  Indeed the race was in using `run --rm`
where a log file may be removed before we could fully read it.

Fixes: containers#10596
Signed-off-by: Valentin Rothberg <[email protected]>
Copy link
Member

@Luap99 Luap99 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@openshift-ci
Copy link
Contributor

openshift-ci bot commented Jun 8, 2021

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: Luap99, vrothberg

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@rhatdan
Copy link
Member

rhatdan commented Jun 8, 2021

/lgtm
/hold

@openshift-ci openshift-ci bot added do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. lgtm Indicates that a PR is ready to be merged. labels Jun 8, 2021
@rhatdan
Copy link
Member

rhatdan commented Jun 8, 2021

/hold cancel

@openshift-ci openshift-ci bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Jun 8, 2021
@openshift-merge-robot openshift-merge-robot merged commit b5e5730 into containers:master Jun 8, 2021
@maybe-sybr
Copy link
Contributor

@mheon I've also hit the issue introduced by 84b55ee in 3.2.1 (picked as c3f6ef6) and would appreciate if you could include this patch in 3.2.2 :)

@vrothberg vrothberg deleted the fix-10596 branch June 23, 2021 07:41
@vrothberg
Copy link
Member Author

@mheon I've also hit the issue introduced by 84b55ee in 3.2.1 (picked as c3f6ef6) and would appreciate if you could include this patch in 3.2.2 :)

Roger :) I backported a fix for the fix yesterday to the v3.2 branch, so it'll be fixed in 3.2.2.

@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 Sep 23, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 23, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
approved Indicates a PR has been approved by an approver from all required OWNERS files. lgtm Indicates that a PR is ready to be merged. 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 this pull request may close these issues.

podman logs -f ends early
5 participants