KEP-5032: Container log rotation on Disk pressure

[Zeel-Patel]

• One-line PR description: Rotate containers logs when there is disk pressure on kubelet host.

• Issue link: Container log rotation on Disk pressure #5032

[k8s-ci-robot]

Welcome @Zeel-Patel!

It looks like this is your first PR to kubernetes/enhancements 🎉. Please refer to our pull request process documentation to help your PR have a smooth ride to approval.

You will be prompted by a bot to use commands during the review process. Do not be afraid to follow the prompts! It is okay to experiment. Here is the bot commands documentation.

You can also check if kubernetes/enhancements has its own contribution guidelines.

You may want to refer to our testing guide if you run into trouble with your tests not passing.

If you are having difficulty getting your pull request seen, please follow the recommended escalation practices. Also, for tips and tricks in the contribution process you may want to read the Kubernetes contributor cheat sheet. We want to make sure your contribution gets all the attention it needs!

Thank you, and welcome to Kubernetes. 😃

[k8s-ci-robot]

Hi @Zeel-Patel. 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-sigs/prow repository.

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: Zeel-Patel
Once this PR has been reviewed and has the lgtm label, please assign dchen1107 for approval. For more information see the Code Review Process.

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

Needs approval from an approver in each of these files:

• keps/sig-node/OWNERS

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

[Zeel-Patel]

/sig-node

[kannon92]

I was thinking that when there is disk pressure in nodefs.available/imagefs.available we can add rotateLogs to our list of functions we run in case of disk pressure.

https://github.com/kubernetes/kubernetes/blob/master/pkg/kubelet/eviction/helpers.go#L1195-#L1230

[Zeel-Patel]

That's better. Thanks.
But won't that use kubelet eviction thresholds to identify disk pressure?

[harshanarayana]

I suppose this log cleanup is another form of eviction to make space like we do with Images and containers.

So, Adding that to the nodefs.available / imagefs.available would logically make a great addition

[ffromani]

big +1, this was my initial thinking as well. Detecting disk pressure should be a trigger for log rotation in addition to the timer-based approach.

[Zeel-Patel]

Sure.

Considering this
#5022 (comment)

If we rely on same kubelet eviction thresholds, it will cause log rotation to fail. We have experienced it as well, that log copy creation fails.
Up for suggestions.

[Zeel-Patel]

@ffromani @harshanarayana @kannon92

Listing down few options, lmk your thoughts

• We use same disk eviction thresholds. Every time there is disk pressure, check size of .gz log files of all containers. If the combined file size (for a particular container) exceeds (containerLogMaxSize*containerLogMaxFiles), simply delete older .gz files till remaining size is within this limit. No log rotate. So if we have containerLogMaxSize = 20Mib and containerLogMaxFiles = 6, we will ensure that combined log file size remains within 120Mib. It could also happen that a single .gz file endsup taking all 120Mib after cleanup
• Blindly do log rotation as proposed in KEP (But using disk pressure thresholds as suggested by you all)
• Make the change suggested in option 1 in ContainerLogManager periodic log rotation itself.

[kannon92]

my suggestion is when disk pressure is hit (by our eviction settings) we would trigger your logic for forcing rotations on any logs that exceed the limits.

Though the fact that they exceed limits seems to be a bug..

The goal would be to preemptly try and clean up disk space without evicting.

[Zeel-Patel]

Looking at this goal, this seems good to me

We use same disk eviction thresholds. Every time there is disk pressure, check size of .gz log files of all containers. If the combined file size (for a particular container) exceeds (containerLogMaxSize*containerLogMaxFiles), simply delete older .gz files till remaining size is within this limit. No log rotate. So if we have containerLogMaxSize = 20Mib and containerLogMaxFiles = 6, we will ensure that combined log file size remains within 120Mib. It could also happen that a single .gz file endsup taking all 120Mib after cleanup

[kannon92]

/ok-to-test

[harshanarayana]

Leaving behind a few comments/ Feel free to ignore if you consider them irrelevant/invalid.

[harshanarayana]

Here is my two cent.

