DeprecationLogger's deduplication performance #37530
Comments
markharwood
added
>enhancement
:Core/Infra/Core
|
Pinging @elastic/es-core-infra |
danielmitterdorfer
added
:Core/Infra/Logging
|
I started attacking #35754 after a discussion in our team discussion meeting today. For the performance regression there, the improvements I have made in #37590 and #37597 take the performance penalty on my machine from 40x to 10x. The remaining time is spent in de-duplicating the warning headers and then what remains in encoding and formatting the log message. I don't see any room for improvement on the latter, and the de-duplication is around 50% of the remaining time. I would consider the encoding/formatting the tax we have to pay for deprecation logging something, but there is still room for improvement in the de-duplication. |
1. Setting length for formatWarning String to avoid AbstractStringBuilder.ensureCapacityInternal calls 2. Adding extra check for parameter array length == 0 to avoid unnecessarily creating StringBuilder in LoggerMessageFormat.format Relates to elastic#37530 Relates to elastic#37411
1. Setting length for formatWarning String to avoid AbstractStringBuilder.ensureCapacityInternal calls 2. Adding extra check for parameter array length == 0 to avoid unnecessarily creating StringBuilder in LoggerMessageFormat.format Helps to narrow the performance gap in throughout for geonames benchmark (#37411) by 3%. For more details: #37530 (comment) Relates to #37530 Relates to #37411 Relates to #35754
1. Setting length for formatWarning String to avoid AbstractStringBuilder.ensureCapacityInternal calls 2. Adding extra check for parameter array length == 0 to avoid unnecessarily creating StringBuilder in LoggerMessageFormat.format Helps to narrow the performance gap in throughout for geonames benchmark (elastic#37411) by 3%. For more details: elastic#37530 (comment) Relates to elastic#37530 Relates to elastic#37411 Relates to elastic#35754
1. Setting length for formatWarning String to avoid AbstractStringBuilder.ensureCapacityInternal calls 2. Adding extra check for parameter array length == 0 to avoid unnecessarily creating StringBuilder in LoggerMessageFormat.format Helps to narrow the performance gap in throughout for geonames benchmark (#37411) by 3%. For more details: #37530 (comment) Relates to #37530 Relates to #37411 Relates to #35754
|
Closing this for now, since the majority of the original 21% gap got narrowed to 4% with all the changes. |
As part of types removal we discovered that
DeprecationLogger.deprecatedAndMaybeLog()calls were the source of a big performance regression.I suspect the bulk of the performance cost is in the use of the
extractWarningValueFromWarningHeadermethod which has to parse prior logged messages to reject any duplicates.Since that discovery we have implemented our own upstream event thinning in the bulk indexing API and now search APIs to reduce the number of duplicate deprecation calls.
The remaining concern is that other areas of the system may be tempted to make the same mistake given the logging API advertises a de-duplicate function through the use of a common key. Even if developers are aware of the poor performance they may not have a single loop (like in bulk indexing) where it is convenient to add the required trimming of log calls.
If the DeprecationLogger implementation was made more efficient this would help with all these concerns.
The text was updated successfully, but these errors were encountered: