Add checks to avoid use of logrus WithFields function in hot paths #26327
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
c5a765b to
4085aa0
Compare
christarazi
approved these changes
Jun 25, 2023
|
(Accidentally submitted review too soon...but below is what I was going to say) The change looks good to me. I wonder how we can prevent the need to do PRs like these in the future. At some point I'd imagine we'll have some performance testing, but that might be too late in the feedback cycle to inform whether new debug logs caused a performance impact. Food for thought I guess :). |
|
Definitely food for thought. Ideally, this will be a one-time PR for these changes. For 1.15, I am going to work on a CFP to explore some options to address the overhead we see here. |
ysksuzuki
approved these changes
Jun 27, 2023
|
I haven't found a great way to share the flamegraphs yet, as go's pprof tool doesn't have a method for generating svg flamegraphs. I've attached tarballs of the CPU, Heap and Alloc profiles that were taken during the course of the 100 node test. After extracting each, you can run:
To view CPU, Heap or Alloc flamegraphs respectively. |
4085aa0 to
eca0075
Compare
eca0075 to
6d0e6b7
Compare
|
/test |
6d0e6b7 to
39dccd5
Compare
39dccd5 to
a34b7c2
Compare
This commit modifies identified hot paths that contain the use of logrus' WithFields function, to add extra conditions to only call this expensive function as necessary. The most common case was a scoped logger created using WithFields that is only used to emit debug messages. These hot paths were identified using profiles taken from cilium agents in a 100 node ClusterLoader2 scale test. For example, the function `pkg/endpoint.(*Endpoint).removeDirectory` had a wasted call to WithFields which accounted for 1.5% of overall memory allocations and 0.13% of overall CPU time, as it is called during endpoint regeneration. Signed-off-by: Ryan Drew <ryan.drew@isovalent.com>
a34b7c2 to
8a96d7b
Compare
|
/test |
8 tasks
antonipp
pushed a commit
to DataDog/cilium
that referenced
this pull request
Dec 7, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 and cilium#23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com>
antonipp
pushed a commit
to DataDog/cilium
that referenced
this pull request
Dec 7, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 and cilium#23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com>
antonipp
pushed a commit
to DataDog/cilium
that referenced
this pull request
Dec 7, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 and cilium#23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com>
tklauser
pushed a commit
that referenced
this pull request
Dec 8, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from #26327 and #23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: #29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com>
antonipp
pushed a commit
to DataDog/cilium
that referenced
this pull request
Dec 8, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 and cilium#23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com>
learnitall
added a commit
to learnitall/cilium
that referenced
this pull request
Dec 12, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com>
learnitall
added a commit
to learnitall/cilium
that referenced
this pull request
Dec 12, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from cilium#26327 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: cilium#29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com>
ldelossa
pushed a commit
that referenced
this pull request
Dec 15, 2023
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from #26327 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: #29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com>
pchaigno
pushed a commit
that referenced
this pull request
Jan 8, 2024
[ upstream commit 00ab252 ] [ Backporter's notes: ignoring changes from #26327 and #23971 ] The DefaultLogger variable in the logging module serves as a parent logger which all other loggers can be derived from. It is initialized using the InitializeDefaultLogger function and then adjusted on startup based on user configuration. Users should not call InitializeDefaultLogger to create a parent logger for their logger, since the logger returned by InitializeDefaultLogger will always use the hardcoded defaults. For example, the logger returned will always be of level INFO, even if a user has enabled debug logging. To make this clear, this commit renames InitializeDefaultLogger to initializeDefaultLogger to signal that it should not be used outside of the logging module. Fixes: #29215 Signed-off-by: Ryan Drew <ryan.drew@isovalent.com> Signed-off-by: Anton Ippolitov <anton.ippolitov@datadoghq.com> Signed-off-by: Marco Iorio <marco.iorio@isovalent.com>
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
This commit modifies identified hot paths that contain the use of logrus' WithFields function, to add extra conditions to only call this expensive function as necessary. The most common case was a scoped logger created using WithFields that is only used to emit debug messages.
These hot paths were identified using profiles taken from cilium agents in a 100 node ClusterLoader2 scale test. For example, the function
pkg/endpoint.(*Endpoint).removeDirectoryhad a wasted call to WithFields which accounted for 1.5% of overall memory allocations and 0.13% of overall CPU time, as it is called during endpoint regeneration.I believe this needs the following labels:
release-note/misckind/bug