I was the one who added a similar config to the Log rotate workflow where it can take a configurable number workers with a duration and rotate logs in async mode to help reduce the leak of log file size when the container log generation rate it way too high.

Which definitely helps, but never really prevents the issue. The safest way to deal with this would be to truncate and fix the size when the logs are being written instead of monitor, rotate and cleanup. That will be the most fool proof way to do this.

That being said, In absence of that workflow, I like your suggestion.

it will rotate logs of all the containers of the kubelet.

However, I am not sure if all service/containers should be taxed because of one service's misbehaviour. The reason being how the kubectl log would look like after one such global rotation.

As far as I can recall, the .gz extensions are ignored when the kubectl logs are being used. So, forcing a global rotation can lead to logs going missing from the kubectl log out of nowhere.

We should still cleanup only those logs that have exceeded the configured threshold in this loop so that we let the other service behave the way they do.

[Zeel-Patel]

Yes, that's what we are proposing.
Currently, log files are anyways exceeding the set thresholds which causes high disk usage.
Instead of evicting pods, we can once try rotating logs of such containers (containers for which logs size is exceeding the containerLogMaxSize threshold)

[harshanarayana]

I suppose this log cleanup is another form of eviction to make space like we do with Images and containers.

So, Adding that to the nodefs.available / imagefs.available would logically make a great addition

[harshanarayana]

FYI, there is also two other fields to configure the worker + the monitoring duration to perform the cleanup.

containerLogMaxWorkers and containerLogMonitorInterval respectively.

[harshanarayana]

This can also prevent further container log rotation to fail and make the problem even worse.

case and point, an issue we ran into very recently.

Dec 11 21:35:31 tardis-node-192-168-4-51 kubelet[8204]: E1211 21:35:31.794811 8204 container_log_manager.go:296] "Failed to rotate log for container" err="failed to compress log "/var/log/pods/tardis-pod-2-5bb1ae31-tm-78475757b8-2mbl9_f53b5f87-5b48-4748-a919-9eb702bb5f0c/taskmanager/2.log.20241211-202335": failed to create temporary log "/var/log/pods/tardis-pod-2-5bb1ae31-tm-78475757b8-2mbl9_f53b5f87-5b48-4748-a919-9eb702bb5f0c/taskmanager/2.log.20241211-202335.tmp": open /var/log/pods/tardis-pod-2-5bb1ae31-tm-78475757b8-2mbl9_f53b5f87-5b48-4748-a919-9eb702bb5f0c/taskmanager/2.log.20241211-202335.tmp: disk quota exceeded" path="/var/log/pods/tardis-pod-2-5bb1ae31-tm-78475757b8-2mbl9_f53b5f87-5b48-4748-a919-9eb702bb5f0c/taskmanager/2.log" containerID="2c7de6fdcbda4498543ab3cc68d59dcee487e08ad7d37751f9ea5c366975f784"

[Zeel-Patel]

Yes, we have faced this issue on disk pressure as well. But the periodic log rotations is anyways failing.
If we wisely chose logRotateDiskPressureThreshold, it would be helpful.
wdyt?

[harshanarayana]

It should definitely help. But the way to chose the right size and frequency to monitor is trial and error and I can't think of an effective way to determine the number. But that is besides the scope of this KEP anyway.

[harshanarayana]

Would there be a configuration required to help identify what logs are to be selected for such cleanup ?

[Zeel-Patel]

Containers for which log size is exceeding containerLogMaxSize will be selected for cleanup.

[ffromani]

please add @kannon92 and @ffromani for starters

[ffromani]

feel free to remove comments when no longer needed, to make review (and reading in general) easier

[ffromani]

we will need something here

[ffromani]

we will need some details here

[ffromani]

brainstorming, let's evaluate some ideas:

• if the log rotation manager detects that the previous X rotations (1? 2? N?) made the rotated logs exceeds the configured max size, because containers are producing many logs continuously, should this cause kubelet to report disk pressure?
• do we want or need to review log retention also? if a rotated log is like 500 megs while it is supposed to be 100 megs (random example numbers), should that cause the kubelet to report disk pressure? arguably, we are consuming more disk space than the user configured, and thus expects.

[harshanarayana]

