Added Log4j2 Appender (still WiP but seems to be working. Added tests.

This commit is contained in:
tomasz.kowalczewski committed 2020-10-18 22:00:37 +02:00
1 parent 89c6342d3f
commit e07322c25a
12 files changed
+633 -27

No files matched your search

@@ -1,16 +1,33 @@
package pl.tkowalcz.tjahzi;
import org.agrona.concurrent.AgentRunner;
import org.agrona.concurrent.ringbuffer.ManyToOneRingBuffer;
import java.util.function.Consumer;
public class LoggingSystem {
private final ManyToOneRingBuffer logBuffer;
private final AgentRunner runner;
public LoggingSystem(ManyToOneRingBuffer logBuffer) {
public LoggingSystem(
ManyToOneRingBuffer logBuffer,
AgentRunner runner
) {
this.logBuffer = logBuffer;
this.runner = runner;
}
public TjahziLogger createLogger() {
return new TjahziLogger(logBuffer);
}
public void close(
int retryCloseTimeoutMs,
Consumer<Thread> closeFailAction) {
runner.close(
retryCloseTimeoutMs,
closeFailAction
);
}
}
@@ -38,7 +38,8 @@ public class TjahziInitializer {
AgentRunner.startOnThread(runner);
return new LoggingSystem(
logBuffer
logBuffer,
runner
);
}
@@ -50,10 +50,44 @@ public class TjahziLogger {
return this;
}
private int calculateRequiredSizeAscii(
Map<String, String> labels,
String line
) {
public TjahziLogger log(long timestamp,
Map<String, String> labels,
byte[] line) {
int requiredSize = calculateRequiredSizeAscii(labels, line);
int claim = logBuffer.tryClaim(LOG_MESSAGE_TYPE_ID, requiredSize);
int cursor = claim;
if (requiredSize > 0) {
try {
AtomicBuffer buffer = this.logBuffer.buffer();
buffer.putLong(cursor, timestamp);
cursor += Long.BYTES;
buffer.putInt(cursor, labels.size());
cursor += Integer.BYTES;
for (Map.Entry<String, String> entry : labels.entrySet()) {
String key = entry.getKey();
String value = entry.getValue();
cursor += buffer.putStringAscii(cursor, key);
cursor += buffer.putStringAscii(cursor, value);
}
buffer.putInt(cursor, line.length);
cursor += Integer.BYTES;
buffer.putBytes(cursor, line);
logBuffer.commit(claim);
} catch (Throwable t) {
logBuffer.abort(claim);
}
}
return this;
}
private int calculateRequiredSizeAscii(Map<String, String> labels) {
return Long.BYTES +
Integer.BYTES +
labels
@@ -61,8 +95,22 @@ public class TjahziLogger {
.stream()
.mapToInt(entry -> entry.getKey().length() + entry.getValue().length())
.map(size -> size + 2 * Integer.BYTES)
.sum() +
line.length() + Integer.BYTES;
.sum();
}
private int calculateRequiredSizeAscii(
Map<String, String> labels,
String line
) {
return calculateRequiredSizeAscii(labels) +
line.length() + Integer.BYTES;
}
private int calculateRequiredSizeAscii(
Map<String, String> labels,
byte[] line
) {
return calculateRequiredSizeAscii(labels) +
line.length + Integer.BYTES;
}
}
-17
View File
@@ -1,17 +0,0 @@
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<logger name="curl" level="DEBUG">
<AppenderRef ref="Console"/>
</logger>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
+6 -2
View File
@@ -18,7 +18,6 @@
<version>${project.version}</version>
</dependency>
<!-- Binding for Log4J -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
@@ -42,7 +41,12 @@
<version>4.0.3</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.13.3</version>
<scope>test</scope>
</dependency>
<!-- Testcontainers -->
<dependency>
@@ -0,0 +1,30 @@
package pl.tkowalcz.tjahzi.log4j2;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.config.plugins.PluginValue;
import org.apache.logging.log4j.status.StatusLogger;
@Plugin(name = "header", category = Node.CATEGORY, printObject = true)
public class Header extends Property {
private static final Logger LOGGER = StatusLogger.getLogger();
protected Header(String name, String value) {
super(name, value);
}
@PluginFactory
public static Header createHeader(
@PluginAttribute("name") String name,
@PluginValue("value") String value) {
if (name == null) {
LOGGER.error("Property name cannot be null");
}
return new Header(name, value);
}
}
@@ -0,0 +1,30 @@
package pl.tkowalcz.tjahzi.log4j2;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.config.plugins.PluginValue;
import org.apache.logging.log4j.status.StatusLogger;
@Plugin(name = "label", category = Node.CATEGORY, printObject = true)
public class Label extends Property {
private static final Logger LOGGER = StatusLogger.getLogger();
private Label(String name, String value) {
super(name, value);
}
@PluginFactory
public static Label createLabel(
@PluginAttribute("name") String name,
@PluginValue("value") String value) {
if (name == null) {
LOGGER.error("Property name cannot be null");
}
return new Label(name, value);
}
}
@@ -0,0 +1,269 @@
package pl.tkowalcz.tjahzi.log4j2;
import com.google.common.collect.Maps;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Filter;
import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractAppender;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.Property;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderFactory;
import org.apache.logging.log4j.core.config.plugins.PluginElement;
import org.apache.logging.log4j.core.config.plugins.validation.constraints.Required;
import pl.tkowalcz.tjahzi.LoggingSystem;
import pl.tkowalcz.tjahzi.TjahziInitializer;
import pl.tkowalcz.tjahzi.http.ClientConfiguration;
import pl.tkowalcz.tjahzi.http.HttpClientFactory;
import pl.tkowalcz.tjahzi.http.NettyHttpClient;
import java.io.Serializable;
import java.util.Arrays;
import java.util.HashMap;
import java.util.Map;
import java.util.Objects;
import java.util.concurrent.TimeUnit;
/**
* Loki Appender.
*/
@Plugin(name = "Loki", category = Node.CATEGORY, elementType = Appender.ELEMENT_TYPE, printObject = true)
public class LokiAppender extends AbstractAppender {
/**
* Builds LokiAppender instances.
*
* @param <B> The type to build
*/
public static class Builder<B extends LokiAppender.Builder<B>> extends AbstractAppender.Builder<B>
implements org.apache.logging.log4j.core.util.Builder<LokiAppender> {
public static final int BYTES_IN_MEGABYTE = 1024 * 1024;
@PluginBuilderAttribute
@Required(message = "No Loki address provided for LokiAppender")
private String host;
@PluginBuilderAttribute
@Required(message = "No Loki port provided for LokiAppender")
private int port;
@PluginBuilderAttribute
private int connectTimeoutMillis = 0;
@PluginBuilderAttribute
private int readTimeoutMillis = 0;
@PluginBuilderAttribute
private int maxRetries = 0;
@PluginBuilderAttribute
private int bufferSizeMegabytes = 32;
@PluginBuilderAttribute
private boolean useOffHeapBuffer = true;
@PluginElement("Headers")
private Header[] headers;
@PluginElement("Labels")
private Label[] labels;
@Override
public LokiAppender build() {
ClientConfiguration configurationBuilder = ClientConfiguration.builder()
.withHost(host)
.withConnectionTimeoutMillis(connectTimeoutMillis)
.withPort(port)
.withMaxRetries(maxRetries)
.withRequestTimeoutMillis(readTimeoutMillis)
.build();
NettyHttpClient httpClient = HttpClientFactory
.defaultFactory()
.getHttpClient(configurationBuilder);
LoggingSystem loggingSystem = new TjahziInitializer().createLoggingSystem(
httpClient,
getBufferSizeMegabytes() * BYTES_IN_MEGABYTE,
isUseOffHeapBuffer()
);
HashMap<String, String> lokiLabels = Maps.newHashMap();
Arrays.stream(labels).forEach(property -> {
String value = getConfiguration()
.getStrSubstitutor()
.replace(property.getValue());
lokiLabels.put(
property.getName(),
value
);
}
);
return new LokiAppender(
getName(),
getLayout(),
getFilter(),
isIgnoreExceptions(),
getPropertyArray(),
lokiLabels,
loggingSystem
);
}
public String getHost() {
return host;
}
public int getConnectTimeoutMillis() {
return connectTimeoutMillis;
}
public int getReadTimeoutMillis() {
return readTimeoutMillis;
}
public Header[] getHeaders() {
return headers;
}
public B setHost(String host) {
this.host = host;
return asBuilder();
}
public B setConnectTimeoutMillis(final int connectTimeoutMillis) {
this.connectTimeoutMillis = connectTimeoutMillis;
return asBuilder();
}
public B setReadTimeoutMillis(final int readTimeoutMillis) {
this.readTimeoutMillis = readTimeoutMillis;
return asBuilder();
}
public int getPort() {
return port;
}
public void setPort(int port) {
this.port = port;
}
public int getMaxRetries() {
return maxRetries;
}
public void setMaxRetries(int maxRetries) {
this.maxRetries = maxRetries;
}
public int getBufferSizeMegabytes() {
return bufferSizeMegabytes;
}
public void setBufferSizeMegabytes(int bufferSizeMegabytes) {
this.bufferSizeMegabytes = bufferSizeMegabytes;
}
public boolean isUseOffHeapBuffer() {
return useOffHeapBuffer;
}
public void setUseOffHeapBuffer(boolean useOffHeapBuffer) {
this.useOffHeapBuffer = useOffHeapBuffer;
}
public void setHeaders(Header[] headers) {
this.headers = headers;
}
public Label[] getLabels() {
return labels;
}
public void setLabels(Label[] labels) {
this.labels = labels;
}
}
/**
* @return a builder for a LokiAppender.
*/
@PluginBuilderFactory
public static <B extends LokiAppender.Builder<B>> B newBuilder() {
return new LokiAppender.Builder<B>().asBuilder();
}
private final Map<String, String> lokiLabels;
private final LoggingSystem loggingSystem;
private LokiAppender(
String name,
Layout<? extends Serializable> layout,
Filter filter,
boolean ignoreExceptions,
Property[] properties,
Map<String, String> lokiLabels,
LoggingSystem loggingSystem) {
super(
name,
filter,
layout,
ignoreExceptions,
properties
);
Objects.requireNonNull(layout, "layout");
this.lokiLabels = lokiLabels;
this.loggingSystem = loggingSystem;
}
@Override
public void start() {
super.start();
}
@Override
public void append(final LogEvent event) {
byte[] bytes = getLayout().toByteArray(event);
loggingSystem.createLogger().log(
event.getTimeMillis(),
lokiLabels,
bytes
);
}
@Override
public boolean stop(long timeout, TimeUnit timeUnit) {
setStopping();
boolean stopped = super.stop(
timeout,
timeUnit,
false
);
loggingSystem.close(
(int) timeUnit.toMillis(timeout),
thread -> {
error("");
}
);
setStopped();
return stopped;
}
@Override
public String toString() {
return "LokiAppender{" +
"name=" + getName() +
", state=" + getState() +
'}';
}
}
@@ -0,0 +1,54 @@
package pl.tkowalcz.tjahzi.log4j2;
import org.apache.logging.log4j.util.Strings;
import java.util.Objects;
/**
* Class copied from org.apache.logging.log4j.core.config.Property. I have no idea how to reuse that class while assigning
* it a custom tag name e.g. headers/labels.
*/
public class Property {
private final String name;
private final String value;
private final boolean valueNeedsLookup;
protected Property(final String name, final String value) {
this.name = name;
this.value = value;
this.valueNeedsLookup = value != null && value.contains("${");
}
/**
* Returns the property name.
*
* @return the property name.
*/
public String getName() {
return name;
}
/**
* Returns the property value.
*
* @return the value of the property.
*/
public String getValue() {
return Objects.toString(value, Strings.EMPTY); // LOG4J2-1313 null would be same as Property not existing
}
/**
* Returns {@code true} if the value contains a substitutable property that requires a lookup to be resolved.
*
* @return {@code true} if the value contains {@code "${"}, {@code false} otherwise
*/
public boolean isValueNeedsLookup() {
return valueNeedsLookup;
}
@Override
public String toString() {
return name + '=' + getValue();
}
}
@@ -0,0 +1,100 @@
package pl.tkowalcz.tjahzi.log4j2;
import io.restassured.RestAssured;
import io.restassured.http.ContentType;
import io.restassured.parsing.Parser;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.awaitility.Awaitility;
import org.awaitility.Durations;
import org.hamcrest.BaseMatcher;
import org.hamcrest.Description;
import org.junit.jupiter.api.Test;
import org.testcontainers.containers.BindMode;
import org.testcontainers.containers.GenericContainer;
import org.testcontainers.containers.wait.strategy.Wait;
import org.testcontainers.junit.jupiter.Container;
import org.testcontainers.junit.jupiter.Testcontainers;
import java.util.List;
import java.util.concurrent.TimeUnit;
import static io.restassured.RestAssured.given;
import static org.hamcrest.CoreMatchers.equalTo;
import static org.hamcrest.CoreMatchers.hasItems;
@Testcontainers
class LokiAppenderTest {
@Container
public GenericContainer loki = new GenericContainer("grafana/loki:latest")
.withCommand("-config.file=/etc/loki-config.yaml")
.withClasspathResourceMapping("loki-config.yaml",
"/etc/loki-config.yaml",
BindMode.READ_ONLY)
.waitingFor(
Wait.forHttp("/ready")
.forPort(3100)
)
.withExposedPorts(3100);
@Test
void sendData() {
System.setProperty("loki.host", loki.getHost());
System.setProperty("loki.port", loki.getFirstMappedPort().toString());
((org.apache.logging.log4j.core.LoggerContext) LogManager.getContext(false)).reconfigure();
String expectedLogLine = "Test";
long expectedTimestamp = System.currentTimeMillis();
Logger logger = LogManager.getLogger(LokiAppenderTest.class);
logger.info(expectedLogLine);
RestAssured.port = loki.getFirstMappedPort();
RestAssured.baseURI = "http://" + loki.getHost();
RestAssured.registerParser("text/plain", Parser.JSON);
Awaitility
.await()
.atMost(Durations.TEN_SECONDS)
.pollInterval(Durations.ONE_SECOND)
.ignoreExceptions()
.untilAsserted(() -> {
given()
.contentType(ContentType.URLENC)
.urlEncodingEnabled(false)
.formParam("query=%7Bserver%3D%22127.0.0.1%22%7D")
.when()
.get("/loki/api/v1/query_range")
.then()
.log()
.all()
.statusCode(200)
.body("status", equalTo("success"))
.body("data.result.size()", equalTo(1))
.body("data.result[0].stream.server", equalTo("127.0.0.1"))
.body("data.result[0].values", hasItems(new BaseMatcher<>() {
@Override
public boolean matches(Object o) {
List<Object> list = (List<Object>) o;
if (list.size() != 2) {
return false;
}
long actualTimestamp = Long.parseLong(list.get(0).toString());
String actualLogLine = list.get(1).toString();
return actualLogLine.contains(expectedLogLine)
&& (expectedTimestamp - actualTimestamp) < TimeUnit.MINUTES.toMillis(1);
}
@Override
public void describeTo(Description description) {
}
}
));
});
}
}
@@ -0,0 +1,23 @@
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="OFF" shutdownHook="disable" packages="pl.tkowalcz.tjahzi.log4j2">
<Loggers>
<Root level="INFO">
<AppenderRef ref="Loki"/>
</Root>
</Loggers>
<appenders>
<Loki name="Loki">
<host>${sys:loki.host}</host>
<port>${sys:loki.port}</port>
<ThresholdFilter level="ALL"/>
<PatternLayout>
<Pattern>%X{tid} [%t] %d{MM-dd HH:mm:ss.SSS} %5p %c{1} - %m%n%exception{full}</Pattern>
</PatternLayout>
<Header name="server" value="127.0.0.1"/>
<Label name="server" value="127.0.0.1"/>
</Loki>
</appenders>
</configuration>
@@ -0,0 +1,47 @@
auth_enabled: false
server:
http_listen_port: 3100
log_level: debug
ingester:
lifecycler:
address: 127.0.0.1
ring:
kvstore:
store: inmemory
replication_factor: 1
min_ready_duration: 0s
final_sleep: 0s
chunk_idle_period: 5m
chunk_retain_period: 30s
max_transfer_retries: 0
schema_config:
configs:
- from: 2018-04-15
store: boltdb
object_store: filesystem
schema: v11
index:
prefix: index_
period: 168h
storage_config:
boltdb:
directory: /loki/index
filesystem:
directory: /loki/chunks
limits_config:
enforce_metric_name: false
reject_old_samples: true
reject_old_samples_max_age: 168h
chunk_store_config:
max_look_back_period: 0s
table_manager:
retention_deletes_enabled: false
retention_period: 0s