Reduce useless log messages about default CNI network

[roman-kiselenko]

The logs with empty default CNI network updates are useless and produce much noise.

time="2024-06-25 19:33:12.783576005Z" level=info msg="Updated default CNI network name to "
time="2024-06-25 19:33:12.783958197Z" level=info msg="Updated default CNI network name to "
time="2024-06-25 19:33:12.784004164Z" level=info msg="Updated default CNI network name to "
time="2024-06-25 19:33:12.784321809Z" level=info msg="Updated default CNI network name to "
time="2024-06-25 19:33:12.784364691Z" level=info msg="Updated default CNI network name to "

This PR change log, so only actual changes are logged.

What type of PR is this?

/kind cleanup

What this PR does / why we need it:

Reduce useless log messages.

Which issue(s) this PR fixes:

None

Special notes for your reviewer:

Does this PR introduce a user-facing change?

Reduce useless log messages about default CNI network changes

[coveralls]

Pull Request Test Coverage Report for Build 9809293589

Details

• 3 of 3 (100.0%) changed or added relevant lines in 1 file are covered.
• No unchanged relevant lines lost coverage.
• Overall coverage increased (+0.7%) to 62.037%

---

Totals
Change from base Build 9657830375:	0.7%
Covered Lines:	536
Relevant Lines:	864

---

💛 - Coveralls

[coveralls]

Pull Request Test Coverage Report for Build 9809302081

Details

• 3 of 3 (100.0%) changed or added relevant lines in 1 file are covered.
• No unchanged relevant lines lost coverage.
• Overall coverage increased (+0.09%) to 61.458%

---

Totals
Change from base Build 9657830375:	0.09%
Covered Lines:	531
Relevant Lines:	864

---

💛 - Coveralls

[kwilczynski]

Related:

• a fsnotify-related risk #42
• Tearing down networks should allow an empty netns #64

[openshift-ci]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: roman-kiselenko, saschagrunert

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:

• OWNERS [saschagrunert]

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

[kwilczynski]

@roman-kiselenko, there is also a different angle to this problem.

The CNI plugins can be configured using .conf and .json files for a single network configuration and .conflict (there is no JSON file equivalent for conflist-style configuration) when configuring multiple networks. The directories that are usually involved in the whole CNI shebang are:

• /etc/cni/net.d
• /etc/kubernetes/cni/net.d
• /var/lib/cni/networks
• /var/lib/cni/results

We watch these directories which are also shared with other things, such as the specific CNI runtimes, etc. This can lead to a lot of spurious file system events, per:

An excerpt from the CRI-O log:

Jun 25 19:34:51 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:34:51.427866852Z" level=info msg="CNI monitoring event REMOVE        \"/var/lib/cni/bin/upgrade_5a6545b2-25e7-4511-8b40-e882c1305752\""
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.278298219Z" level=info msg="CNI monitoring event CREATE        \"/var/lib/cni/bin/upgrade_c1b67453-f6f3-4303-928e-b5fb53550991\""
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.278379200Z" level=info msg="Updated default CNI network name to "
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.404745277Z" level=info msg="CNI monitoring event CREATE        \"/var/lib/cni/bin/cert-approver\""
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.404839986Z" level=info msg="Updated default CNI network name to "
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.408682926Z" level=info msg="CNI monitoring event CREATE        \"/var/lib/cni/bin/install_multus\""
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.408748001Z" level=info msg="Updated default CNI network name to "
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.408900356Z" level=info msg="CNI monitoring event CREATE        \"/var/lib/cni/bin/kubeconfig_generator\""
Jun 25 19:35:59 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:35:59.408956448Z" level=info msg="Updated default CNI network name to "

Eventually, the proper configuration will land:

Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.545735113Z" level=info msg="CNI monitoring event CREATE        \"/etc/kubernetes/cni/net.d/00-multus.conf\""
Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.561614840Z" level=info msg="Found CNI network multus-cni-network (type=multus-shim) at /etc/kubernetes/cni/net.d/00-multus.conf"
Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.561643272Z" level=info msg="Updated default CNI network name to multus-cni-network"
Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.561664302Z" level=info msg="CNI monitoring event WRITE         \"/etc/kubernetes/cni/net.d/00-multus.conf\""
Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.574319103Z" level=info msg="Found CNI network multus-cni-network (type=multus-shim) at /etc/kubernetes/cni/net.d/00-multus.conf"
Jun 25 19:36:22 kwilczynski-dev2-th748-worker-a-kg8lj crio[2219]: time="2024-06-25 19:36:22.574350829Z" level=info msg="Updated default CNI network name to multus-cni-network"

Thus, as much as suppressing the log line will make it "go away", the proper solution here might be an update to the code that handles file system events.

[kwilczynski]

@roman-kiselenko, thoughts on my comment?

[roman-kiselenko]

@roman-kiselenko, thoughts on my comment?

🤔 I tried to determine which events can be ignored, but have not yet been able to find the desired configuration, I will try to investigate the problem more carefully, thanks.

Maybe separate issue would be good for cleanup work.

[kwilczynski]

@roman-kiselenko, thoughts on my comment?

🤔 I tried to determine which events can be ignored, but have not yet been able to find the desired configuration, I will try to investigate the problem more carefully, thanks.

Maybe separate issue would be good for cleanup work.

@roman-kiselenko, the events are fine. What I suggested doing, would be to ignore everything that is not a valid CNI configuration file. There is little point having this code fire every time a CNI plugin downloads some files, or stored a temporary file to later delete it. All of this creates an event, to which the code reacts, and there is no need to reload CNI configuration cache, which would be empty, for some random binaries downloaded the CNI plugins, etc.

Does this make more sense now? I hope it does. 😄