I am not sure if these should trigger a disk pressure report. That can have a side-effect. Right ?

However, this can definitely be Turned into a warning event from the node level to indicate that something is going wrong. Would that lead to an event storm for some cases? Depends on how frequently we generate the event.

[harshanarayana]

if the log rotation manager detects that the previous X rotations (1? 2? N?) made the rotated logs exceeds the configured max size

This problem becomes even more concerning with high value being set for containerLogMaxFiles.

[ffromani]

big +1, this was my initial thinking as well. Detecting disk pressure should be a trigger for log rotation in addition to the timer-based approach.

[ffromani]

please also add @harshanarayana

[ffromani]

let's think a bit more about this, especially if we start from beta. What can go wrong?

[ffromani]

will it? why exactly? could you please elaborate?

[harshanarayana]

1. Suppose this is a function of what your cloud provider lets you do in terms of tuning the kubelet configuration.
2. For on prem deployments, this definitely is just a kubelet restart away. So, not much of a downtime/re-provisioning

[ffromani]

The cloud provider use case is interesting indeed, but from project perspective this looks like the BM use case anyway. I think a good first step is just adding more details on the answer here.

[kannon92]

@Zeel-Patel Please create an issue in kubernetes/enhancement that tracks this KEP. That would be the title of the KEP.

The k/k issue is used as a discussion to create the KEP. Sorry to be pain about this.

[harshanarayana]

Suggested change

	- Rotate and Clean all container logs on kubelet Disk pressure
	- Rotate and Clean all container logs on kubelet Disk pressure that has exceeded the configured log retention quota

[harshanarayana]

