Fix: kubelet will not output logs after log file is rotated #115702

xyz-li · 2023-02-11T13:26:12Z

What type of PR is this?

/kind bug

What this PR does / why we need it:

kubectl logs POD_NAME -f won't output logs after kubelet rotate log file of the container .

Which issue(s) this PR fixes:

Fixes #115701

Special notes for your reviewer:

Comment from the method Wacher.Add

// # Watching directories
//
// All files in a directory are monitored, including new files that are created
// after the watcher is started. Subdirectories are not watched (i.e. it's
// non-recursive).
//
// # Watching files
//
// Watching individual files (rather than directories) is generally not
// recommended as many tools update files atomically. Instead of "just" writing
// to the file a temporary file will be written to first, and if successful the
// temporary file is moved to to destination removing the original, or some
// variant thereof. The watcher on the original file is now lost, as it no
// longer exists.
//
// Instead, watch the parent directory and use Event.Name to filter out files
// you're not interested in. There is an example of this in [cmd/fsnotify/file.go].

Does this PR introduce a user-facing change?

Fixed the bug that kubelet could't output logs after log file rotated when kubectl logs POD_NAME -f is running.

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

k8s-ci-robot · 2023-02-11T13:26:21Z

Hi @xyz-li. Thanks for your PR.

I'm waiting for a kubernetes member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

saschagrunert

Can we add a unit test to TestReadLogs to cover the failure scenario?

pkg/kubelet/kuberuntime/logs/logs.go

saschagrunert · 2023-02-13T13:20:38Z

/ok-to-test

xyz-li · 2023-02-14T14:45:14Z

Can we add a unit test to TestReadLogs to cover the failure scenario?

Working on it.

xyz-li · 2023-07-17T08:53:35Z

/assign @sjenning

tuibeovince · 2023-08-15T07:51:42Z

I was able to confirm that this patch/fix allows continuous output of kubectl logs -f even after log rotation. I would love to have this patch merged soon.

tuibeovince · 2023-09-07T05:53:09Z

I also did a confirmation of the performance of this fix by recursively executing the kubectl logs command over 100 times. A stuck log during rotation didn't occur even once using this fix.

I used the reproduction method in #115701

As supplimentary info:

As of the the release of v1.28, executing kubectl logs POD_NAME -f numerous times may also trigger a "failed to watch file" error.

Specifically speaking, I executed the logging command for the pod 100 times. It occurs very very rarely, about once in one hundred executions. This PR also addresses and fixes this error's occurence as far as my reproduction methodology is concerned.

Stdout:

...
print log to stand out 1064678
print log to stand out 1064679
print log to stand out 1064680
failed to watch file "/var/log/pods/default_testlogrotator_41df37c5-02e3-4687-a237-329bec3b2d25/testlogrotator/0.log": no such file or directory

dims · 2023-10-14T19:36:25Z

this has waited long enough. let's see if something shakes up in the CI

/approve
/lgtm

k8s-ci-robot · 2023-10-14T19:36:58Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: dims, xyz-li

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:

~~pkg/kubelet/OWNERS~~ [dims]

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

tuibeovince · 2023-10-16T02:29:14Z

this has waited long enough. let's see if something shakes up in the CI

/approve /lgtm

Thank you very much for this approval. I believe this log rotation problem has been an issue for other people for a while now.

zwpaper · 2023-10-16T07:05:22Z

as this fixes a bug many people had met in production environments, will this be cherry-picked to the previous releases?

Versions of Kubernetes that do not contain kubernetes/kubernetes#115702 will fail to detect rolled log files, causing the API to stop sending logs to the agent for processing. To work around this, this commit intorduces a rolling average calculator to determine the average delta between log entries per target. If 3x the normal delta time has elapsed since the last entry, the tailer is restarted. False positives here are acceptable, but false negatives mean that log lines may not appear for an extended period of time until the rolling detection succeeds. Closes grafana#5040

Versions of Kubernetes that do not contain kubernetes/kubernetes#115702 will fail to detect rolled log files, causing the API to stop sending logs to the agent for processing. To work around this, this commit intorduces a rolling average calculator to determine the average delta between log entries per target. If 3x the normal delta time has elapsed since the last entry, the tailer is restarted. False positives here are acceptable, but false negatives mean that log lines may not appear for an extended period of time until the rolling detection succeeds. Closes grafana#5040 Co-authored-by: Edward Welch <[email protected]>

* component/prometheus: fix panic in interceptor when child isn't set This commit fixes a panic in prometheus.Interceptor where an interceptor which doesn't forward samples to another appendable panics when appending data. Co-authored-by: Edward Welch <[email protected]> * loki.source.kubernetes: improve detection of rolled log files Versions of Kubernetes that do not contain kubernetes/kubernetes#115702 will fail to detect rolled log files, causing the API to stop sending logs to the agent for processing. To work around this, this commit intorduces a rolling average calculator to determine the average delta between log entries per target. If 3x the normal delta time has elapsed since the last entry, the tailer is restarted. False positives here are acceptable, but false negatives mean that log lines may not appear for an extended period of time until the rolling detection succeeds. Closes #5040 Co-authored-by: Edward Welch <[email protected]> * loki.source.kubernetes: support clustering Add support for loki.source.kubernetes to distribute targets using clustering. Closes #4502 Co-authored-by: Edward Welch <[email protected]> * loki.source.podlogs: support clustering Add support for loki.source.podlogs to distribute targets using clustering. * service/cluster: add common block for clustering arguments * remove irrelevant TODO comment #5623 (comment) --------- Co-authored-by: Edward Welch <[email protected]>

