diff --git a/benchmarks/README.md b/benchmarks/README.md new file mode 100644 index 00000000..bbcb655a --- /dev/null +++ b/benchmarks/README.md @@ -0,0 +1,34 @@ +# Benchmarks + +JMH microbenchmarks for the solarwinds-apm-java project, using the +[`me.champeau.jmh`](https://github.com/melix/jmh-gradle-plugin) Gradle plugin. + +## Running + +Run all benchmarks: + +```shell +./gradlew :benchmarks:jmh +``` + +Run a specific benchmark by class name (regex matched against the fully +qualified benchmark name): + +```shell +./gradlew :benchmarks:jmh -Pjmh.include=LoggerLazyLoggingBenchmark +``` + +Results are written in CSV format to `benchmarks/build/results/jmh/results.csv`. + +## Adding a benchmark + +Benchmark sources live under `src/jmh/java`. Add the module under test as a +`jmh` dependency in `build.gradle.kts`, then write a class annotated with +JMH's `@Benchmark` and related annotations (see +`LoggerLazyLoggingBenchmark` for an example). + +## Existing benchmarks + +- `LoggerLazyLoggingBenchmark` — compares eager (`debug(String)`) vs. lazy + (`debug(Supplier)`) logging calls, at both a disabled (`INFO`) and + enabled (`DEBUG`) log level. diff --git a/benchmarks/build.gradle.kts b/benchmarks/build.gradle.kts new file mode 100644 index 00000000..52bac1fb --- /dev/null +++ b/benchmarks/build.gradle.kts @@ -0,0 +1,28 @@ +/* + * © SolarWinds Worldwide, LLC. All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +plugins { + id("solarwinds.java-conventions") + id("me.champeau.jmh") version "0.7.2" +} + +dependencies { + jmh(project(":libs:logging")) +} + +jmh { + resultFormat.set("CSV") +} diff --git a/benchmarks/src/jmh/java/com/solarwinds/benchmarks/LoggerLazyLoggingBenchmark.java b/benchmarks/src/jmh/java/com/solarwinds/benchmarks/LoggerLazyLoggingBenchmark.java new file mode 100644 index 00000000..d1d3f5d2 --- /dev/null +++ b/benchmarks/src/jmh/java/com/solarwinds/benchmarks/LoggerLazyLoggingBenchmark.java @@ -0,0 +1,144 @@ +/* + * © SolarWinds Worldwide, LLC. All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.solarwinds.benchmarks; + +import com.solarwinds.joboe.logging.LogSetting; +import com.solarwinds.joboe.logging.Logger; +import com.solarwinds.joboe.logging.LoggerConfiguration; +import com.solarwinds.joboe.logging.LoggerFactory; +import java.util.Locale; +import java.util.concurrent.TimeUnit; +import org.openjdk.jmh.annotations.Benchmark; +import org.openjdk.jmh.annotations.BenchmarkMode; +import org.openjdk.jmh.annotations.Fork; +import org.openjdk.jmh.annotations.Level; +import org.openjdk.jmh.annotations.Measurement; +import org.openjdk.jmh.annotations.Mode; +import org.openjdk.jmh.annotations.OutputTimeUnit; +import org.openjdk.jmh.annotations.Param; +import org.openjdk.jmh.annotations.Scope; +import org.openjdk.jmh.annotations.Setup; +import org.openjdk.jmh.annotations.State; +import org.openjdk.jmh.annotations.Warmup; + +/** + * Compares eager {@code debug(String)} against lazy {@code debug(Supplier)} logging. + * + *