Suggested change

	The [ContainerLogManager](https://github.com/kubernetes/kubernetes/blob/master/pkg/kubelet/logs/container_log_manager.go#L52-L60), responsible for log rotation and cleanup of log files of containers periodically, should also rotate logs of all containers in case of disk pressure on host.
	The [ContainerLogManager](https://github.com/kubernetes/kubernetes/blob/master/pkg/kubelet/logs/container_log_manager.go#L52-L60), responsible for log rotation and cleanup of log files of containers periodically, should also rotate logs of all containers that has exceeded the configured log retention quota in case of disk pressure on host.

[harshanarayana]

Some of the details from the KEP should go into this section.

[harshanarayana]

Suggested change

	ContainerLogManager of kubelet will use more CPU cycle then now.
	CPU cycles usage of ContainerLogManager of kubelet will increase.

[kannon92]

So it seems to be a bug that logs exceed the limit we specify. I know @harshanarayana worked on the parallel workers to clean up logs.

Reading this it seems that we proposing a feature to resolve a bug that log rotation exceeds the limit.

Is it worth focusing on fixing this issue?

ie what I am trying to get is if we "fix" this bug of log rotations exceeding limits is there a need for this KEP?

[sftim]

In this write up, who is "our"? Kubernetes project?

[Zeel-Patel]

Updated

[kannon92]

I worry that this won't work out that well when we come close to disk pressure. Let's say that a few pods are exceeding their limits and then we trigger a function to rotate. If we are close to host file system limits would log rotation still be expected to work?

[ffromani]

/retitle KEP-5032: Container log rotation on Disk pressure

[sftim]

In this write up, who is "our"? Kubernetes project?

[sftim]

There's no alternatives section. Let's add one.

Another option: provide a means for an external tool to trigger the kubelet to rotate its logs. That would move the policy decisions outside of the kubelet; for example, into a DaemonSet.

I wanted to suggest this, but couldn't see the page section where it would live.

[sftim]

There's no proposal. You should add one.

[sftim]

5032

[Zeel-Patel]

/sig node

[harshanarayana]

@kannon92 / @sftim

He is a long rant/response to very valid point that both of you brought up.

I think the source of the problem exists in the fact that kubelet is the one rotating after the longs are written onto the disk. So, no matter how hard we try, there will always be a possibility for leak. Since we are monitoring and reacting after the fact. The duration can be turned to as small a value as possible and tax kubelet, but that will also not be fool proof. The safest would be to truncate the log to size in the writer and not write the logs higher than configured size to the host. Drop everything else. But that also comes with a lot of problem. What if we end up having partial logs. That can break a lot of tooling and workflows.

provide a means for an external tool to trigger the kubelet to rotate its logs. That would move the policy decisions outside of the kubelet; for example, into a DaemonSet.

We tried this out internally, and had the same behavior more or less as that of doing in the kubelet. It did give us more configure knobs and options, but the underlying matter is, we are doing the cleanup after the logs are written first.

So, we are equally failure prone is it not ?

what I am trying to get is if we "fix" this bug of log rotations exceeding limits

This KEP and my old PR both did part of that work. But never got it fully accurate. The crux is in how we cleanup.

Say you have a heavy logging pod, that is writing 10G per second (Silly number, but hey! Where is the fun otherwise). Say your configured limit was 100M per pod with 5 files. The one file written will easily exceed all configured limits.

Now the question is, how do you cleanup these files. Do you cleanup the entire file? Or part of the file ? Both of whcih can be really flaky and very opinionated. Can cause loss of logs in both cases.

So, when my original change was done, I left the truncating part of the file out and cleaned up exceed files based on count alone. That fixed part of the problem But then the current issue that @Zeel-Patel mentioned happen. Now comes the part of another cleanup that we have to where we sweep across and find all exceed limits and cleanup. But this cleanup is bound by the same problem that my original change would have had to deal with.

Honestly, the safest I can think of for mitigating this would be to find a mechanism to truncate at the source ensuring we do not run into partial logs being written and then kubelet can just do the count based cleanup.

[pohly]

Honestly, the safest I can think of for mitigating this would be to find a mechanism to truncate at the source ensuring we do not run into partial logs being written

This is only safe if the process which writes the log data is also the one which rotates because it knows the message boundaries. But we removed log rotation from klog. There is now a proposal in kubernetes/kubernetes#127667 to add it back in logrunner. Perhaps something could be done with datagram stream sockets (preserve message boundaries) there.

[sftim]

AIUI there is no safe way to have a process ship logs; it is always possible to have a log volume that fills either local storage or a local buffer. There's no safe means because the rate of application log writes is formally not bounded, whereas buffers and local storage are always finite.

If we provide a way for container log writes to go to a socket or other file descriptor not backed by local storage, there is no need to rotate. That approach doesn't prevent log entries being dropped but it is proof against any local storage exhaustion.

[harshanarayana]

@pohly

This is only safe if the process which writes the log data is also the one which rotates because it knows the message boundaries.

Absolutely. Couldn't agree more on this.

I noticed that PR a couple of days ago but how does that help for service that do not really use that bin to run their process? For such, it is containerd that is doing the write. Correct ? https://github.com/containerd/containerd/blob/main/internal/cri/io/logger.go (is my understanding of this incorrect? )

For example, containerd exposes a knob max_container_log_line_size, would it make this better if the rotation were to be done there? Would that give us a slight bit more precision on how accurately we meet the log size per file configuration?

If we provide a way for container log writes to go to a socket or other file descriptor not backed by local storage, there is no need to rotate.

@sftim Most definitely, But this might not always be possible for everyone to configure even it provided as an option. I still remember the days when docker had a whole slew of plugins one can configure for log management that could help avoid writing to the local storage. Or you could create one yourself.

[pohly]

I noticed that PR a couple of days ago but how does that help for service that do not really use that bin to run their process?

I doesn't. An app has to be configured explicitly to redirect output to its own files and then not write anything to stdout/stderr... which breaks kubectl logs. I still need to review that PR again in more detail, your comments on the design and usage would be very welcome.

[sftim]

whole slew of plugins one can configure for log management

I'd definitely support a KEP to make container logging more extensible / pluggable. The story we have now is OK but not great.

[Zeel-Patel]

Honestly, the safest I can think of for mitigating this would be to find a mechanism to truncate at the source ensuring we do not run into partial logs being written and then kubelet can just do the count based cleanup.

• On disk pressure, analyse log paths of all containers. Logs of containers with existing combined log size exceeding containerLogMaxSizecontainerLogMaxFiles should be deleted till the combined log size is within containerLogMaxSizecontainerLogMaxFiles.

what do you think about this proposal?