diff --git a/build.gradle.kts b/build.gradle.kts index 394e7cd6..d1fbdef1 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -40,7 +40,7 @@ subprojects { } dependencies { - implementation(rootProject.libs.slf4j.api) + implementation(rootProject.libs.slog) compileOnly(rootProject.libs.lombok) annotationProcessor(rootProject.libs.lombok) diff --git a/client/src/main/java/io/oxia/client/SequenceUpdates.java b/client/src/main/java/io/oxia/client/SequenceUpdates.java index a1dcb521..35c3c53c 100644 --- a/client/src/main/java/io/oxia/client/SequenceUpdates.java +++ b/client/src/main/java/io/oxia/client/SequenceUpdates.java @@ -15,6 +15,7 @@ */ package io.oxia.client; +import io.github.merlimat.slog.Logger; import io.grpc.ClientCall; import io.grpc.stub.StreamObserver; import io.opentelemetry.api.common.Attributes; @@ -31,11 +32,11 @@ import java.util.function.Consumer; import java.util.function.Function; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class SequenceUpdates implements Closeable, StreamObserver { + private static final Logger log = Logger.get(SequenceUpdates.class); + private final String key; private final String partitionKey; @@ -108,7 +109,7 @@ public synchronized void onError(Throwable t) { if (closed || isClientClosed.apply(null)) { return; } - log.warn("Failure while processing sequence updates: {}", t.getMessage(), t); + log.warn().exception(t).log("Failure while processing sequence updates"); createStream(); } diff --git a/client/src/main/java/io/oxia/client/grpc/OxiaStub.java b/client/src/main/java/io/oxia/client/grpc/OxiaStub.java index 025378a4..76d4c610 100644 --- a/client/src/main/java/io/oxia/client/grpc/OxiaStub.java +++ b/client/src/main/java/io/oxia/client/grpc/OxiaStub.java @@ -35,9 +35,7 @@ import java.util.concurrent.Executor; import javax.annotation.Nullable; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class OxiaStub implements AutoCloseable { public static String TLS_SCHEMA = "tls://"; private final ManagedChannel channel; diff --git a/client/src/main/java/io/oxia/client/grpc/OxiaWriteStreamManager.java b/client/src/main/java/io/oxia/client/grpc/OxiaWriteStreamManager.java index 8022958b..09a60545 100644 --- a/client/src/main/java/io/oxia/client/grpc/OxiaWriteStreamManager.java +++ b/client/src/main/java/io/oxia/client/grpc/OxiaWriteStreamManager.java @@ -49,7 +49,8 @@ public WriteStreamWrapper getWriteStream(long shardId) { final var asyncStub = provider.getStubForShard(shardId).async(); return new WriteStreamWrapper( asyncStub.withInterceptors( - MetadataUtils.newAttachHeadersInterceptor(headers))); + MetadataUtils.newAttachHeadersInterceptor(headers)), + shardId); }); } if (wrapper.isValid()) { diff --git a/client/src/main/java/io/oxia/client/grpc/WriteStreamWrapper.java b/client/src/main/java/io/oxia/client/grpc/WriteStreamWrapper.java index 20bb58d3..b44c7174 100644 --- a/client/src/main/java/io/oxia/client/grpc/WriteStreamWrapper.java +++ b/client/src/main/java/io/oxia/client/grpc/WriteStreamWrapper.java @@ -15,6 +15,7 @@ */ package io.oxia.client.grpc; +import io.github.merlimat.slog.Logger; import io.grpc.stub.StreamObserver; import io.oxia.proto.OxiaClientGrpc; import io.oxia.proto.WriteRequest; @@ -24,18 +25,19 @@ import java.util.Optional; import java.util.concurrent.CancellationException; import java.util.concurrent.CompletableFuture; -import lombok.extern.slf4j.Slf4j; -@Slf4j public final class WriteStreamWrapper implements StreamObserver { + private final Logger log; + private final StreamObserver clientStream; private final Deque> pendingWrites; private volatile boolean completed; private volatile Throwable completedException; - public WriteStreamWrapper(OxiaClientGrpc.OxiaClientStub stub) { + public WriteStreamWrapper(OxiaClientGrpc.OxiaClientStub stub, long shardId) { + this.log = Logger.get(WriteStreamWrapper.class).with().attr("shard", shardId).build(); this.pendingWrites = new ArrayDeque<>(); this.completed = false; this.completedException = null; @@ -62,10 +64,11 @@ public void onError(Throwable error) { completedException = error; completed = true; if (!pendingWrites.isEmpty()) { - log.warn( - "Receive error when writing data to server through the stream, prepare to fail pending requests. pendingWrites={} {}", - pendingWrites.size(), - completedException.getMessage()); + log.warn() + .attr("pendingWrites", pendingWrites.size()) + .exceptionMessage(completedException) + .log( + "Receive error when writing data to server through the stream, prepare to fail pending requests"); } pendingWrites.forEach(f -> f.completeExceptionally(completedException)); pendingWrites.clear(); @@ -77,9 +80,10 @@ public void onCompleted() { synchronized (WriteStreamWrapper.this) { completed = true; if (!pendingWrites.isEmpty()) { - log.info( - "Receive stream close signal when writing data to server through the stream, prepare to cancel pending requests. pendingWrites={}", - pendingWrites.size()); + log.info() + .attr("pendingWrites", pendingWrites.size()) + .log( + "Receive stream close signal when writing data to server through the stream, prepare to cancel pending requests"); } pendingWrites.forEach(f -> f.completeExceptionally(new CancellationException())); pendingWrites.clear(); @@ -98,9 +102,7 @@ public CompletableFuture send(WriteRequest request) { } final CompletableFuture future = new CompletableFuture<>(); try { - if (log.isDebugEnabled()) { - log.debug("Sending request {}", request); - } + log.debug().attr("request", request).log("Sending request"); clientStream.onNext(request); pendingWrites.add(future); } catch (Exception e) { diff --git a/client/src/main/java/io/oxia/client/notify/NotificationManager.java b/client/src/main/java/io/oxia/client/notify/NotificationManager.java index c9c9a233..97a91251 100644 --- a/client/src/main/java/io/oxia/client/notify/NotificationManager.java +++ b/client/src/main/java/io/oxia/client/notify/NotificationManager.java @@ -34,9 +34,7 @@ import java.util.function.Consumer; import lombok.Getter; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class NotificationManager implements AutoCloseable, Consumer { private final ConcurrentMap shardReceivers = new ConcurrentHashMap<>(); diff --git a/client/src/main/java/io/oxia/client/notify/ShardNotificationReceiver.java b/client/src/main/java/io/oxia/client/notify/ShardNotificationReceiver.java index 2684f5f9..0a12fc65 100644 --- a/client/src/main/java/io/oxia/client/notify/ShardNotificationReceiver.java +++ b/client/src/main/java/io/oxia/client/notify/ShardNotificationReceiver.java @@ -18,6 +18,7 @@ import static io.oxia.client.api.Notification.KeyModified; import static lombok.AccessLevel.PACKAGE; +import io.github.merlimat.slog.Logger; import io.grpc.stub.StreamObserver; import io.oxia.client.CompositeConsumer; import io.oxia.client.api.Notification; @@ -35,11 +36,11 @@ import lombok.Getter; import lombok.NonNull; import lombok.RequiredArgsConstructor; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class ShardNotificationReceiver implements Closeable, StreamObserver { + private final Logger log; + private final OxiaStubManager manager; private final String leader; private final NotificationManager notificationManager; @@ -68,6 +69,7 @@ public class ShardNotificationReceiver implements Closeable, StreamObserver { - if (log.isDebugEnabled()) { - log.debug("--- Got notification: {} - {}", key, notification.getType()); - } + log.debug().attr("key", key).attr("type", notification.getType()).log("Got notification"); var n = switch (notification.getType()) { @@ -125,17 +125,16 @@ public void onError(Throwable t) { } long retryDelayMillis = backoff.nextDelayMillis(); - log.warn( - "Error while receiving notifications for shard={}: {} - Retrying in {} seconds", - shardId, - t.getMessage(), - retryDelayMillis / 1000.0); + log.warn() + .attr("retryInSeconds", retryDelayMillis / 1000.0) + .exceptionMessage(t) + .log("Error while receiving notifications"); notificationManager .getExecutor() .schedule( () -> { if (!closed) { - log.info("Retrying getting notifications for shard={}", shardId); + log.info("Retrying getting notifications"); start(); } }, diff --git a/client/src/main/java/io/oxia/client/session/Session.java b/client/src/main/java/io/oxia/client/session/Session.java index 01f9cf92..c3df2cac 100644 --- a/client/src/main/java/io/oxia/client/session/Session.java +++ b/client/src/main/java/io/oxia/client/session/Session.java @@ -20,6 +20,7 @@ import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Throwables; +import io.github.merlimat.slog.Logger; import io.grpc.stub.StreamObserver; import io.opentelemetry.api.common.Attributes; import io.oxia.client.ClientConfig; @@ -38,11 +39,11 @@ import java.util.concurrent.TimeUnit; import lombok.Getter; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class Session implements StreamObserver { + private final @NonNull Logger log; + private final @NonNull OxiaStubProvider stubProvider; private final @NonNull Duration sessionTimeout; private final @NonNull Duration heartbeatInterval; @@ -89,12 +90,15 @@ public class Session implements StreamObserver { this.heartbeat = new SessionHeartbeat(); this.heartbeat.setShard(shardId).setSessionId(sessionId); this.listener = listener; + this.log = + Logger.get(Session.class) + .with() + .attr("shard", shardId) + .attr("sessionId", sessionId) + .attr("clientIdentity", config.clientIdentifier()) + .build(); - log.info( - "Session created shard={} sessionId={} clientIdentity={}", - shardId, - sessionId, - config.clientIdentifier()); + log.info("Session created"); this.sessionsOpened = instrumentProvider.newCounter( @@ -125,7 +129,9 @@ public class Session implements StreamObserver { try { sendKeepAlive(); } catch (Throwable ex) { - log.warn("receive error when send keep-alive request", Throwables.getRootCause(ex)); + log.warn() + .exception(Throwables.getRootCause(ex)) + .log("receive error when send keep-alive request"); } }, heartbeatInterval.toMillis(), @@ -147,23 +153,12 @@ private void sendKeepAlive() { @Override public void onNext(KeepAliveResponse value) { lastSuccessfullResponse = Instant.now(); - if (log.isDebugEnabled()) { - log.debug( - "Received keep-alive response shard={} sessionId={} clientIdentity={}", - shardId, - sessionId, - clientIdentifier); - } + log.debug("Received keep-alive response"); } @Override public void onError(Throwable t) { - log.warn( - "Error during session keep-alive shard={} sessionId={} clientIdentity={}: {}", - shardId, - sessionId, - clientIdentifier, - t.getMessage()); + log.warn().exceptionMessage(t).log("Error during session keep-alive"); } @Override @@ -173,11 +168,7 @@ public void onCompleted() { private void handleSessionExpired() { sessionsExpired.increment(); - log.warn( - "Session expired shard={} sessionId={} clientIdentity={}", - shardId, - sessionId, - clientIdentifier); + log.warn("Session expired"); close(); } @@ -198,11 +189,7 @@ public CompletableFuture close() { return future.whenComplete( (__, ignore) -> { listener.onSessionClosed(Session.this); - log.info( - "Session closed shard={} sessionId={} clientIdentity={}", - shardId, - sessionId, - clientIdentifier); + log.info("Session closed"); }); } } diff --git a/client/src/main/java/io/oxia/client/session/SessionManager.java b/client/src/main/java/io/oxia/client/session/SessionManager.java index 0e99f703..be6967bb 100644 --- a/client/src/main/java/io/oxia/client/session/SessionManager.java +++ b/client/src/main/java/io/oxia/client/session/SessionManager.java @@ -28,9 +28,7 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.function.Consumer; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class SessionManager implements AutoCloseable, Consumer, SessionNotificationListener { diff --git a/client/src/main/java/io/oxia/client/shard/ShardManager.java b/client/src/main/java/io/oxia/client/shard/ShardManager.java index 8a801fd1..f059fb5f 100644 --- a/client/src/main/java/io/oxia/client/shard/ShardManager.java +++ b/client/src/main/java/io/oxia/client/shard/ShardManager.java @@ -24,6 +24,7 @@ import static java.util.stream.Collectors.toSet; import com.google.common.annotations.VisibleForTesting; +import io.github.merlimat.slog.Logger; import io.grpc.Status; import io.grpc.StatusRuntimeException; import io.grpc.stub.StreamObserver; @@ -48,10 +49,11 @@ import java.util.function.Consumer; import java.util.stream.Stream; import lombok.NonNull; -import lombok.extern.slf4j.Slf4j; -@Slf4j public class ShardManager implements AutoCloseable, StreamObserver { + + private static final Logger LOG = Logger.get(ShardManager.class); + private final Logger log; private final ScheduledExecutorService executor; private final OxiaStub stub; private final @NonNull ShardAssignmentsContainer assignments; @@ -75,6 +77,7 @@ public class ShardManager implements AutoCloseable, StreamObserver { if (!closed) { - log.info( - "Retry creating stream for shard assignments namespace={}", - assignments.getNamespace()); + log.info("Retry creating stream for shard assignments"); start(); } }, @@ -169,9 +170,7 @@ public void onCompleted() { executor.schedule( () -> { if (!closed) { - log.info( - "Retry creating stream for shard assignments after stream closed namespace={}", - assignments.getNamespace()); + log.info("Retry creating stream for shard assignments after stream closed"); start(); } }, @@ -213,7 +212,10 @@ static Map recomputeShardHashBoundaries( .findOverlapping(assignments.values()) .forEach( existing -> { - log.info("Deleting shard {} as it overlaps with {}", existing, update); + LOG.info() + .attr("existing", existing) + .attr("update", update) + .log("Deleting shard as it overlaps"); toDelete.add(existing.id()); })); diff --git a/client/src/test/java/io/oxia/client/batch/BatchTest.java b/client/src/test/java/io/oxia/client/batch/BatchTest.java index fb9297cd..59bd71f1 100644 --- a/client/src/test/java/io/oxia/client/batch/BatchTest.java +++ b/client/src/test/java/io/oxia/client/batch/BatchTest.java @@ -171,7 +171,7 @@ public void setUp() throws Exception { stub = new OxiaStub( InProcessChannelBuilder.forName(serverName).directExecutor().build(), authentication); - final WriteStreamWrapper writeStreamWrapper = new WriteStreamWrapper(stub.async()); + final WriteStreamWrapper writeStreamWrapper = new WriteStreamWrapper(stub.async(), 0L); clientByShardId = mock(OxiaStubProvider.class); lenient().when(clientByShardId.getStubForShard(anyLong())).thenReturn(stub); lenient() diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 7d389e2f..d2ed485f 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -6,7 +6,8 @@ opentelemetry = "1.57.0" opentelemetry-semconv = "1.37.0" junit = "5.11.3" guava = "33.5.0-jre" -slf4j = "1.7.32" +slf4j = "2.0.16" +slog = "0.9.1" lombok = "1.18.42" assertj = "3.27.7" awaitility = "4.2.2" @@ -39,6 +40,7 @@ junit-bom = { module = "org.junit:junit-bom", version.ref = "junit" } # Compile dependencies slf4j-api = { module = "org.slf4j:slf4j-api", version.ref = "slf4j" } +slog = { module = "io.github.merlimat.slog:slog", version.ref = "slog" } lombok = { module = "org.projectlombok:lombok", version.ref = "lombok" } guava = { module = "com.google.guava:guava", version.ref = "guava" } opentelemetry-api = { module = "io.opentelemetry:opentelemetry-api" } @@ -68,6 +70,7 @@ protobuf-java = { module = "com.google.protobuf:protobuf-java", version.ref = "p jackson-databind = { module = "com.fasterxml.jackson.core:jackson-databind", version.ref = "jackson" } jackson-core = { module = "com.fasterxml.jackson.core:jackson-core", version.ref = "jackson" } log4j-core = { module = "org.apache.logging.log4j:log4j-core", version.ref = "log4j" } +log4j-slf4j2-impl = { module = "org.apache.logging.log4j:log4j-slf4j2-impl", version.ref = "log4j" } bcpkix = { module = "org.bouncycastle:bcpkix-jdk18on", version.ref = "bouncy-castle" } # Perf dependencies diff --git a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/Worker.java b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/Worker.java index b61025b4..17c1644d 100644 --- a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/Worker.java +++ b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/Worker.java @@ -21,6 +21,7 @@ import com.fasterxml.jackson.databind.ObjectMapper; import com.google.common.collect.Lists; import com.google.common.util.concurrent.RateLimiter; +import io.github.merlimat.slog.Logger; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.common.Attributes; import io.opentelemetry.api.metrics.DoubleHistogram; @@ -48,11 +49,11 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicLong; import java.util.function.Function; -import lombok.extern.slf4j.Slf4j; -@Slf4j public final class Worker implements Runnable, Closeable, Operations { + private static final Logger log = Logger.get(Worker.class); + private static final ObjectMapper MAPPER = new ObjectMapper(); private final WorkerOptions options; private final SyncOxiaClient client; @@ -203,7 +204,7 @@ public Worker(WorkerOptions options, OpenTelemetry openTelemetry) { public void run() { try { final String optionsStr = MAPPER.writeValueAsString(options); - log.info("starting worker. the options={}", optionsStr); + log.info().attr("options", optionsStr).log("starting worker"); } catch (JsonProcessingException ex) { throw new WorkerException(ex); } @@ -240,7 +241,9 @@ public void run() { intervalOutput.report(internalSnapshotFunc.apply(lastSnapshotTime)); if (options.operationNum > 0) { - log.info("remain operation num {}", operationNum.get()); + log.info() + .attr("remainOperationNum", operationNum.get()) + .log("remain operation num"); } lastSnapshotTime = System.nanoTime(); } @@ -276,7 +279,7 @@ public void run() { } if (!sts.isSuccess()) { operationCounter.add(1, operationWriteFailedAttributes); - log.warn("write failed. the error info {}", sts.getErrorInfo()); + log.warn().attr("errorInfo", sts.getErrorInfo()).log("write failed"); final long latencyMicros = NANOSECONDS.toMicros(System.nanoTime() - start); operationLatency.record( latencyMicros / MICROS, operationWriteFailedAttributes); @@ -301,7 +304,7 @@ public void run() { final long latencyMicros = NANOSECONDS.toMicros(System.nanoTime() - start); operationLatency.record( latencyMicros / MICROS, operationReadFailedAttributes); - log.warn("read failed. the error info {}", sts.getErrorInfo()); + log.warn().attr("errorInfo", sts.getErrorInfo()).log("read failed"); globalReport.readFailed().increment(); intervalReport.readFailed().increment(); } else { diff --git a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/WorkerOptions.java b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/WorkerOptions.java index d22504b4..2714b359 100644 --- a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/WorkerOptions.java +++ b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/WorkerOptions.java @@ -18,13 +18,14 @@ import io.opentelemetry.sdk.autoconfigure.AutoConfiguredOpenTelemetrySdk; import io.oxia.client.OxiaClientBuilderImpl; import java.util.concurrent.TimeUnit; -import lombok.extern.slf4j.Slf4j; +import io.github.merlimat.slog.Logger; import picocli.CommandLine; -@Slf4j @CommandLine.Command(name = "ycsb") public final class WorkerOptions implements Runnable { + private static final Logger log = Logger.get(WorkerOptions.class); + @CommandLine.Option( names = {"--name"}, required = true, @@ -202,7 +203,7 @@ public void run() { Thread.sleep(TimeUnit.SECONDS.toMillis(elapsedMs)); } } catch (Throwable ex) { - log.error("unexpected error. ", ex); + log.error().exception(ex).log("unexpected error"); } } } diff --git a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/LogOutput.java b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/LogOutput.java index 393d2f09..611a5cc2 100644 --- a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/LogOutput.java +++ b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/LogOutput.java @@ -18,10 +18,11 @@ import com.fasterxml.jackson.annotation.JsonAutoDetect; import com.fasterxml.jackson.annotation.PropertyAccessor; import com.fasterxml.jackson.databind.ObjectMapper; -import lombok.extern.slf4j.Slf4j; +import io.github.merlimat.slog.Logger; -@Slf4j final class LogOutput implements Output { + + private static final Logger log = Logger.get(LogOutput.class); private static final ObjectMapper mapper = new ObjectMapper(); private final boolean pretty; diff --git a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/PulsarOutput.java b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/PulsarOutput.java index 8e17efb3..a65e6bc5 100644 --- a/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/PulsarOutput.java +++ b/perf-ycsb/src/main/java/io/oxia/client/perf/ycsb/output/PulsarOutput.java @@ -15,13 +15,14 @@ */ package io.oxia.client.perf.ycsb.output; +import io.github.merlimat.slog.Logger; import io.oxia.client.perf.ycsb.WorkerException; import java.io.IOException; -import lombok.extern.slf4j.Slf4j; import org.apache.pulsar.client.api.*; -@Slf4j final class PulsarOutput implements Output { + + private static final Logger log = Logger.get(PulsarOutput.class); private final PulsarClient client; private final Producer producer; @@ -46,7 +47,7 @@ public PulsarOutput(PulsarOutputOptions options) { public void report(BenchmarkReportSnapshot report) { try { final MessageId send = producer.send(report); - log.info("output to pulsar success, the response message id: {}", send); + log.info().attr("messageId", send).log("output to pulsar success"); } catch (Throwable e) { throw new WorkerException(e); } diff --git a/perf/build.gradle.kts b/perf/build.gradle.kts index 8a973374..a9c23780 100644 --- a/perf/build.gradle.kts +++ b/perf/build.gradle.kts @@ -21,6 +21,7 @@ plugins { application { mainClass.set("io.oxia.client.perf.PerfClient") + applicationDefaultJvmArgs = listOf("-Dlog4j.configurationFile=classpath:log4j2.xml") } dependencies { @@ -33,7 +34,8 @@ dependencies { implementation(libs.opentelemetry.sdk) implementation(libs.opentelemetry.sdk.autoconfigure) implementation(libs.hdr.histogram) - implementation(libs.slf4j.simple) + implementation(libs.log4j.core) + implementation(libs.log4j.slf4j2.impl) } tasks.shadowJar { diff --git a/perf/src/main/java/io/oxia/client/perf/PerfClient.java b/perf/src/main/java/io/oxia/client/perf/PerfClient.java index 16c53d82..d98f1b0e 100644 --- a/perf/src/main/java/io/oxia/client/perf/PerfClient.java +++ b/perf/src/main/java/io/oxia/client/perf/PerfClient.java @@ -32,14 +32,14 @@ import java.util.concurrent.Semaphore; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.LongAdder; -import java.util.function.Function; -import lombok.extern.slf4j.Slf4j; +import io.github.merlimat.slog.Logger; import org.HdrHistogram.Histogram; import org.HdrHistogram.Recorder; -@Slf4j public class PerfClient { + private static final Logger log = Logger.get(PerfClient.class); + private static final List keys = new ArrayList<>(); private static final LongAdder writeOps = new LongAdder(); private static final LongAdder readOps = new LongAdder(); @@ -115,25 +115,25 @@ public static void main(String[] args) throws Exception { writeReportHistogram = writeLatency.getIntervalHistogram(writeReportHistogram); readReportHistogram = readLatency.getIntervalHistogram(readReportHistogram); - log.info( + log.infof( """ - Stats - Total ops: {} ops/s - Failed ops: {} ops/s - Write ops {} w/s Latency ms: 50% {} - 95% {} - 99% {} - 99.9% {} - max {} - Read ops {} r/s Latency ms: 50% {} - 95% {} - 99% {} - 99.9% {} - max {}""", - INT_FORMAT.apply(writeRate + readRate), - INT_FORMAT.apply(failedWriteRate + failedReadRate), - INT_FORMAT.apply(writeRate), - DEC_FORMAT.apply(writeReportHistogram.getValueAtPercentile(50) / 1000.0), - DEC_FORMAT.apply(writeReportHistogram.getValueAtPercentile(95) / 1000.0), - DEC_FORMAT.apply(writeReportHistogram.getValueAtPercentile(99) / 1000.0), - DEC_FORMAT.apply(writeReportHistogram.getValueAtPercentile(99.9) / 1000.0), - DEC_FORMAT.apply(writeReportHistogram.getMaxValue() / 1000.0), - INT_FORMAT.apply(readRate), - DEC_FORMAT.apply(readReportHistogram.getValueAtPercentile(50) / 1000.0), - DEC_FORMAT.apply(readReportHistogram.getValueAtPercentile(95) / 1000.0), - DEC_FORMAT.apply(readReportHistogram.getValueAtPercentile(99) / 1000.0), - DEC_FORMAT.apply(readReportHistogram.getValueAtPercentile(99.9) / 1000.0), - DEC_FORMAT.apply(readReportHistogram.getMaxValue() / 1000.0)); + Stats - Total ops: %7.0f ops/s - Failed ops: %7.0f ops/s + Write ops %7.0f w/s Latency ms: 50%% %7.1f - 95%% %7.1f - 99%% %7.1f - 99.9%% %7.1f - max %7.1f + Read ops %7.0f r/s Latency ms: 50%% %7.1f - 95%% %7.1f - 99%% %7.1f - 99.9%% %7.1f - max %7.1f""", + writeRate + readRate, + failedWriteRate + failedReadRate, + writeRate, + writeReportHistogram.getValueAtPercentile(50) / 1000.0, + writeReportHistogram.getValueAtPercentile(95) / 1000.0, + writeReportHistogram.getValueAtPercentile(99) / 1000.0, + writeReportHistogram.getValueAtPercentile(99.9) / 1000.0, + writeReportHistogram.getMaxValue() / 1000.0, + readRate, + readReportHistogram.getValueAtPercentile(50) / 1000.0, + readReportHistogram.getValueAtPercentile(95) / 1000.0, + readReportHistogram.getValueAtPercentile(99) / 1000.0, + readReportHistogram.getValueAtPercentile(99.9) / 1000.0, + readReportHistogram.getMaxValue() / 1000.0); writeReportHistogram.reset(); readReportHistogram.reset(); @@ -168,7 +168,7 @@ private static void generateWriteTraffic(AsyncOxiaClient client) { }) .exceptionally( ex -> { - log.warn("Write operation failed {}", ex.getMessage()); + log.warn().exceptionMessage(ex).log("Write operation failed"); writeFailed.increment(); semaphore.release(); return null; @@ -201,7 +201,7 @@ private static void generateReadTraffic(AsyncOxiaClient client) { }) .exceptionally( ex -> { - log.warn("Read operation failed {}", ex.getMessage()); + log.warn().exceptionMessage(ex).log("Read operation failed"); readFailed.increment(); semaphore.release(); return null; @@ -209,6 +209,4 @@ private static void generateReadTraffic(AsyncOxiaClient client) { } } - static final Function DEC_FORMAT = d -> String.format("%7.1f", d); - static final Function INT_FORMAT = d -> String.format("%7.0f", d); } diff --git a/perf/src/main/resources/log4j2.xml b/perf/src/main/resources/log4j2.xml new file mode 100644 index 00000000..bcf906dd --- /dev/null +++ b/perf/src/main/resources/log4j2.xml @@ -0,0 +1,14 @@ + + + + + + + + + + + + + +