k8s-ci-robot added the needs-priority Indicates a PR lacks a `priority/foo` label and requires one. label Feb 11, 2023

k8s-ci-robot requested review from derekwaynecarr and SergeyKanzhelev February 11, 2023 13:27

k8s-ci-robot added area/kubelet sig/node Categorizes an issue or PR as relevant to SIG Node. and removed do-not-merge/needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. labels Feb 11, 2023

xyz-li force-pushed the master branch from 29ac243 to c5b45a8 Compare February 11, 2023 13:47

bart0sh added this to Triage in SIG Node PR Triage Feb 11, 2023

xyz-li changed the title ~~FIX: kubelet will not output logs after log file is rotated~~ Fix: kubelet will not output logs after log file is rotated Feb 12, 2023

saschagrunert reviewed Feb 13, 2023

View reviewed changes

pkg/kubelet/kuberuntime/logs/logs.go Outdated Show resolved Hide resolved

k8s-ci-robot added ok-to-test Indicates a non-member PR verified by an org member that is safe to test. and removed needs-ok-to-test Indicates a PR that requires an org member to verify it is safe to test. labels Feb 13, 2023

xyz-li force-pushed the master branch from c5b45a8 to c1dde72 Compare February 14, 2023 03:15

xyz-li force-pushed the master branch from c1dde72 to 2785d74 Compare February 15, 2023 02:17

k8s-ci-robot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/S Denotes a PR that changes 10-29 lines, ignoring generated files. labels Feb 15, 2023

xyz-li force-pushed the master branch from 2785d74 to 5f477f7 Compare February 15, 2023 05:05

xyz-li requested review from saschagrunert and removed request for derekwaynecarr and SergeyKanzhelev February 15, 2023 17:46

k8s-ci-robot assigned Random-Liu Jul 17, 2023

k8s-ci-robot assigned sjenning Jul 17, 2023

tuibeovince mentioned this pull request Sep 7, 2023

kubelet: fix handle new log file in ReadLogs after log rotation #118500

Closed

xyz-li requested review from bart0sh, s-kawamura-w664 and saschagrunert September 8, 2023 06:51

k8s-ci-robot assigned dims Oct 14, 2023

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 14, 2023

k8s-ci-robot merged commit 4911aad into kubernetes:master Oct 14, 2023
12 checks passed

SIG Node PR Triage automation moved this from Needs Approver to Done Oct 14, 2023

k8s-ci-robot added this to the v1.29 milestone Oct 14, 2023

Klaas- mentioned this pull request Oct 18, 2023

Pod logs stop being pulled when container log files are rotated ansible/receptor#446

Open

rfratto mentioned this pull request Oct 26, 2023

loki.source.kubernetes should handle log rotation grafana/agent#5040

Closed

rfratto mentioned this pull request Oct 26, 2023

Flow: Improve Kubernetes log collection grafana/agent#5623

Merged

tksm mentioned this pull request Dec 14, 2023

Stern stops tailing logs after a while (possible log file rotation??) stern/stern#287

Closed

rouilj mentioned this pull request Dec 14, 2023

'kubectl logs -f insert_pod_here' stops reporting when log file rotates k3s-io/k3s#9060

Closed

zmedico mentioned this pull request Jan 5, 2024

kubectl logs should support log rotation for CRI container runtime. #59902

Open

Klaas- mentioned this pull request Apr 3, 2024

UI: Lines 3094 - 7371 not shown in job output ansible/awx#15032

Closed

11 tasks

hainenber mentioned this pull request Jan 27, 2024

[loki.source.kubernetes] decrease logLevel of log msg grafana/alloy#264

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix: kubelet will not output logs after log file is rotated #115702

Fix: kubelet will not output logs after log file is rotated #115702

xyz-li commented Feb 11, 2023 •

edited

k8s-ci-robot commented Feb 11, 2023

saschagrunert left a comment

saschagrunert commented Feb 13, 2023

xyz-li commented Feb 14, 2023

xyz-li commented Jul 17, 2023

tuibeovince commented Aug 15, 2023

tuibeovince commented Sep 7, 2023

dims commented Oct 14, 2023

k8s-ci-robot commented Oct 14, 2023

tuibeovince commented Oct 16, 2023

zwpaper commented Oct 16, 2023

Fix: kubelet will not output logs after log file is rotated #115702

Fix: kubelet will not output logs after log file is rotated #115702

Conversation

xyz-li commented Feb 11, 2023 • edited

What type of PR is this?

What this PR does / why we need it:

Which issue(s) this PR fixes:

Special notes for your reviewer:

Does this PR introduce a user-facing change?

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

k8s-ci-robot commented Feb 11, 2023

saschagrunert left a comment

Choose a reason for hiding this comment

saschagrunert commented Feb 13, 2023

xyz-li commented Feb 14, 2023

xyz-li commented Jul 17, 2023

tuibeovince commented Aug 15, 2023

tuibeovince commented Sep 7, 2023

dims commented Oct 14, 2023

k8s-ci-robot commented Oct 14, 2023

tuibeovince commented Oct 16, 2023

zwpaper commented Oct 16, 2023

xyz-li commented Feb 11, 2023 •

edited