Skip to content

Commit

Permalink
Merge pull request #70 from hkupty/thread-stuff
Browse files Browse the repository at this point in the history
Refactor core mechanisms for thread-safety
  • Loading branch information
hkupty authored Nov 14, 2023
2 parents f3c3bde + f6b60fb commit 3ed1c56
Show file tree
Hide file tree
Showing 38 changed files with 1,150 additions and 608 deletions.
8 changes: 8 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,14 @@ the PATCH component is omitted when its value is `0`.

## Unreleased

### `penna-core`

#### Changed

- Restructured internal controls for better thread safety ([#70](https://github.com/hkupty/penna/pull/70))

## 0.7

### `penna-api`

#### Changed
Expand Down
1 change: 1 addition & 0 deletions penna-core/build.gradle
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ testing {
}
}
}

jmh(JvmTestSuite) {
testType = TestSuiteType.PERFORMANCE_TEST
dependencies {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,188 @@
package penna.core.logger;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.JsonEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.util.LogbackMDCAdapter;
import ch.qos.logback.core.OutputStreamAppender;
import org.junit.jupiter.api.Test;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.openjdk.jmh.runner.options.TimeValue;
import penna.api.config.Config;
import penna.core.logger.utils.LogbackDevNullAppender;
import penna.core.sink.CoreSink;
import penna.core.sink.SinkManager;

import java.io.File;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.IOException;
import java.util.Random;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.LockSupport;
import java.util.regex.Pattern;

public class CompleteUsecaseComparison {

@State(Scope.Thread)
public static class LogbackState {

@Param({
"1",
"4",
// "16",
// "64",
// "256"
})
int threads;

public final Random random = new Random();
LoggerContext context = new LoggerContext();

public org.slf4j.Logger getLogger(String name) {
Logger logger;
context.setName("JMH");
context.setMDCAdapter(new LogbackMDCAdapter());
logger = context.getLogger(name);
logger.setLevel(Level.INFO);
OutputStreamAppender<ILoggingEvent> appender = new LogbackDevNullAppender();

var encoder = new JsonEncoder();
encoder.start();
appender.setContext(context);
appender.setEncoder(encoder);
logger.addAppender(appender);

appender.start();
context.start();
return logger;
}

}

@State(Scope.Thread)
public static class PennaState {
private static final Pattern DOT_SPLIT = Pattern.compile("\\.");

@Param({
"1",
"4",
// "16",
// "64",
// "256"
})
int threads;

public final Random random = new Random();
private FileOutputStream fos;
TreeCache cache = new TreeCache(Config.getDefault());

@Setup
public void setup() {
var devnull = new File("/dev/null");
try {
fos = new FileOutputStream(devnull);
} catch (FileNotFoundException e) {
throw new RuntimeException("Dev null doesn't exist!", e);
}

SinkManager.Instance.replace(() -> new CoreSink(fos));
}
@TearDown
public void tearDown() throws IOException {
fos.close();
}


public org.slf4j.Logger getLogger(String name) {
return cache.getLoggerAt(DOT_SPLIT.split(name));
}
}

@Benchmark
public long penna(PennaState state) throws InterruptedException {
CountDownLatch latch = new CountDownLatch(state.threads);

for (int i = 0; i < state.threads; i++) {
int index = i;
Thread.ofVirtual()
.name("jmh-penna-", i)
.start(() -> {
try {
var logger = state.getLogger("jmh.penna.task" + index);
logger.info("Message 1");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 2");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 3");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 4");
} finally {
latch.countDown();
}
});
}

latch.await();

return System.currentTimeMillis();
}


// @Benchmark
public long logback(LogbackState state) throws InterruptedException {
CountDownLatch latch = new CountDownLatch(state.threads);

for (int i = 0; i < state.threads; i++) {
int index = i;
Thread.ofVirtual().name("jmh-logback-" + i).start(() -> {
try {
var logger = state.getLogger("jmh.logback.task" + index);
logger.info("Message 1");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 2");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 3");
LockSupport.parkNanos(180 + state.random.nextInt(0, 40));
logger.info("Message 4");
} finally {
latch.countDown();
}
});
}

latch.await();

return System.currentTimeMillis();
}


@Test
public void runBenchmarks() throws Exception {
Options options = new OptionsBuilder()
.include(this.getClass().getName() + ".*")
.mode(Mode.Throughput)
.timeUnit(TimeUnit.SECONDS)
.warmupTime(TimeValue.seconds(20))
.warmupIterations(3)
.measurementTime(TimeValue.seconds(50))
.measurementIterations(3)
.forks(1)
.shouldFailOnError(true)
.shouldDoGC(true)
.addProfiler("gc")
.threads(1)
.jvm("/usr/lib/jvm/java-21-jetbrains/bin/java")
.jvmArgs("-Xmx8192m")
.build();

new Runner(options).run();
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,119 @@
package penna.core.logger;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.JsonEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.util.LogbackMDCAdapter;
import ch.qos.logback.core.OutputStreamAppender;
import org.junit.jupiter.api.Test;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.openjdk.jmh.runner.options.TimeValue;
import penna.api.config.Config;
import penna.core.logger.utils.LogbackDevNullAppender;
import penna.core.sink.CoreSink;
import penna.core.sink.SinkManager;

import java.io.File;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.IOException;
import java.util.Random;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.LockSupport;
import java.util.regex.Pattern;

public class CompleteUsecasePerformanceTest {

@State(Scope.Thread)
public static class PennaState {
private static final Pattern DOT_SPLIT = Pattern.compile("\\.");

@Param({
"1",
// "4",
// "16",
// "64",
// "256"
})
int threads;

public final Random random = new Random();
private FileOutputStream fos;
TreeCache cache = new TreeCache(Config.getDefault());

@Setup
public void setup() {
var devnull = new File("/dev/null");
try {
fos = new FileOutputStream(devnull);
} catch (FileNotFoundException e) {
throw new RuntimeException("Dev null doesn't exist!", e);
}

SinkManager.Instance.replace(() -> new CoreSink(fos));
}
@TearDown
public void tearDown() throws IOException {
fos.close();
}


public org.slf4j.Logger getLogger(String name) {
return cache.getLoggerAt(DOT_SPLIT.split(name));
}
}

@Benchmark
public void penna(PennaState state) throws InterruptedException {
CountDownLatch latch = new CountDownLatch(state.threads);

for (int i = 0; i < state.threads; i++) {
int index = i;
Thread.ofVirtual()
.name("jmh-penna-", i)
.start(() -> {
try {
var logger = state.getLogger("jmh.penna.task" + index);
logger.info("Message 1");
logger.info("Message 2");
logger.info("Message 3");
logger.info("Message 4");
} finally {
latch.countDown();
}
});
}

latch.await();
}

@Test
public void runBenchmarks() throws Exception {
Options options = new OptionsBuilder()
.include(this.getClass().getName() + ".*")
.mode(Mode.Throughput)
.timeUnit(TimeUnit.SECONDS)
.warmupTime(TimeValue.seconds(20))
.warmupIterations(3)
.measurementIterations(3)
.forks(1)
.shouldFailOnError(true)
.shouldDoGC(false)
.addProfiler("gc")
.addProfiler("perfnorm")
.addProfiler("perfasm", "tooBigThreshold=2100")
.threads(1)
.jvm("/usr/lib/jvm/java-21-jetbrains/bin/java")
.jvmArgs("-Xmx8192m")
.build();

new Runner(options).run();
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.JsonEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.util.LogbackMDCAdapter;
import ch.qos.logback.core.OutputStreamAppender;
import ch.qos.logback.core.encoder.Encoder;
import net.logstash.logback.encoder.LogstashEncoder;
Expand Down Expand Up @@ -99,6 +100,7 @@ private Encoder<ILoggingEvent> getLogstashEncoder() {
@Setup
public void setup() {
context.setName("JMH");
context.setMDCAdapter(new LogbackMDCAdapter());
logger = context.getLogger("jmh.test.logback");
logger.setLevel(Level.INFO);
OutputStreamAppender<ILoggingEvent> appender = new LogbackDevNullAppender();
Expand Down Expand Up @@ -140,6 +142,7 @@ public void setup() throws IOException {

logger = cache.getLoggerAt("jmh", "test", "penna");
}

@TearDown
public void tearDown() throws IOException {
fos.close();
Expand All @@ -151,10 +154,10 @@ public void penna(PennaState state, TestBehavior tb) throws IOException {
tb.log(state.logger);
}

// @Benchmark
// public void logback(LogbackState state, TestBehavior tb) throws IOException {
// tb.log(state.logger);
// }
@Benchmark
public void logback(LogbackState state, TestBehavior tb) throws IOException {
tb.log(state.logger);
}

@Test
public void runBenchmarks() throws Exception {
Expand All @@ -171,7 +174,7 @@ public void runBenchmarks() throws Exception {
.addProfiler("gc")
.addProfiler("perfnorm")
.addProfiler("perfasm", "tooBigThreshold=2100")
.threads(4)
.threads(1)
.jvm("/usr/lib/jvm/java-21-jetbrains/bin/java")
.jvmArgs("-Xmx8192m")
.build();
Expand Down
Loading

0 comments on commit 3ed1c56

Please sign in to comment.