Four scenarios are driven by the {@link #loggerLevel} parameter: + * + *

+ * + *

Both stdout and stderr streams are disabled on the logger so that the benchmark measures + * message construction and dispatch (the {@code shouldLog} guard, lambda allocation, formatting) + * rather than console I/O throughput. + * + *

Run with: + * + *

{@code
+ * ./gradlew :benchmarks:jmh -Pjmh.include=LoggerLazyLoggingBenchmark
+ * }
+ */ +@Fork(2) +@State(Scope.Benchmark) +@BenchmarkMode(Mode.AverageTime) +@Warmup(iterations = 5, time = 1) +@OutputTimeUnit(TimeUnit.NANOSECONDS) +@Measurement(iterations = 100, time = 1) +public class LoggerLazyLoggingBenchmark { + + /** "INFO" leaves DEBUG disabled (the win); "DEBUG" enables it (the cost). */ + @Param({"INFO", "DEBUG"}) + public String loggerLevel; + + private Logger logger; + + private int statusCode; + + private long durationNanos; + + private String payload; + + @Setup(Level.Trial) + public void setUp() { + Logger.Level level = Logger.Level.fromLabel(loggerLevel.toLowerCase(Locale.ROOT)); + // stdoutEnabled=false, stderrEnabled=false => the logger's output stream is a no-op, so we do + // not measure console I/O even in the DEBUG (enabled) scenario. + LogSetting logSetting = new LogSetting(level, false, false, null, null, null); + LoggerFactory.init(LoggerConfiguration.builder().logSetting(logSetting).build()); + logger = LoggerFactory.getLogger(); + + statusCode = 200; + durationNanos = 1_234_567_890L; + payload = "instance-identity-document"; + } + + /** Eager, {@code String.format}: format runs unconditionally, before {@code debug} checks. */ + @Benchmark + public void eagerFormat() { + logger.debug( + String.format( + "Retrieved metadata: status=%d durationNanos=%d payload=%s", + statusCode, durationNanos, payload)); + } + + /** Lazy, {@code String.format}: the supplier is only evaluated when DEBUG is enabled. */ + @Benchmark + public void lazyFormat() { + logger.debug( + () -> + String.format( + "Retrieved metadata: status=%d durationNanos=%d payload=%s", + statusCode, durationNanos, payload)); + } + + /** + * Eager, string concatenation: the {@code +} expression runs unconditionally, before {@code + * debug} checks the level. + */ + @Benchmark + public void eagerConcat() { + logger.debug( + "Retrieved metadata: status=" + + statusCode + + " durationNanos=" + + durationNanos + + " payload=" + + payload); + } + + /** Lazy, string concatenation: the supplier is only evaluated when DEBUG is enabled. */ + @Benchmark + public void lazyConcat() { + logger.debug( + () -> + "Retrieved metadata: status=" + + statusCode + + " durationNanos=" + + durationNanos + + " payload=" + + payload); + } +} diff --git a/bootstrap/src/main/java/com/solarwinds/opentelemetry/core/Util.java b/bootstrap/src/main/java/com/solarwinds/opentelemetry/core/Util.java index f7264ab5..2ff5ab57 100644 --- a/bootstrap/src/main/java/com/solarwinds/opentelemetry/core/Util.java +++ b/bootstrap/src/main/java/com/solarwinds/opentelemetry/core/Util.java @@ -139,7 +139,7 @@ public static String parsePath(String url) { try { return new URL(url).getPath(); } catch (MalformedURLException e) { - logger.debug("Cannot parse URL " + url); + logger.debug(() -> "Cannot parse URL " + url); } } return null; diff --git a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsAgentListener.java b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsAgentListener.java index 2a6f91a8..343e6987 100644 --- a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsAgentListener.java +++ b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsAgentListener.java @@ -84,10 +84,11 @@ private void executeStartupTasks() { : Collections.emptyList(); logger.debug( - "Detected host id: " - + HostInfoUtils.getHostId() - + " ip addresses: " - + ipAddresses); + () -> + "Detected host id: " + + HostInfoUtils.getHostId() + + " ip addresses: " + + ipAddresses); CountDownLatch settingsLatch = SettingsManager.initialize( @@ -101,7 +102,7 @@ private void executeStartupTasks() { if (JavaRuntimeVersionChecker.isJdkVersionSupported() && profilerSetting != null && profilerSetting.isEnabled()) { - logger.debug("Profiler is enabled, local settings : " + profilerSetting); + logger.debug(() -> "Profiler is enabled, local settings : " + profilerSetting); Profiler.initialize( profilerSetting, ReporterFactory.getInstance() diff --git a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessor.java b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessor.java index 87b5fab7..4949bd50 100644 --- a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessor.java +++ b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessor.java @@ -95,15 +95,17 @@ public void onEnding(ReadWriteSpan readWriteSpan) { if (profile.isSampled()) { readWriteSpan.setAttribute(SW_KEY_PREFIX + "profile.spans", 1); logger.debug( - String.format( - "Profiling stopped with sw.profile.spans=1, trace_id=%s span_id=%s", - spanContext.getTraceId(), spanContext.getSpanId())); + () -> + String.format( + "Profiling stopped with sw.profile.spans=1, trace_id=%s span_id=%s", + spanContext.getTraceId(), spanContext.getSpanId())); } else { readWriteSpan.setAttribute(SW_KEY_PREFIX + "profile.spans", 0); logger.debug( - String.format( - "Profiling stopped with sw.profile.spans=0, trace_id=%s span_id=%s", - spanContext.getTraceId(), spanContext.getSpanId())); + () -> + String.format( + "Profiling stopped with sw.profile.spans=0, trace_id=%s span_id=%s", + spanContext.getTraceId(), spanContext.getSpanId())); } } } diff --git a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/ConfigurationLoader.java b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/ConfigurationLoader.java index b54eccab..575b6dff 100644 --- a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/ConfigurationLoader.java +++ b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/ConfigurationLoader.java @@ -426,7 +426,8 @@ public static void processConfigs(ConfigContainer configs) throws InvalidConfigE + ServiceKeyUtils.maskServiceKey(serviceKey)); configs.put(ConfigProperty.AGENT_SERVICE_KEY, serviceKey, true); } - logger.debug("Service key (masked) is [" + ServiceKeyUtils.maskServiceKey(serviceKey) + "]"); + logger.debug( + () -> "Service key (masked) is [" + ServiceKeyUtils.maskServiceKey(serviceKey) + "]"); } else { if (!configs.containsProperty(ConfigProperty.AGENT_SERVICE_KEY)) { diff --git a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/HttpSettingsReader.java b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/HttpSettingsReader.java index c4c84293..884e19bb 100644 --- a/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/HttpSettingsReader.java +++ b/custom/src/main/java/com/solarwinds/opentelemetry/extensions/config/HttpSettingsReader.java @@ -54,7 +54,9 @@ public Settings getSettings() { String tokenHeader = String.format("Bearer %s", apiToken); Settings fetchedSettings = delegate.fetchSettings(settingsUrl, tokenHeader); logger.debug( - String.format("Got settings from http: %s, serviceName: %s", fetchedSettings, serviceName)); + () -> + String.format( + "Got settings from http: %s, serviceName: %s", fetchedSettings, serviceName)); return fetchedSettings; } diff --git a/custom/src/test/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessorTest.java b/custom/src/test/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessorTest.java index 0c5799b1..c662cc12 100644 --- a/custom/src/test/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessorTest.java +++ b/custom/src/test/java/com/solarwinds/opentelemetry/extensions/SolarwindsProfilingSpanProcessorTest.java @@ -259,7 +259,6 @@ void onEndingShouldSetAttributeToOneWhenProfileHasSample() throws InvalidConfigE when(mockSpan.getSpanContext()).thenReturn(mockSpanContext); when(mockSpanContext.isSampled()).thenReturn(true); when(mockSpanContext.getTraceId()).thenReturn(traceId); - when(mockSpanContext.getSpanId()).thenReturn(spanId); profilerMock.when(Profiler::hasActiveProfiles).thenReturn(true); when(mockSpan.toSpanData()).thenReturn(mockSpanData); @@ -283,7 +282,6 @@ void onEndingShouldSetAttributeToZeroWhenProfileHasNoSample() throws InvalidConf profilerMock.when(Profiler::hasActiveProfiles).thenReturn(true); when(mockSpanContext.getTraceId()).thenReturn(traceId); - when(mockSpanContext.getSpanId()).thenReturn(spanId); when(mockSpan.toSpanData()).thenReturn(mockSpanData); when(mockSpanData.getParentSpanContext()).thenReturn(mockParentSpanContext); diff --git a/instrumentation/instrumentation-shared/src/main/java/com/solarwinds/opentelemetry/instrumentation/StatementTruncator.java b/instrumentation/instrumentation-shared/src/main/java/com/solarwinds/opentelemetry/instrumentation/StatementTruncator.java index c8967dce..123150f4 100644 --- a/instrumentation/instrumentation-shared/src/main/java/com/solarwinds/opentelemetry/instrumentation/StatementTruncator.java +++ b/instrumentation/instrumentation-shared/src/main/java/com/solarwinds/opentelemetry/instrumentation/StatementTruncator.java @@ -46,7 +46,7 @@ public static void maybeTruncateStatement(Context context) { getAttribute.setAccessible(true); sql = (String) getAttribute.invoke(span, DbAttributes.DB_QUERY_TEXT); } catch (Throwable throwable) { - logger.debug("Cannot execute method getAttribute: " + throwable); + logger.debug(() -> "Cannot execute method getAttribute: " + throwable); } if (sql == null) { return; @@ -60,12 +60,14 @@ public static void maybeTruncateStatement(Context context) { sql = sql.substring(0, sqlMaxLength); span.setAttribute(QueryTruncatedAttributeKey.KEY, true); span.setAttribute(DbAttributes.DB_QUERY_TEXT, sql); + int truncatedLength = sql.length(); logger.debug( - "SQL Query trimmed as its length [" - + sql.length() - + "] exceeds max [" - + sqlMaxLength - + "]"); + () -> + "SQL Query trimmed as its length [" + + truncatedLength + + "] exceeds max [" + + sqlMaxLength + + "]"); } } } diff --git a/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigContainer.java b/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigContainer.java index c1a278c5..cbd843bf 100644 --- a/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigContainer.java +++ b/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigContainer.java @@ -125,15 +125,17 @@ public void put(ConfigProperty propertyKey, Object value, boolean override) if (!override && configMap.containsKey( propertyKey)) { // the key was already inserted before, do NOT overwrite - if (!configMap.get(propertyKey).equals(value)) { + Object existingValue = configMap.get(propertyKey); + if (!existingValue.equals(value)) { logger.debug( - "key [" - + propertyKey - + "] is already defined with value [" - + configMap.get(propertyKey) - + "]. Ignoring new value [" - + value - + "]"); + () -> + "key [" + + propertyKey + + "] is already defined with value [" + + existingValue + + "]. Ignoring new value [" + + value + + "]"); } } else { if (value == null) { // Do not allow null via put by string value diff --git a/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigManager.java b/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigManager.java index 74c98c76..99c572fa 100644 --- a/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigManager.java +++ b/libs/config/src/main/java/com/solarwinds/joboe/config/ConfigManager.java @@ -60,9 +60,10 @@ public static void removeConfig(ConfigProperty configKey) { public static Object getConfig(ConfigProperty configKey) { if (SINGLETON.configs == null) { logger.debug( - "Failed to read config property [" - + configKey - + "] as agent is not initialized properly, config is null!"); + () -> + "Failed to read config property [" + + configKey + + "] as agent is not initialized properly, config is null!"); return null; } @@ -73,9 +74,10 @@ public static Object getConfig(ConfigProperty configKey) { public static T getConfigOptional(ConfigProperty configKey, T defaultValue) { if (SINGLETON.configs == null) { logger.debug( - "Failed to read config property [" - + configKey - + "] as agent is not initialized properly, config is null!"); + () -> + "Failed to read config property [" + + configKey + + "] as agent is not initialized properly, config is null!"); return defaultValue; } Object value = SINGLETON.configs.get(configKey); diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/EventImpl.java b/libs/core/src/main/java/com/solarwinds/joboe/core/EventImpl.java index e00114e6..30dca34c 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/EventImpl.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/EventImpl.java @@ -244,7 +244,7 @@ public void addEdge(String hexstr) { try { addEdge(new Metadata(hexstr)); } catch (SamplingException ex) { - logger.debug("Invalid XTrace ID: " + hexstr, ex); + logger.debug(() -> "Invalid XTrace ID: " + hexstr, ex); } } @@ -308,9 +308,10 @@ public void report(Metadata contextMetadata, EventReporter reporter) { } } catch (EventReporterException e) { logger.trace( - "Failed to send out event, exception message [" - + e.getMessage() - + "]. Please take note that existing code flow should not be affected, this might only impact the instrumentation of current trace"); + () -> + "Failed to send out event, exception message [" + + e.getMessage() + + "]. Please take note that existing code flow should not be affected, this might only impact the instrumentation of current trace"); } catch (Throwable ex) { logger.error( "Failed to send out event, exception message [" @@ -433,10 +434,11 @@ private BsonDocument trimDoc(BsonDocument doc) { // will not fully utilize all the space available. logger.debug( - "Trimming KVs on other key count " - + otherKeyValues.size() - + " maxBytePerKeyValue " - + maxBytePerKeyValue); + () -> + "Trimming KVs on other key count " + + otherKeyValues.size() + + " maxBytePerKeyValue " + + maxBytePerKeyValue); // test buffer to check accumulative size of the bson document to be built ByteBuffer testBuffer = @@ -506,13 +508,15 @@ private BsonDocument trimDoc(BsonDocument doc) { } } else { // not string or object[], not going to trim try { + int bsonByteSize = getBsonByteSize(entry.getValue()); logger.debug( - "Skip " - + entry.getKey() - + " for trimming as it is type " - + (entry.getValue() != null ? entry.getValue().getClass().getName() : "null ") - + ". Estimated size is " - + getBsonByteSize(entry.getValue())); + () -> + "Skip " + + entry.getKey() + + " for trimming as it is type " + + (entry.getValue() != null ? entry.getValue().getClass().getName() : "null ") + + ". Estimated size is " + + bsonByteSize); } catch (IllegalArgumentException e) { logger.warn( "Skip " diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/EventValueConverter.java b/libs/core/src/main/java/com/solarwinds/joboe/core/EventValueConverter.java index c331d4a1..5829ab41 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/EventValueConverter.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/EventValueConverter.java @@ -138,9 +138,10 @@ private Object getValueFromSpecialType(Object parameter) { if (converter == null) { logger.debug( - "Class [" - + parameter.getClass().getName() - + "] is not in the expected list of classes for PreparedStatement parameter. Using the default handler"); + () -> + "Class [" + + parameter.getClass().getName() + + "] is not in the expected list of classes for PreparedStatement parameter. Using the default handler"); converter = DEFAULT_HANDLER; } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/NonThreadLocalTestReporter.java b/libs/core/src/main/java/com/solarwinds/joboe/core/NonThreadLocalTestReporter.java index a991ab52..c31c51ea 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/NonThreadLocalTestReporter.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/NonThreadLocalTestReporter.java @@ -43,7 +43,7 @@ public synchronized void reset() { public synchronized void send(Event event) { try { byte[] buf = event.toBytes(); - logger.debug("Sent " + buf.length + " bytes"); + logger.debug(() -> "Sent " + buf.length + " bytes"); byteBufferList.add(buf); } catch (BsonBufferException e) { logger.error("Failed to send events : " + e.getMessage(), e); diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/QueuingEventReporter.java b/libs/core/src/main/java/com/solarwinds/joboe/core/QueuingEventReporter.java index 26a866d4..898352b0 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/QueuingEventReporter.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/QueuingEventReporter.java @@ -96,7 +96,7 @@ public void onChange(Integer newValue) { static void setFlushInterval(int eventsFlushInterval) { if (eventsFlushInterval >= 0) { flushInterval = eventsFlushInterval; - logger.debug("Event flush interval set to " + eventsFlushInterval + "s"); + logger.debug(() -> "Event flush interval set to " + eventsFlushInterval + "s"); } else { logger.warn("Event flush interval value " + eventsFlushInterval + " is not valid"); } @@ -141,7 +141,7 @@ public void run() { ResultCode resultCode = result.getResultCode(); if (resultCode.isError()) { - logger.debug("Failed to send out " + sendingEvents.size() + " events"); + logger.debug(() -> "Failed to send out " + sendingEvents.size() + " events"); stats.incrementFailedCount(sendingEvents.size()); } else { stats.incrementSentCount(sendingEvents.size()); @@ -150,10 +150,11 @@ public void run() { } catch (Exception e) { // do not retry the message, just log the problem logger.debug( - "Failed to send " - + sendingEvents.size() - + " events, exception found: " - + e.getMessage()); // Should not be too noisy + () -> + "Failed to send " + + sendingEvents.size() + + " events, exception found: " + + e.getMessage()); // Should not be too noisy stats.incrementFailedCount(sendingEvents.size()); } finally { stats.incrementProcessedCount(sendingEvents.size()); @@ -253,7 +254,7 @@ public void close() { try { client.close(); boolean termination = executorService.awaitTermination(5, TimeUnit.SECONDS); - logger.debug(String.format("Event reporter service shut down: [%s]", termination)); + logger.debug(() -> String.format("Event reporter service shut down: [%s]", termination)); } catch (InterruptedException ignored) { } } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/TestReporter.java b/libs/core/src/main/java/com/solarwinds/joboe/core/TestReporter.java index 4cde670d..49d11d63 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/TestReporter.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/TestReporter.java @@ -54,7 +54,7 @@ public void reset() { public void send(Event event) { try { byte[] buf = event.toBytes(); - logger.debug("Sent " + buf.length + " bytes"); + logger.debug(() -> "Sent " + buf.length + " bytes"); byteBufList.get().add(buf); } catch (BsonBufferException e) { logger.error("Failed to send events : " + e.getMessage(), e); diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/profiler/Profiler.java b/libs/core/src/main/java/com/solarwinds/joboe/core/profiler/Profiler.java index dd18bfd7..020fbbb6 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/profiler/Profiler.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/profiler/Profiler.java @@ -139,10 +139,11 @@ public static void initialize(ProfilerSetting setting, EventReporter reporter) { Profiler.reporter = reporter; if (interval != 0) { - logger.debug("Starting profiler worker, previous status: " + status); + logger.debug(() -> "Starting profiler worker, previous status: " + status); start(); } else { - logger.debug("No profiling started. Profiler is on standby, previous status: " + status); + logger.debug( + () -> "No profiling started. Profiler is on standby, previous status: " + status); } addIntervalChangeListener(); // add listener here to avoid race condition on starting the @@ -206,8 +207,9 @@ static void run() { } } catch (InterruptedException e) { logger.debug( - "Profiler interrupted: " - + e.getMessage()); // hard to tell whether this is triggered by JVM + () -> + "Profiler interrupted: " + + e.getMessage()); // hard to tell whether this is triggered by JVM // shutdown status = Status.STOPPING; // flag it to stop } catch (Throwable e) { @@ -289,7 +291,9 @@ public static boolean addProfiledThread(Thread thread, Metadata metadata, String if (status != Status.RUNNING) { logger.debug( - "Add profile thread operation skipped as profiler is not running, status : " + status); + () -> + "Add profile thread operation skipped as profiler is not running, status : " + + status); return false; } @@ -302,12 +306,13 @@ public static boolean addProfiledThread(Thread thread, Metadata metadata, String if (profile.startProfilingOnThread(thread, metadata)) { logger.debug( - "Started profiling on Thread id: " - + thread.getId() - + " name: " - + thread.getName() - + " for trace: " - + traceId); + () -> + "Started profiling on Thread id: " + + thread.getId() + + " name: " + + thread.getName() + + " for trace: " + + traceId); return true; } else { return false; diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientLoggingCallback.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientLoggingCallback.java index 9e540138..21ead41b 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientLoggingCallback.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientLoggingCallback.java @@ -83,13 +83,14 @@ public void complete(T result) { + "]"); } else { logger.debug( - "Completed operation [" - + operation - + "] with Result code [" - + resultCode - + "] arg [" - + arg - + "]"); + () -> + "Completed operation [" + + operation + + "] with Result code [" + + resultCode + + "] arg [" + + arg + + "]"); } } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientManagerProvider.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientManagerProvider.java index 5371d508..7c9978b7 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientManagerProvider.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/ClientManagerProvider.java @@ -35,7 +35,7 @@ private ClientManagerProvider() {} } public static Optional getClientManager(Client.ClientType clientType) { - logger.debug("Using " + clientType + " for rpc calls"); + logger.debug(() -> "Using " + clientType + " for rpc calls"); return Optional.ofNullable(registeredManagers.get(clientType)); } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/KeepAliveMonitor.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/KeepAliveMonitor.java index 1eee51eb..b0939652 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/KeepAliveMonitor.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/KeepAliveMonitor.java @@ -40,7 +40,8 @@ public KeepAliveMonitor(Supplier protocolClient, String serviceK protocolClient.get().doPing(serviceKey); schedule(); // reschedule another keep alive ping } catch (Exception e) { - LoggerFactory.getLogger().debug("Keep alive ping failed [" + e.getMessage() + "]", e); + LoggerFactory.getLogger() + .debug(() -> "Keep alive ping failed [" + e.getMessage() + "]", e); // do not re-schedule another keep alive ping if it was having issues } } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcClient.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcClient.java index a3805613..b6723eee 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcClient.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcClient.java @@ -263,8 +263,9 @@ private T handleClientCall(Callable clientCall, RetryParams retryParams) } catch (Exception e) { if (RpcClient.this.isClosing) { logger.debug( - "Found exception during collector Client shutdown. This is probably not critical as the client is shutting down : " - + e.getMessage(), + () -> + "Found exception during collector Client shutdown. This is probably not critical as the client is shutting down : " + + e.getMessage(), e); return null; } else if (e instanceof ClientRecoverableException) { @@ -392,10 +393,10 @@ private synchronized void initClient() { boolean initClient = !RpcClient.this.isClosing; while (initClient) { - logger.debug("Creating collector client : " + host + ":" + port); + logger.debug(() -> "Creating collector client : " + host + ":" + port); try { protocolClient = protocolClientFactory.buildClient(host, port); - logger.debug("Created collector client : " + host + ":" + port); + logger.debug(() -> "Created collector client : " + host + ":" + port); connectionStatus = Status.OK; return; @@ -851,14 +852,20 @@ public boolean flagRetry(RetryType retryType, boolean resetOtherParams) { shouldRetry = maxRetryCount == null || retryCount <= maxRetryCount; if (!shouldRetry) { logger.debug( - "Not going to retry message as max retry count [" - + maxRetryCount - + "] is exceeded, cause: " - + retryType); + () -> + "Not going to retry message as max retry count [" + + maxRetryCount + + "] is exceeded, cause: " + + retryType); activeDelay = 0; } else { + int flaggedDelay = delay; logger.debug( - "Flagging to retry message with delay [" + delay + "] ms, cause: " + retryType); + () -> + "Flagging to retry message with delay [" + + flaggedDelay + + "] ms, cause: " + + retryType); activeDelay = delay; } @@ -894,11 +901,12 @@ public boolean retry() { if (shouldRetry) { try { if (activeDelay > 0) { - logger.debug("Collector client retry sleeping for " + activeDelay + " millisecs"); + logger.debug(() -> "Collector client retry sleeping for " + activeDelay + " millisecs"); TimeUnit.MILLISECONDS.sleep(activeDelay); } } catch (InterruptedException e) { - logger.debug("Collector client retry sleep is interrupted, message: " + e.getMessage()); + logger.debug( + () -> "Collector client retry sleep is interrupted, message: " + e.getMessage()); return false; // should not retry if sleep is interrupted } finally { activeDelay = 0; diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcSettings.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcSettings.java index b3df22e6..3f8c8068 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcSettings.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/RpcSettings.java @@ -88,7 +88,7 @@ private void readArgs(Map inputArgs) { for (Entry inputArg : inputArgs.entrySet()) { SettingsArg arg = SettingsArg.fromKey(inputArg.getKey()); if (arg == null) { - logger.debug("Cannot recognize argument [" + inputArg.getKey() + "], ignoring..."); + logger.debug(() -> "Cannot recognize argument [" + inputArg.getKey() + "], ignoring..."); } else { args.put(arg, arg.readFromByteBuffer(inputArg.getValue())); } @@ -112,7 +112,7 @@ public static short convertFlagsFromStringToShort(String stringFlags) { } else if ("PROFILING".equals(flagToken)) { flags |= OBOE_SETTINGS_FLAG_PROFILING; } else { - logger.debug("Unknown flag found from settings: " + flagToken); + logger.debug(() -> "Unknown flag found from settings: " + flagToken); } } return flags; diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/grpc/GrpcClient.java b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/grpc/GrpcClient.java index f75b171b..99cdcc92 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/grpc/GrpcClient.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/rpc/grpc/GrpcClient.java @@ -177,11 +177,12 @@ private Result postInBatch( .setIdentity(hostId) .setEncoding(Collector.EncodingType.BSON); logger.debug( - postAction.getDescription() - + " " - + itemsAsByteString.size() - + " item(s) using gRPC client hostId=" - + hostId); + () -> + postAction.getDescription() + + " " + + itemsAsByteString.size() + + " item(s) using gRPC client hostId=" + + hostId); try { builder.addAllMessages(itemsAsByteString); resultMessage = @@ -289,7 +290,7 @@ static class GrpcProtocolClientFactory implements ProtocolClientFactory "Using compression " + compression + " for gRPC client"); } GrpcProtocolClientFactory(URL serverCertLocation) throws IOException, GeneralSecurityException { diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/settings/PollingSettingsFetcher.java b/libs/core/src/main/java/com/solarwinds/joboe/core/settings/PollingSettingsFetcher.java index 61427225..3ac5806e 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/settings/PollingSettingsFetcher.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/settings/PollingSettingsFetcher.java @@ -122,7 +122,7 @@ public void run() { newSettings = reader.getSettings(); } catch (OboeSettingsException e) { logger.debug( - "Failed to get settings : " + e.getMessage(), + () -> "Failed to get settings : " + e.getMessage(), e); // Should not be too noisy as this might happen for intermittent connection // problem } @@ -144,9 +144,10 @@ public void run() { TimeUnit.SECONDS.sleep(refreshInterval); // sleep for the defined interval } catch (InterruptedException e) { logger.debug( - PollingSettingsFetcher.class.getName() - + " worker is interrupted : " - + e.getMessage()); + () -> + PollingSettingsFetcher.class.getName() + + " worker is interrupted : " + + e.getMessage()); running = false; } } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/settings/RpcSettingsReader.java b/libs/core/src/main/java/com/solarwinds/joboe/core/settings/RpcSettingsReader.java index fd46d6c9..3add9eb9 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/settings/RpcSettingsReader.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/settings/RpcSettingsReader.java @@ -53,7 +53,7 @@ public Settings getSettings() throws OboeSettingsException { try { result = rpcClient.getSettings(SSL_CLIENT_VERSION, loggingCallback).get(); if (result.getResultCode() == ResultCode.OK) { - logger.debug("Got settings from collector: " + result.getSettings().get(0)); + logger.debug(() -> "Got settings from collector: " + result.getSettings().get(0)); return result.getSettings().get(0); } } catch (Exception e) { diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/BackTraceUtil.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/BackTraceUtil.java index dc9d35c3..fc7eefb3 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/BackTraceUtil.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/BackTraceUtil.java @@ -35,9 +35,10 @@ public static StackTraceElement[] getBackTrace(int skipElements) { if (startPosition >= stackTrace.length) { logger.debug( - "Attempt to skip [" - + skipElements - + "] elements in addBackTrace is invalid, no stack trace element is left!"); + () -> + "Attempt to skip [" + + skipElements + + "] elements in addBackTrace is invalid, no stack trace element is left!"); return new StackTraceElement[0]; } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/ExecUtils.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/ExecUtils.java index d46d4615..7b297602 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/ExecUtils.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/ExecUtils.java @@ -59,7 +59,7 @@ public static String exec(String command, String newLine) throws Exception { String standardResult = inputStreamFuture.get(EXEC_TIMEOUT, TimeUnit.SECONDS); if (!errorResult.isEmpty()) { - logger.debug("exec " + command + " output to error stream : " + errorResult); + logger.debug(() -> "exec " + command + " output to error stream : " + errorResult); } return standardResult; diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/HostInfoUtils.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/HostInfoUtils.java index cb7c71f5..a2e65fa2 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/HostInfoUtils.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/HostInfoUtils.java @@ -37,7 +37,8 @@ public class HostInfoUtils { static { for (HostInfoReaderProvider provider : ServiceLoader.load(HostInfoReaderProvider.class)) { - logger.debug("Use HostInfoReaderProvider implementation " + provider.getClass().getName()); + logger.debug( + () -> "Use HostInfoReaderProvider implementation " + provider.getClass().getName()); HostInfoUtils.reader = provider.getHostInfoReader(); break; // use the first implementation found in the path } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/ServerHostInfoReader.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/ServerHostInfoReader.java index eb42f255..8e2f480c 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/ServerHostInfoReader.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/ServerHostInfoReader.java @@ -210,7 +210,7 @@ private static void buildNicStatusMap(Map nicStatusMap) { } String name = line.substring(0, statusStartPoint).trim(); NicStatus status = NicStatus.fromDesc(line.substring(statusStartPoint).trim()); - logger.debug("Get device display name=" + name + ", status=" + status); + logger.debug(() -> "Get device display name=" + name + ", status=" + status); nicStatusMap.put(name, status); } } @@ -238,23 +238,25 @@ public HostInfoUtils.NetworkAddressInfo getNetworkAddressInfo() { Collections.list(NetworkInterface.getNetworkInterfaces())) { try { logger.debug( - "Found network interface " - + networkInterface.getName() - + " " - + networkInterface.getDisplayName()); + () -> + "Found network interface " + + networkInterface.getName() + + " " + + networkInterface.getDisplayName()); if (!networkInterface.isLoopback() && !networkInterface.isPointToPoint() && isPhysicalInterface(networkInterface) && !isGhostHyperV(networkInterface)) { logger.debug( - "Processing physical network interface " - + networkInterface.getName() - + " " - + networkInterface.getDisplayName()); + () -> + "Processing physical network interface " + + networkInterface.getName() + + " " + + networkInterface.getDisplayName()); boolean hasIp = false; for (InetAddress address : Collections.list(networkInterface.getInetAddresses())) { String ipAddress = address.getHostAddress(); - logger.debug("Found ip address " + ipAddress); + logger.debug(() -> "Found ip address " + ipAddress); if (!ips.contains(ipAddress)) { ips.add(ipAddress); } @@ -265,19 +267,21 @@ && isPhysicalInterface(networkInterface) // https://github.com/librato/joboe/pull/1090 for details NicStatus status = nicStatusMap.get(networkInterface.getDisplayName()); logger.debug( - "Checking " - + networkInterface.getName() - + ", " - + networkInterface.getDisplayName() - + ", status=" - + status); + () -> + "Checking " + + networkInterface.getName() + + ", " + + networkInterface.getDisplayName() + + ", status=" + + status); if (!(NicStatus.UP.equals(status) || NicStatus.DISCONNECTED.equals(status))) { // ignore disabled/null NIC on Windows when "-Djava.net.preferIPv4Stack=true" is set logger.debug( - "Ignore disabled/null network adapter " - + networkInterface.getDisplayName() - + ", status=" - + status); + () -> + "Ignore disabled/null network adapter " + + networkInterface.getDisplayName() + + ", status=" + + status); continue; } // We cannot simply filter out NICs without an IP for all the scenarios. This is @@ -291,19 +295,21 @@ && isPhysicalInterface(networkInterface) // it doesn't have an IP address. if (NicStatus.UP.equals(status) && !hasIp) { logger.debug( - "Ignore network adapter which is up but no IP assigned: " - + networkInterface.getDisplayName()); + () -> + "Ignore network adapter which is up but no IP assigned: " + + networkInterface.getDisplayName()); continue; } } else if (!hasIp) { - logger.debug("Ignore network adapter without an IP: " + networkInterface.getName()); + logger.debug( + () -> "Ignore network adapter without an IP: " + networkInterface.getName()); continue; } // add mac addresses too byte[] hwAddr = networkInterface.getHardwareAddress(); if ((hwAddr != null) && (hwAddr.length != 0)) { String macAddress = getMacAddressFromBytes(hwAddr); - logger.debug("Found MAC address " + macAddress); + logger.debug(() -> "Found MAC address " + macAddress); if (!macAddresses.contains(macAddress)) { macAddresses.add(macAddress); } @@ -311,18 +317,20 @@ && isPhysicalInterface(networkInterface) } } catch (NoSuchMethodError e) { logger.debug( - "Failed to get network info for " - + networkInterface.getName() - + ", probably running JDK 1.5 or earlier"); + () -> + "Failed to get network info for " + + networkInterface.getName() + + ", probably running JDK 1.5 or earlier"); } catch (SocketException e) { logger.debug( - "Failed to get network info for " - + networkInterface.getName() - + ":" - + e.getMessage()); + () -> + "Failed to get network info for " + + networkInterface.getName() + + ":" + + e.getMessage()); } } - logger.debug("All MAC addresses accepted: " + Arrays.toString(macAddresses.toArray())); + logger.debug(() -> "All MAC addresses accepted: " + Arrays.toString(macAddresses.toArray())); return new HostInfoUtils.NetworkAddressInfo(ips, macAddresses); } catch (SocketException e) { logger.warn("Failed to get network info : " + e.getMessage()); @@ -381,7 +389,7 @@ private static boolean isGhostHyperV(NetworkInterface networkInterface) { && displayName.startsWith(hyperVprefix) && !networkInterface.isUp(); } catch (SocketException e) { - logger.debug("Cannot call isUp on " + networkInterface.getDisplayName(), e); + logger.debug(() -> "Cannot call isUp on " + networkInterface.getDisplayName(), e); return false; } } @@ -794,7 +802,8 @@ private void initialize() { if (instanceId != null) { // only proceed if instance id can be found availabilityZone = getResourceOnEndpoint(AVAILABILITY_ZONE_PATH, token); logger.debug( - "Found EC2 instance id " + instanceId + " availability zone: " + availabilityZone); + () -> + "Found EC2 instance id " + instanceId + " availability zone: " + availabilityZone); } awsMetadata = getMetadata(token); @@ -824,17 +833,20 @@ private static String useImdsV1(String relativePath) { } String payload = sb.toString(); - logger.debug(String.format("Retrieved metadata using IMDSv1: %s", payload)); + logger.debug(() -> String.format("Retrieved metadata using IMDSv1: %s", payload)); result.set(payload); } } else { logger.debug( - String.format( - "Failed to retrieved metadata using IMDSv1: status code=%d", statusCode)); + () -> + String.format( + "Failed to retrieved metadata using IMDSv1: status code=%d", + statusCode)); } } catch (IOException exception) { - logger.debug(String.format("Error retrieving metadata using IMDSv1: %s", exception)); + logger.debug( + () -> String.format("Error retrieving metadata using IMDSv1: %s", exception)); } finally { if (connection != null) { connection.disconnect(); @@ -877,12 +889,14 @@ private static String getApiToken() { } } else { logger.debug( - String.format( - "Failed to retrieved metadata request token: status code=%d", statusCode)); + () -> + String.format( + "Failed to retrieved metadata request token: status code=%d", + statusCode)); } } catch (IOException e) { - logger.debug(String.format("Error getting token for IMDSv2: %s", e)); + logger.debug(() -> String.format("Error getting token for IMDSv2: %s", e)); } finally { if (connection != null) { connection.disconnect(); @@ -916,17 +930,19 @@ private static String useImdsV2(String relativePath, String apiToken) { sb.append(line); } String payload = sb.toString(); - logger.debug(String.format("Retrieved metadata using IMDSv2: %s", payload)); + logger.debug(() -> String.format("Retrieved metadata using IMDSv2: %s", payload)); result.set(payload); } } else { logger.debug( - String.format( - "Failed to retrieved metadata using IMDSv2: status code=%d", statusCode)); + () -> + String.format( + "Failed to retrieved metadata using IMDSv2: status code=%d", + statusCode)); } } catch (IOException e) { - logger.debug(String.format("Error retrieving metadata using IMDSv2: %s", e)); + logger.debug(() -> String.format("Error retrieving metadata using IMDSv2: %s", e)); } finally { if (connection != null) { connection.disconnect(); @@ -955,12 +971,13 @@ private static HostId.AwsMetadata getMetadata(String token) { HostId.AwsMetadata metadata = HostId.AwsMetadata.fromJson( payload, getResourceOnEndpoint("latest/meta-data/hostname", token)); - logger.debug(String.format("Aws Metadata: %s", metadata)); + logger.debug(() -> String.format("Aws Metadata: %s", metadata)); return metadata; } catch (JSONException e) { logger.debug( - String.format("Error converting json to AwsMetadata model: %s\n %s", payload, e)); + () -> + String.format("Error converting json to AwsMetadata model: %s\n %s", payload, e)); } } return null; @@ -994,7 +1011,7 @@ private DockerInfoReader() { } if (dockerId != null) { - logger.debug("Found Docker instance ID :" + this.dockerId); + logger.debug(() -> "Found Docker instance ID :" + this.dockerId); } else { logger.debug("Cannot locate Docker id, not a Docker container"); } @@ -1038,7 +1055,7 @@ private static Optional getIdFromLine(String line) { return Optional.of(containerId); } else { - logger.debug(String.format("No container id in line: {%s}", line)); + logger.debug(() -> String.format("No container id in line: {%s}", line)); return Optional.empty(); } } @@ -1087,7 +1104,7 @@ public static String getDynoId() { private HerokuDynoReader() { this.dynoId = System.getenv(DYNO_ENV_VARIABLE); if (this.dynoId != null) { - logger.debug("Found Heroku Dyno ID: " + this.dynoId); + logger.debug(() -> "Found Heroku Dyno ID: " + this.dynoId); } } } @@ -1138,7 +1155,7 @@ private HostId.AzureVmMetadata getVmMetadata() { connection.setRequestProperty("Metadata", "true"); int statusCode = connection.getResponseCode(); - logger.debug(String.format("Azure IMDS status code: %s", statusCode)); + logger.debug(() -> String.format("Azure IMDS status code: %s", statusCode)); if (statusCode >= 200 && statusCode < 300) { try (BufferedReader reader = new BufferedReader(new InputStreamReader(connection.getInputStream()))) { @@ -1150,7 +1167,7 @@ private HostId.AzureVmMetadata getVmMetadata() { } String payload = sb.toString(); - logger.debug(String.format("Azure IMDS payload: %s", payload)); + logger.debug(() -> String.format("Azure IMDS payload: %s", payload)); result.set(HostId.AzureVmMetadata.fromJson(payload)); } } @@ -1169,10 +1186,10 @@ private HostId.AzureVmMetadata getVmMetadata() { private AzureReader() { this.appInstanceId = System.getenv(INSTANCE_ID_ENV_VARIABLE); if (this.appInstanceId != null) { - logger.debug("Found Azure instance ID: " + this.appInstanceId); + logger.debug(() -> "Found Azure instance ID: " + this.appInstanceId); } azureVmMetadata = getVmMetadata(); - logger.debug(String.format("Azure vm metadata: %s", azureVmMetadata)); + logger.debug(() -> String.format("Azure vm metadata: %s", azureVmMetadata)); } } @@ -1231,7 +1248,7 @@ private static String getPodId() { podId = line.substring(matcher.start(), matcher.end()); logger.info(String.format("Found pod uid: %s", podId)); } else { - logger.debug(String.format("Pod uid not found on line: %s", line)); + logger.debug(() -> String.format("Pod uid not found on line: %s", line)); } return Optional.ofNullable(podId); }); @@ -1257,7 +1274,7 @@ public static V fileReader(String filepath, Function> li .orElse(Optional.empty()); } catch (IOException e) { - logger.debug(String.format("Error reading file(%s). %s", filepath, e.getMessage())); + logger.debug(() -> String.format("Error reading file(%s). %s", filepath, e.getMessage())); } return value.orElse(null); } diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/TimeUtils.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/TimeUtils.java index 428f196e..7ebfb2c7 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/TimeUtils.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/TimeUtils.java @@ -115,8 +115,9 @@ private static boolean startAdjustBaseWorker(Integer paramValue) { } } catch (InterruptedException e) { logger.debug( - "Adjust time worker thread interrupted, probably due to shutdown : " - + e.getMessage()); + () -> + "Adjust time worker thread interrupted, probably due to shutdown : " + + e.getMessage()); } }) .start(); @@ -155,8 +156,9 @@ private static void adjustBase() { >= BAD_TIMESTAMP_THRESHOLD) { // avoid endless looping if a system never manage to get 2 // timestamps within a millisecond logger.debug( - "Aborting current time adjustment as system appears to be busy. Will try again in next cycle. Bad diffs: " - + badDiffs); + () -> + "Aborting current time adjustment as system appears to be busy. Will try again in next cycle. Bad diffs: " + + badDiffs); return; } } else if (diff diff --git a/libs/core/src/main/java/com/solarwinds/joboe/core/util/UamsClientIdReader.java b/libs/core/src/main/java/com/solarwinds/joboe/core/util/UamsClientIdReader.java index 9a2a8d3d..ff5e89fb 100644 --- a/libs/core/src/main/java/com/solarwinds/joboe/core/util/UamsClientIdReader.java +++ b/libs/core/src/main/java/com/solarwinds/joboe/core/util/UamsClientIdReader.java @@ -54,7 +54,7 @@ public class UamsClientIdReader { } else { uamsClientIdPath = Paths.get("/", "opt", "solarwinds", "uamsclient", "var", "uamsclientid"); } - logger.debug("Set uamsclientid path to " + uamsClientIdPath); + logger.debug(() -> "Set uamsclientid path to " + uamsClientIdPath); } public static String getUamsClientId() { @@ -64,10 +64,15 @@ public static String getUamsClientId() { lastModified.set(modifiedTime); uamsClientId.set(sanitize(readFirstLine(uamsClientIdPath))); logger.debug( - "Updated uamsclientid to " + uamsClientId.get() + ", lastModifiedTime=" + modifiedTime); + () -> + "Updated uamsclientid to " + + uamsClientId.get() + + ", lastModifiedTime=" + + modifiedTime); } } catch (IOException e) { - logger.debug(String.format("Cannot read the file[%s] due error: %s", uamsClientIdPath, e)); + logger.debug( + () -> String.format("Cannot read the file[%s] due error: %s", uamsClientIdPath, e)); getUamsClientIdViaRestApi().ifPresent(uamsClientId::set); } return uamsClientId.get(); @@ -100,18 +105,21 @@ static Optional getUamsClientIdViaRestApi() { String clientId = jsonPayload.getString("uamsclient_id"); logger.debug( - String.format( - "Got UAMS client ID(%s) from API, using hardcoded endpoint", clientId)); + () -> + String.format( + "Got UAMS client ID(%s) from API, using hardcoded endpoint", clientId)); result.set(Optional.ofNullable(clientId)); } else { logger.debug( - String.format( - "Request to UAMS REST endpoint failed. Status=%d, payload=%s", - statusCode, null)); + () -> + String.format( + "Request to UAMS REST endpoint failed. Status=%d, payload=%s", + statusCode, null)); } } catch (IOException | JSONException exception) { - logger.debug(String.format("Error reading from UAMS REST endpoint\n%s", exception)); + logger.debug( + () -> String.format("Error reading from UAMS REST endpoint\n%s", exception)); } finally { if (connection != null) { connection.disconnect(); @@ -142,7 +150,7 @@ private static String sanitize(String id) { } res = id; } catch (IllegalArgumentException e) { - logger.debug("Discarded invalid UAMS client id: " + id, e); + logger.debug(() -> "Discarded invalid UAMS client id: " + id, e); } return res; } diff --git a/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/AwsLambdaSettingsFetcher.java b/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/AwsLambdaSettingsFetcher.java index 8844e5b6..48fee791 100644 --- a/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/AwsLambdaSettingsFetcher.java +++ b/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/AwsLambdaSettingsFetcher.java @@ -47,7 +47,7 @@ public Settings getSettings() { } catch (SamplingException e) { logger.debug( - "Failed to get settings : " + e.getMessage(), + () -> "Failed to get settings : " + e.getMessage(), e); // Should not be too noisy as this might happen for intermittent connection problem } diff --git a/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/FileSettingsReader.java b/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/FileSettingsReader.java index 46a952bd..5d92974d 100644 --- a/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/FileSettingsReader.java +++ b/libs/lambda/src/main/java/com/solarwinds/opentelemetry/extensions/FileSettingsReader.java @@ -51,14 +51,14 @@ public Settings getSettings() throws SamplingException { List kvSetting = JsonSettingWrapper.fromJsonSettings( gson.fromJson(new String(bytes, StandardCharsets.UTF_8), type)); - logger.debug(String.format("Got settings from file: %s", kvSetting)); + logger.debug(() -> String.format("Got settings from file: %s", kvSetting)); if (!kvSetting.isEmpty()) { settings = kvSetting.get(0); } } catch (IOException e) { - logger.debug(String.format("Failed to read settings from file, error: %s", e)); + logger.debug(() -> String.format("Failed to read settings from file, error: %s", e)); throw new SamplingException("Error reading settings from file"); } return settings; diff --git a/libs/logging/src/main/java/com/solarwinds/joboe/logging/FileLoggerStream.java b/libs/logging/src/main/java/com/solarwinds/joboe/logging/FileLoggerStream.java index 64b0a3f0..e667f46c 100644 --- a/libs/logging/src/main/java/com/solarwinds/joboe/logging/FileLoggerStream.java +++ b/libs/logging/src/main/java/com/solarwinds/joboe/logging/FileLoggerStream.java @@ -85,7 +85,7 @@ class FileLoggerStream implements LoggerStream, Closeable { } else { this.logFileLockPath = Paths.get(logFilePath.toString() + ".lock"); } - Logger.INSTANCE.debug("Using " + logFileLockPath + " for log file lock for file rolling"); + Logger.INSTANCE.debug(() -> "Using " + logFileLockPath + " for log file lock for file rolling"); this.maxSize = maxSizeInBytes; this.maxBackup = maxBackup; @@ -150,7 +150,7 @@ protected void log() { } catch (RejectedExecutionException e) { // use STD_STREAM_LOGGER as we do not want to submit more messages to this file logger STD_STREAM_LOGGER.debug( - "Failed to log message to file as queue is full " + e.getMessage(), e); + () -> "Failed to log message to file as queue is full " + e.getMessage(), e); } } @@ -168,7 +168,7 @@ protected void log() { } catch (RejectedExecutionException e) { // use STD_STREAM_LOGGER as we do not want to submit more messages to this file logger STD_STREAM_LOGGER.debug( - "Failed to log message to file as queue is full " + e.getMessage(), e); + () -> "Failed to log message to file as queue is full " + e.getMessage(), e); } } @@ -231,11 +231,12 @@ private boolean checkFile() throws IOException { try { if (shouldRollFile()) { // then see if files should be rolled Logger.INSTANCE.debug( - "Log file [" - + logFilePath - + "] exceeds " - + (maxSize / 1024 / 1024) - + " MB, attempt to roll the log files."); + () -> + "Log file [" + + logFilePath + + "] exceeds " + + (maxSize / 1024 / 1024) + + " MB, attempt to roll the log files."); boolean rolled = lockAndRollFile(); forcedReset = rolled; // always reset the channel if the rolling was successful } @@ -348,7 +349,7 @@ FileLockAndChannel tryLock() { return new FileLockAndChannel(lock, lockChannel); } } catch (IOException e) { - Logger.INSTANCE.debug("Failed to obtain lockChannel : " + e.getMessage(), e); + Logger.INSTANCE.debug(() -> "Failed to obtain lockChannel : " + e.getMessage(), e); } try { TimeUnit.MILLISECONDS.sleep(LOCK_RETRY_SLEEP); diff --git a/libs/logging/src/main/java/com/solarwinds/joboe/logging/Logger.java b/libs/logging/src/main/java/com/solarwinds/joboe/logging/Logger.java index 993e53b2..893adff8 100644 --- a/libs/logging/src/main/java/com/solarwinds/joboe/logging/Logger.java +++ b/libs/logging/src/main/java/com/solarwinds/joboe/logging/Logger.java @@ -27,7 +27,9 @@ import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.Objects; import java.util.Set; +import java.util.function.Supplier; import lombok.Getter; /** @@ -136,6 +138,14 @@ public void debug(String message, Throwable throwable) { this.log(Level.DEBUG, message, throwable); } + public void debug(Supplier messageSupplier) { + this.log(Level.DEBUG, messageSupplier); + } + + public void debug(Supplier messageSupplier, Throwable throwable) { + this.log(Level.DEBUG, messageSupplier, throwable); + } + public void trace(String message) { this.log(Level.TRACE, message); } @@ -144,6 +154,14 @@ public void trace(String message, Throwable throwable) { this.log(Level.TRACE, message, throwable); } + public void trace(Supplier messageSupplier) { + this.log(Level.TRACE, messageSupplier); + } + + public void trace(Supplier messageSupplier, Throwable throwable) { + this.log(Level.TRACE, messageSupplier, throwable); + } + public void log(Level level, String message) { log(level, message, null); } @@ -162,6 +180,32 @@ public void log(Level level, String message, Throwable t) { } } + public void log(Level level, Supplier messageSupplier) { + log(level, messageSupplier, null); + } + + /** + * Logs a message produced by the given supplier. The supplier is only evaluated when the message + * would actually be logged for the given {@code level}, avoiding the cost of constructing the + * message (e.g. string concatenation) when it would be discarded. + */ + public void log(Level level, Supplier messageSupplier, Throwable t) { + Objects.requireNonNull(messageSupplier, "messageSupplier"); + if (level == null) { + if (shouldLog(Level.ERROR)) { // missing level in the input has severity level of Level.ERROR + print(Level.ERROR, "Missing log Level for this log message!"); + } + + if (shouldLog( + DEFAULT_LOGGING)) { // the logging message itself takes the default logging level + print(DEFAULT_LOGGING, messageSupplier.get(), t); + } + + } else if (shouldLog(level)) { + print(level, messageSupplier.get(), t); + } + } + private void print(Level level, String message) { print(level, message, null); } diff --git a/libs/logging/src/test/java/com/solarwinds/joboe/logging/LoggerTest.java b/libs/logging/src/test/java/com/solarwinds/joboe/logging/LoggerTest.java index 09e0e695..1532a496 100644 --- a/libs/logging/src/test/java/com/solarwinds/joboe/logging/LoggerTest.java +++ b/libs/logging/src/test/java/com/solarwinds/joboe/logging/LoggerTest.java @@ -17,10 +17,15 @@ package com.solarwinds.joboe.logging; import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; import java.io.ByteArrayOutputStream; import java.io.PrintStream; import java.lang.reflect.Field; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.function.Supplier; import lombok.Getter; import org.junit.jupiter.api.Test; @@ -274,6 +279,70 @@ public void testOff() throws Exception { assertEquals(0, countOccurrence(errMessage, "fatal-exception")); } + @Test + public void testLazyMessageNotEvaluatedWhenBelowLevel() throws Exception { + Logger logger = new Logger(); + logger.configure( + LoggerConfiguration.builder().logSetting(getLogSetting(Logger.Level.INFO)).build()); + + ProxyLoggerStream proxyOutStream = new ProxyLoggerStream(); + ProxyLoggerStream proxyErrStream = new ProxyLoggerStream(); + setProxyStreams(logger, proxyOutStream, proxyErrStream); + + AtomicBoolean evaluated = new AtomicBoolean(false); + Supplier supplier = + () -> { + evaluated.set(true); + return "debug-lazy-message"; + }; + + logger.debug(supplier); + logger.debug(supplier, new Exception("debug-lazy-exception")); + + assertFalse( + evaluated.get(), "message supplier should not be evaluated when below the logging level"); + assertEquals(0, countOccurrence(proxyOutStream.getProxyOutput().toString(), "debug-lazy")); + } + + @Test + public void testLazyMessageEvaluatedWhenAtLevel() throws Exception { + Logger logger = new Logger(); + logger.configure( + LoggerConfiguration.builder().logSetting(getLogSetting(Logger.Level.DEBUG)).build()); + + ProxyLoggerStream proxyOutStream = new ProxyLoggerStream(); + ProxyLoggerStream proxyErrStream = new ProxyLoggerStream(); + setProxyStreams(logger, proxyOutStream, proxyErrStream); + + AtomicBoolean evaluated = new AtomicBoolean(false); + Supplier supplier = + () -> { + evaluated.set(true); + return "debug-lazy-message"; + }; + + logger.debug(supplier); + logger.debug(supplier, new Exception("debug-lazy-exception")); + + String outMessage = proxyOutStream.getProxyOutput().toString(); + assertTrue(evaluated.get(), "message supplier should be evaluated when at the logging level"); + assertEquals(2, countOccurrence(outMessage, "debug-lazy-message")); + assertEquals(1, countOccurrence(outMessage, "debug-lazy-exception")); + } + + @Test + public void testLazyMessageRejectsNullSupplier() throws Exception { + Logger logger = new Logger(); + logger.configure( + LoggerConfiguration.builder().logSetting(getLogSetting(Logger.Level.DEBUG)).build()); + + Supplier nullSupplier = null; + assertThrows(NullPointerException.class, () -> logger.debug(nullSupplier)); + assertThrows( + NullPointerException.class, + () -> logger.debug(nullSupplier, new Exception("debug-lazy-exception"))); + } + private void sendTestMessages(Logger logger) { logger.trace("trace-message"); logger.trace("trace-message", new Exception("trace-exception")); diff --git a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/Metadata.java b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/Metadata.java index 8e62dc3d..69d319f9 100644 --- a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/Metadata.java +++ b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/Metadata.java @@ -548,7 +548,7 @@ public static boolean isCompatible(String traceIdHex) { new Metadata(traceIdHex); return true; } catch (SamplingException e) { - logger.debug("X-Trace ID [" + traceIdHex + "] not compatible : " + e.getMessage()); + logger.debug(() -> "X-Trace ID [" + traceIdHex + "] not compatible : " + e.getMessage()); return false; } } @@ -620,7 +620,8 @@ static int getMaxBacktraces() { random = new XorShiftRng(new DevUrandomSeedGenerator()); } catch (SeedException e) { logger.debug( - "Failed to use /dev/urandom as seed generator. Error message : " + e.getMessage()); + () -> + "Failed to use /dev/urandom as seed generator. Error message : " + e.getMessage()); // try using the SecureRandomSeedGenerator instead random = new XorShiftRng(new SecureRandomSeedGenerator()); } diff --git a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/TraceDecisionUtil.java b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/TraceDecisionUtil.java index b12c7c98..b9809c8d 100644 --- a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/TraceDecisionUtil.java +++ b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/TraceDecisionUtil.java @@ -161,14 +161,14 @@ public static TraceDecision shouldTraceRequest( private static Metadata validateMetadata(String inXtraceId) { if (!Metadata.isCompatible(inXtraceId)) { - logger.debug("Not accepting X-Trace ID [" + inXtraceId + "] for trace continuation"); + logger.debug(() -> "Not accepting X-Trace ID [" + inXtraceId + "] for trace continuation"); return null; } try { Metadata inMetadata = new Metadata(inXtraceId); if (!inMetadata.isValid()) { - logger.debug("Invalid incoming x-trace ID [" + inXtraceId + "]"); + logger.debug(() -> "Invalid incoming x-trace ID [" + inXtraceId + "]"); return null; } return inMetadata; @@ -287,7 +287,7 @@ private static Map getBucketSettings( private static double getBucketSettingsArg(Settings settings, SettingsArg arg) { Double value = settings.getArgValue(arg); if (value == null) { - logger.debug("Cannot read settings arg " + arg); + logger.debug(() -> "Cannot read settings arg " + arg); return 0; } else if (value < 0) { logger.warn("Invalid negative value in settings arg " + arg); diff --git a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/XtraceOptions.java b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/XtraceOptions.java index 9e6ee664..8bd18abc 100644 --- a/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/XtraceOptions.java +++ b/libs/sampling/src/main/java/com/solarwinds/joboe/sampling/XtraceOptions.java @@ -130,8 +130,9 @@ static XtraceOptions getXtraceOptions( if (optionKey.isEmpty()) { // skip empty key if (!optionEntry.isEmpty()) { + String emptyKeyEntry = optionEntry; logger.debug( - "Skipped entry [" + optionEntry + "] in X-Trace-Options as the key is empty"); + () -> "Skipped entry [" + emptyKeyEntry + "] in X-Trace-Options as the key is empty"); } continue; } @@ -146,9 +147,10 @@ static XtraceOptions getXtraceOptions( options.put(option, true); } else { logger.debug( - "Duplicated option [" - + option.getKey() - + "] found in X-Trace-Options, ignoring..."); + () -> + "Duplicated option [" + + option.getKey() + + "] found in X-Trace-Options, ignoring..."); } } } else { @@ -161,11 +163,12 @@ static XtraceOptions getXtraceOptions( options.put(option, option.parseValueFromString(optionValueString)); } else { logger.debug( - "Duplicated option [" - + option.getKey() - + "] with value [" - + optionValueString - + "] found in X-Trace-Options, ignoring..."); + () -> + "Duplicated option [" + + option.getKey() + + "] with value [" + + optionValueString + + "] found in X-Trace-Options, ignoring..."); } } catch (InvalidValueXtraceOptionException e) { exceptions.add(e); diff --git a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/ResourceCustomizer.java b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/ResourceCustomizer.java index 44804802..03afa0a6 100644 --- a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/ResourceCustomizer.java +++ b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/ResourceCustomizer.java @@ -97,7 +97,8 @@ private void updateServiceKey(String serviceName) { ConfigManager.setConfig( ConfigProperty.AGENT_SERVICE_KEY, String.format("%s:%s", apiKey, serviceName)); } catch (InvalidConfigException ignore) { - LoggerFactory.getLogger().debug("Failed to update service key with name: " + serviceName); + LoggerFactory.getLogger() + .debug(() -> "Failed to update service key with name: " + serviceName); } } } diff --git a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsSampler.java b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsSampler.java index 995b3443..9857677b 100644 --- a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsSampler.java +++ b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/SolarwindsSampler.java @@ -164,7 +164,7 @@ public SamplingResult shouldSample( TraceStateSamplingResult.wrap( samplingResult, additionalAttributesBuilder.build(), xtraceOptionsResponseStr); - logger.trace(String.format("Sampling decision: %s", result.getDecision())); + logger.trace(() -> String.format("Sampling decision: %s", result.getDecision())); return result; } @@ -191,7 +191,8 @@ String constructUrl(Attributes attributes) { url = builder.toString(); } - logger.trace(String.format("Constructed url: %s", url)); + String constructedUrl = url; + logger.trace(() -> String.format("Constructed url: %s", constructedUrl)); return url; } diff --git a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/TransactionNameManager.java b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/TransactionNameManager.java index 1e90026b..daed8e76 100644 --- a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/TransactionNameManager.java +++ b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/TransactionNameManager.java @@ -151,14 +151,16 @@ static String truncateTransactionName(String inputTransactionName) { } if (!transactionName.equalsIgnoreCase(inputTransactionName)) { + String truncatedName = transactionName; logger.debug( - "Transaction name [" - + inputTransactionName - + "] was truncated to [" - + transactionName - + "] because it exceeds " - + MAX_TRANSACTION_NAME_LENGTH - + " characters."); + () -> + "Transaction name [" + + inputTransactionName + + "] was truncated to [" + + truncatedName + + "] because it exceeds " + + MAX_TRANSACTION_NAME_LENGTH + + " characters."); } return transactionName; @@ -168,19 +170,21 @@ static String buildTransactionName(SpanData spanData) { Attributes spanAttributes = spanData.getAttributes(); String transactionName = spanAttributes.get(TRANSACTION_NAME_KEY); if (transactionName != null && !transactionName.isEmpty()) { - logger.trace(String.format("Using pre-computed transaction name -> %s", transactionName)); + String preComputedName = transactionName; + logger.trace( + () -> String.format("Using pre-computed transaction name -> %s", preComputedName)); return transactionName; } String custName = CustomTransactionNameDict.get(spanData.getTraceId()); if (custName != null) { - logger.trace(String.format("Using custom transaction name -> %s", custName)); + logger.trace(() -> String.format("Using custom transaction name -> %s", custName)); return custName; } String name = namingScheme.createName(spanAttributes); if (name != null && !name.isEmpty()) { - logger.trace(String.format("Using scheme derived transaction name -> %s", name)); + logger.trace(() -> String.format("Using scheme derived transaction name -> %s", name)); return name; } @@ -188,14 +192,15 @@ static String buildTransactionName(SpanData spanData) { // MVC) String handlerName = spanAttributes.get(handlerNameKey); if (handlerName != null) { - logger.trace(String.format("Using HandlerName(%s) as the transaction name", handlerName)); + logger.trace( + () -> String.format("Using HandlerName(%s) as the transaction name", handlerName)); return handlerName; } // use "http.route" String httpRoute = spanAttributes.get(HttpAttributes.HTTP_ROUTE); if (httpRoute != null) { - logger.trace(String.format("Using http.route (%s) as the transaction name", httpRoute)); + logger.trace(() -> String.format("Using http.route (%s) as the transaction name", httpRoute)); return httpRoute; } @@ -213,10 +218,12 @@ static String buildTransactionName(SpanData spanData) { path, customTransactionNamePattern, false, CUSTOM_TRANSACTION_NAME_PATTERN_SEPARATOR); if (transactionName != null) { + String customPatternName = transactionName; logger.trace( - String.format( - "Using custom configure pattern to extract transaction name: (%s)", - transactionName)); + () -> + String.format( + "Using custom configure pattern to extract transaction name: (%s)", + customPatternName)); return transactionName; } } @@ -230,13 +237,15 @@ static String buildTransactionName(SpanData spanData) { DEFAULT_TRANSACTION_NAME_PATTERN_SEPARATOR); if (transactionNameByUrl != null) { logger.trace( - String.format( - "Using token name pattern to extract transaction name: (%s)", transactionNameByUrl)); + () -> + String.format( + "Using token name pattern to extract transaction name: (%s)", + transactionNameByUrl)); return transactionNameByUrl; } String spanName = spanData.getName(); - logger.trace(String.format("Using span name as the transaction name: (%s)", spanName)); + logger.trace(() -> String.format("Using span name as the transaction name: (%s)", spanName)); return spanName; } @@ -333,9 +342,10 @@ public static boolean isLimitExceeded() { public static void clearTransactionNames() { logger.trace( - String.format( - "Clearing transaction name buffer. Unique transaction count: %d. Note: This log line is used for validation", - EXISTING_TRANSACTION_NAMES.size())); + () -> + String.format( + "Clearing transaction name buffer. Unique transaction count: %d. Note: This log line is used for validation", + EXISTING_TRANSACTION_NAMES.size())); synchronized (EXISTING_TRANSACTION_NAMES) { EXISTING_TRANSACTION_NAMES.clear(); diff --git a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/config/JsonSettingWrapper.java b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/config/JsonSettingWrapper.java index d1250c85..804ac5b9 100644 --- a/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/config/JsonSettingWrapper.java +++ b/libs/shared/src/main/java/com/solarwinds/opentelemetry/extensions/config/JsonSettingWrapper.java @@ -62,7 +62,7 @@ public short getFlags() { } else if ("PROFILING".equals(flagToken)) { flags |= OBOE_SETTINGS_FLAG_PROFILING; } else { - LoggerFactory.getLogger().debug("Unknown flag found from settings: " + flagToken); + LoggerFactory.getLogger().debug(() -> "Unknown flag found from settings: " + flagToken); } } return flags; diff --git a/libs/shared/src/test/java/com/solarwinds/opentelemetry/extensions/NamingSchemeTest.java b/libs/shared/src/test/java/com/solarwinds/opentelemetry/extensions/NamingSchemeTest.java index f0fa113f..adfcadd8 100644 --- a/libs/shared/src/test/java/com/solarwinds/opentelemetry/extensions/NamingSchemeTest.java +++ b/libs/shared/src/test/java/com/solarwinds/opentelemetry/extensions/NamingSchemeTest.java @@ -19,7 +19,7 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertTrue; -import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyString; import static org.mockito.Mockito.doNothing; import static org.mockito.Mockito.mockStatic; import static org.mockito.Mockito.verify; @@ -76,7 +76,7 @@ void verifyThatSchemeOrderIsRetained() { void verifyThatNullSchemeIsIgnored() { try (MockedStatic loggerFactoryMockedStatic = mockStatic(LoggerFactory.class)) { loggerFactoryMockedStatic.when(LoggerFactory::getLogger).thenReturn(loggerMock); - doNothing().when(loggerMock).debug(any()); + doNothing().when(loggerMock).debug(anyString()); NamingScheme.createDecisionChain(Collections.singletonList(null)); diff --git a/settings.gradle.kts b/settings.gradle.kts index 85dc7d02..26ac4f60 100644 --- a/settings.gradle.kts +++ b/settings.gradle.kts @@ -50,4 +50,5 @@ include("libs:config") include("libs:logging") include("libs:sampling") include("testing:feature-tests") +include("benchmarks")