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

fix(inputs.tail): Retry opening file after permission denied #14357

Merged
merged 3 commits into from
Nov 30, 2023

Conversation

ericmiller-wpengine
Copy link
Contributor

@ericmiller-wpengine ericmiller-wpengine commented Nov 27, 2023

Required for all PRs

resolves #13154

Gather() calls tailNewFiles() and creates a tailer for any that are not in the map of tailers already. Deleting the old one from the map on "permission denied" was sufficient to get the plugin to reopen the file.

a lightly redacted section of logs. in another terminal i forced a logrotate that left the log file with the wrong permissions (0600) and then immediately chmod'ed to 0644, easier to catch than the race condition.

2023-11-27T21:58:37Z I! Loaded inputs: conntrack disk filestat http (3x) http_listener_v2 httpjson memcached mysql net_response (5x) nginx (2x) prometheus tail (3x)
2023-11-27T21:58:37Z I! Loaded aggregators:
2023-11-27T21:58:37Z I! Loaded processors: regex rename (2x)
2023-11-27T21:58:37Z I! Loaded secretstores:
2023-11-27T21:58:37Z I! Loaded outputs: file
2023-11-27T21:58:37Z I! Tags enabled: <some tags were here>
2023-11-27T21:58:37Z W! Deprecated inputs: 1 and 0 options
2023-11-27T21:58:37Z I! [agent] Config: Interval:30s, Quiet:false, Hostname:"fake", Flush Interval:1m0s
2023-11-27T21:58:37Z I! [inputs.prometheus] Using the label selector:  and field selector:
2023-11-27T21:58:37Z I! [inputs.http_listener_v2] Listening on [::]:8185
{"fields":{"account_name":"foobar",<more fields omitted>},"name":"nginxlog","tags":{"datacenter":"self-contained",<more tags omitted>},"timestamp":1701122545}
2023-11-27T22:03:31Z E! [inputs.tail] Tailing "/.../access.json": Unable to open file /.../access.json: open /.../access.json: permission denied
2023-11-27T22:03:31Z E! [inputs.tail] Deleting tailer for "/.../access.json"
{"fields":{"account_name":"foobar",<more fields omitted>},"name":"nginxlog","tags":{"datacenter":"self-contained",<more tags omitted>},"timestamp":1701122692}

@telegraf-tiger
Copy link
Contributor

Thanks so much for the pull request!
🤝 ✒️ Just a reminder that the CLA has not yet been signed, and we'll need it before merging. Please sign the CLA when you get a chance, then post a comment here saying !signed-cla

@telegraf-tiger telegraf-tiger bot added area/tail feat Improvement on an existing feature such as adding a new setting/mode to an existing plugin plugin/input 1. Request for new input plugins 2. Issues/PRs that are related to input plugins labels Nov 27, 2023
@ericmiller-wpengine
Copy link
Contributor Author

!signed-cla

@ericmiller-wpengine ericmiller-wpengine changed the title feat(inputs.tail): retry opening file after permission denied feat(inputs.tail): Retry opening file after permission denied Nov 27, 2023
@ericmiller-wpengine ericmiller-wpengine changed the title feat(inputs.tail): Retry opening file after permission denied fix(inputs.tail): Retry opening file after permission denied Nov 27, 2023
@ericmiller-wpengine
Copy link
Contributor Author

Out of a concern the offsets would be affected and cause the wrong behavior, I did a further test:

  • with telegraf tailing a file, appended a line, saw it printed by outputs.file
  • forced logrotate with config that created new log file with 0600 perms, saw "permission denied"
  • appended 3 lines to new empty log file
  • chmod 0644 the log file, saw telegraf print all 3 new lines.

@Hipska
Copy link
Contributor

Hipska commented Nov 28, 2023

What happens in the scenario the file becomes inaccessible, then few lines added, then accessible again?

@ericmiller-wpengine
Copy link
Contributor Author

If the tail plugin has my log open, changing the permissions on the already-open file to something that would cause a problem for telegraf opening it later does not affect telegraf immediately. It already has the file open, and reads new lines written to the file.

@Hipska Hipska added the ready for final review This pull request has been reviewed and/or tested by multiple users and is ready for a final review. label Nov 28, 2023
Copy link
Member

@srebhan srebhan left a comment

Choose a reason for hiding this comment

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

Thanks for the PR @ericmiller-wpengine! One question and one suggestion from my side...

plugins/inputs/tail/tail.go Show resolved Hide resolved
@@ -236,6 +236,10 @@ func (t *Tail) tailNewFiles(fromBeginning bool) error {

if err := tailer.Err(); err != nil {
t.Log.Errorf("Tailing %q: %s", tailer.Filename, err.Error())
if strings.HasSuffix(err.Error(), "permission denied") {
t.Log.Errorf("Deleting tailer for %q", tailer.Filename)
Copy link
Member

Choose a reason for hiding this comment

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

How about adding some details like

Suggested change
t.Log.Errorf("Deleting tailer for %q", tailer.Filename)
t.Log.Errorf("Deleting tailer for %q: %v", tailer.Filename, err)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I moved the previous log message into an else at the same time, hopefully this is adequately idiomatic.

@srebhan srebhan self-assigned this Nov 30, 2023
@srebhan srebhan removed the ready for final review This pull request has been reviewed and/or tested by multiple users and is ready for a final review. label Nov 30, 2023
@ericmiller-wpengine
Copy link
Contributor Author

Now that I pushed again, there is a failed check but the failure looks like its in linting a README I did not touch. I looked but don't see somewhere I can trigger it again without another push.

Also some more checks failed after that, also in unrelated-looking ways.

Copy link
Member

@srebhan srebhan left a comment

Choose a reason for hiding this comment

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

Thanks for tackling this issue @ericmiller-wpengine! Very much appreciated!

@srebhan srebhan added the ready for final review This pull request has been reviewed and/or tested by multiple users and is ready for a final review. label Nov 30, 2023
@srebhan srebhan assigned powersj and unassigned srebhan Nov 30, 2023
@Hipska
Copy link
Contributor

Hipska commented Nov 30, 2023

@ericmiller-wpengine yeah something went wrong for multiple PRs today. Just merge latest master branch and it should be fine.

@telegraf-tiger
Copy link
Contributor

Copy link
Contributor

@powersj powersj left a comment

Choose a reason for hiding this comment

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

Thanks for coming up with this!

@powersj powersj merged commit e4d7be0 into influxdata:master Nov 30, 2023
23 checks passed
@github-actions github-actions bot added this to the v1.29.0 milestone Nov 30, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/tail feat Improvement on an existing feature such as adding a new setting/mode to an existing plugin plugin/input 1. Request for new input plugins 2. Issues/PRs that are related to input plugins ready for final review This pull request has been reviewed and/or tested by multiple users and is ready for a final review.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Permission denied in a middle of logrotate process
4 participants