All Downloads are FREE. Search and download functionalities are using the official Maven repository.
Many resources are needed to download a project. Please understand that we have to compensate our server costs. Thank you in advance.
Project price only 1 $
You can buy this project and download/modify it how often you want.
com.turbospaces.logging.AbstractAppender Maven / Gradle / Ivy
package com.turbospaces.logging;
import java.io.File;
import java.io.IOException;
import java.net.URI;
import java.net.URISyntaxException;
import java.net.URL;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.security.SecureRandom;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Date;
import java.util.HashSet;
import java.util.Iterator;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;
import java.util.Objects;
import java.util.Set;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.function.Supplier;
import java.util.function.ToDoubleFunction;
import org.apache.commons.lang3.BooleanUtils;
import org.apache.commons.lang3.StringUtils;
import org.apache.commons.lang3.builder.EqualsBuilder;
import org.apache.commons.lang3.mutable.MutableLong;
import org.jctools.queues.MessagePassingQueue;
import org.jctools.queues.MpscChunkedArrayQueue;
import org.springframework.cloud.service.UriBasedServiceInfo;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Lists;
import com.google.common.util.concurrent.RateLimiter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.UnsynchronizedAppenderBase;
import ch.qos.logback.core.filter.Filter;
import ch.qos.logback.core.spi.FilterReply;
import io.github.resilience4j.ratelimiter.RateLimiterRegistry;
import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.Gauge;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Timer;
import io.sentry.Sentry;
import io.sentry.SentryClient;
import io.sentry.event.Event;
import io.sentry.event.EventBuilder;
import io.sentry.event.interfaces.ExceptionInterface;
import lombok.AccessLevel;
import lombok.Getter;
import lombok.RequiredArgsConstructor;
import lombok.Setter;
import lombok.ToString;
import lombok.experimental.Accessors;
import lombok.experimental.Delegate;
public abstract class AbstractAppender extends UnsynchronizedAppenderBase {
public static final int MPSC_CHUNK_SIZE = 1024;
public static final String FILE_SUFFIX = "_FILE";
public static final String ENV_UPS_PREFIX = "UPS_";
private final SecureRandom random = new SecureRandom();
private final AtomicLong seq = new AtomicLong(); // ~ global sequence of events
private Timer inboundLag;
private Timer outboundLag;
private Counter outboundCounter;
@Setter
protected DocumentProperties properties = new DocumentProperties(); // ~ which fields to send
@Setter
protected boolean trace; // ~ print useful statistics into info messages
@Setter
protected boolean neverBlock = true; // ~ in case of queue fullness, never block on write
@Setter
protected int threads = 8; // ~ workers count
@Setter
protected int maxPayloadSize = 1 * 1024 * 1024; // ~ 1 MB
@Setter
protected int maxBulkSize = 512; // ~ max bulk size per thread
@Setter
protected int queueSize = 8 * maxBulkSize; // ~ max queue size per thread
@Setter
protected int rate = 100; // ~ max permits per thread
@Setter
protected int socketTimeout = 30; // ~ socket timeout in seconds
@Setter
protected int sentryRateLimit = 10; // ~ not send more than once per X minute (s)
@Setter
protected Set mdcNames = new HashSet<>(); // ~ white-list MDC name
//
// ~ meta configuration (might be provided directly)
//
@Setter
@Getter
private String space;
@Setter
@Getter
private String slot;
@Setter
@Getter
private String host;
@Setter
@Getter
private String service;
@Setter
@Getter
private String release;
@Setter
@Getter
private URL elasticEndpoint;
@Setter
@Getter
private URL sentryEndpoint;
protected WorkerThread[] workers; // ~ background worker threads
protected AtomicLong lastSentryAlert = new AtomicLong();
@Setter
@Getter
private SentryClient sentry;
private boolean closeSentry;
@Setter
@Getter
private MeterRegistry meterRegistry;
@Setter
@Getter
private RateLimiterRegistry rateLimiterRegistry;
@Override
public void start() {
DropSentryFilter dropSentry = new DropSentryFilter();
addFilter(dropSentry);
dropSentry.start();
// ~ Initialise pattern layout
getContext().getCopyOfPropertyMap().forEach((k, v) -> properties.addProperty(k, v));
for (DocumentProperty field : properties.getProperties()) {
field.init(getContext());
}
// ~ get common properties
if (StringUtils.isEmpty(space)) {
space = Objects.requireNonNull(getContext().getProperty(Logback.SPACE));
}
if (StringUtils.isEmpty(host)) {
host = Objects.requireNonNull(getContext().getProperty(Logback.HOST));
}
if (StringUtils.isEmpty(slot)) {
slot = Objects.requireNonNull(getContext().getProperty(Logback.SLOT));
}
if (StringUtils.isEmpty(service)) {
service = Objects.requireNonNull(getContext().getProperty(Logback.SERVICE));
}
if (StringUtils.isEmpty(release)) {
release = Objects.requireNonNull(getContext().getProperty(Logback.RELEASE));
}
if (Objects.isNull(meterRegistry)) {
meterRegistry = (MeterRegistry) Objects.requireNonNull(getContext().getObject(Logback.METER_REGISTRY));
}
if (Objects.isNull(rateLimiterRegistry)) {
rateLimiterRegistry = (RateLimiterRegistry) Objects.requireNonNull(getContext().getObject(Logback.RATE_LIMITER_REGISTRY));
}
List commonTags = getCommonMeterRegistryTags();
inboundLag = meterRegistry.timer("appender.in.latency", commonTags);
outboundLag = meterRegistry.timer("appender.out.latency", commonTags);
outboundCounter = meterRegistry.counter("appender.out.count", commonTags);
//
// ~ prepare workers
//
workers = new WorkerThread[threads];
for (int i = 0; i < threads; i++) {
WorkerThread workerThread = new WorkerThread(i, commonTags);
workers[i] = workerThread;
//
// ~ worker thread should be ignored
//
Filter filter = new Filter() {
@Override
public FilterReply decide(ILoggingEvent event) {
String threadName = event.getThreadName();
if (workerThread.getName().equals(threadName)) {
return FilterReply.DENY;
}
return FilterReply.NEUTRAL;
}
};
filter.setName(workerThread.getName());
addFilter(filter);
filter.start();
}
//
// ~ try to find UPS_ELASTIC-SEARCH and UPS_SENTRY user-provided service
//
for (Entry entry : System.getenv().entrySet()) {
if (entry.getKey().startsWith(ENV_UPS_PREFIX)) {
String key = entry.getKey();
String value = entry.getValue();
String serviceId = key.substring(ENV_UPS_PREFIX.length()).trim().toLowerCase();
//
// ~ docker mounts secrets to /run/secrets/${secret}
//
if (key.endsWith(FILE_SUFFIX)) {
File f = new File(value);
try {
byte[] encoded = Files.readAllBytes(f.toPath());
value = new String(encoded, StandardCharsets.UTF_8);
serviceId = serviceId.substring(0, serviceId.length() - FILE_SUFFIX.length());
} catch (IOException err) {
addError(err.getMessage(), err);
}
}
try {
if (Logback.UPS_SENTRY.equals(serviceId)) {
addInfo("found sentry UPS from ENV variable: " + serviceId);
sentryEndpoint = new URI(value).toURL();
} else if (Logback.UPS_ELASTIC_SEARCH.equals(serviceId)) {
addInfo("found ELK UPS from ENV variable: " + serviceId);
elasticEndpoint = new URI(value).toURL();
}
} catch (IOException | URISyntaxException err) {
addError(err.getMessage(), err);
}
}
}
//
// ~ sentry client
//
if (Objects.isNull(sentry)) {
sentry = (SentryClient) getContext().getObject(Logback.SENTRY_CLIENT);
}
if (Objects.nonNull(sentry)) {
addInfo("found sentry client in context, will use " + sentry);
}
if (Objects.isNull(sentry)) {
UriBasedServiceInfo sentryUps = (UriBasedServiceInfo) getContext().getObject(Logback.UPS_SENTRY);
if (sentryUps != null) {
try {
sentryEndpoint = new URI(sentryUps.getUri()).toURL();
} catch (IOException | URISyntaxException err) {
addError(err.getMessage(), err);
}
}
if (Objects.nonNull(sentryEndpoint)) {
sentry = Sentry.init(sentryEndpoint.toString());
sentry.setEnvironment(space);
sentry.setServerName(service + "/" + slot);
sentry.setRelease(release);
closeSentry = true;
}
}
//
// ~ elastic-search UPS
//
if (Objects.isNull(elasticEndpoint)) {
UriBasedServiceInfo elasticUps = (UriBasedServiceInfo) getContext().getObject(Logback.UPS_ELASTIC_SEARCH);
if (Objects.nonNull(elasticUps)) {
try {
elasticEndpoint = new URI(elasticUps.getUri()).toURL();
} catch (IOException | URISyntaxException err) {
addError(err.getMessage(), err);
}
}
}
}
@Override
public void stop() {
super.stop();
//
// ~ interrupt workers
//
if (Objects.nonNull(workers)) {
for (int i = 0; i < threads; i++) {
WorkerThread worker = workers[i];
worker.interrupt();
}
}
//
// ~ close sentry (only if applicable)
//
if (closeSentry) {
if (Objects.nonNull(sentry)) {
sentry.closeConnection();
}
}
}
@Override
protected void append(ILoggingEvent event) {
event.prepareForDeferredProcessing();
//
// ~ Initialise caller data only for errors
//
if (event.getThrowableProxy() != null) {
event.getCallerData();
}
//
// ~ random choice
//
int idx = random.nextInt(threads);
WorkerThread worker = workers[idx];
SequencedDeferredEvent wrappedEvent = new SequencedDeferredEvent(seq.incrementAndGet(), event);
worker.put(wrappedEvent);
}
@SuppressWarnings("unchecked")
protected boolean alertsDryRun() {
Supplier prop = (Supplier) getContext().getObject(Logback.ALERTS_DRY_RUN);
return prop != null ? prop.get() : false;
}
@SuppressWarnings("unchecked")
protected boolean loggingDryRun() {
Supplier prop = (Supplier) getContext().getObject(Logback.LOGGING_DRY_RUN);
return prop != null ? prop.get() : false;
}
protected boolean sendSentryAlert(String message, Exception err) {
long now = System.currentTimeMillis();
long prev = lastSentryAlert.get();
long period = now - prev;
if (BooleanUtils.isFalse(alertsDryRun())) {
if (Objects.nonNull(sentry)) {
if (period >= TimeUnit.MINUTES.toMillis(sentryRateLimit)) {
try {
EventBuilder builder = new EventBuilder();
builder.withTimestamp(new Date());
builder.withMessage(message);
builder.withLogger(getClass().getName());
builder.withLevel(Event.Level.ERROR);
builder.withSentryInterface(new ExceptionInterface(err));
sentry.sendEvent(builder);
} finally {
lastSentryAlert.compareAndSet(prev, now);
}
return true;
}
}
}
return false;
}
protected List getCommonMeterRegistryTags() {
List commonTags = new ArrayList<>();
commonTags.add(Tag.of("name", getName()));
commonTags.add(Tag.of("host", host));
commonTags.add(Tag.of("service", service));
return commonTags;
}
protected abstract void sendBulk(List bulk);
protected abstract boolean dryRun();
protected final class WorkerThread extends Thread {
private final MpscChunkedArrayQueue queue;
private final RateLimiter limiter;
private final List tags;
private final Counter discarded;
private WorkerThread(int idx, Collection commonTags) {
super(String.format("%s-worker-%d", AbstractAppender.this.getName(), idx));
setDaemon(true);
//
// ~ low latency lock free multiple producers one consumer queue
//
queue = new MpscChunkedArrayQueue<>(MPSC_CHUNK_SIZE, queueSize);
limiter = RateLimiter.create(rate);
tags = ImmutableList. builder().addAll(commonTags).add(Tag.of("thread_idx", String.valueOf(idx))).build();
Gauge.builder("appender.queue.size", queue, MpscChunkedArrayQueue::size).tags(tags).register(meterRegistry);
Gauge.builder("appender.queue.remaining", queue, new ToDoubleFunction<>() {
@Override
public double applyAsDouble(MpscChunkedArrayQueue value) {
return queueSize - queue.size();
}
}).tags(tags).register(meterRegistry);
discarded = Counter.builder("appender.discarded.count").tags(tags).register(meterRegistry);
}
@Override
public void run() {
while (isStarted()) {
double await = limiter.acquire();
await *= 1000; // convert to milliseconds
//
// ~ fetch batch hopefully not over-consuming memory
//
List toSend = Lists.newLinkedList();
queue.drain(new MessagePassingQueue.Consumer() {
@Override
public void accept(SequencedDeferredEvent next) {
toSend.add(next);
}
}, maxBulkSize);
Thread current = Thread.currentThread();
if (toSend.isEmpty()) {
//
// ~ NO-OP (very unlikely)
//
} else {
//
// ~ send to target sink (ELK/sentry)
//
try {
long now = System.currentTimeMillis();
int size = toSend.size();
if (dryRun()) {
addInfo("not sending bulk of: " + size);
} else {
Timer.Sample timer = Timer.start(meterRegistry);
try {
MutableLong totalBytes = new MutableLong();
List chunk = Lists.newArrayListWithExpectedSize(toSend.size()); // ~ preallocate to same size
for (Iterator it = toSend.iterator(); it.hasNext();) {
SequencedDeferredEvent event = it.next();
//
// ~ well should not happen - we simply drop it
//
try {
int length = 0;
String formattedMessage = event.getFormattedMessage();
//
// ~ it turns out it can be NULL not empty string
//
if (StringUtils.isNotEmpty(formattedMessage)) {
length = formattedMessage.getBytes(StandardCharsets.UTF_8).length;
}
if (length <= maxPayloadSize) {
MutableLong totalToAdd = new MutableLong(length);
Map mdc = event.getMDCPropertyMap();
if (Objects.nonNull(mdc)) {
for (Entry entry : mdc.entrySet()) {
String key = entry.getKey();
String value = entry.getValue();
if (StringUtils.isNotEmpty(key)) {
totalToAdd.add(key.getBytes(StandardCharsets.UTF_8).length);
}
if (StringUtils.isNotEmpty(value)) {
totalToAdd.add(value.getBytes(StandardCharsets.UTF_8).length);
}
}
}
//
// ~ if this is causing overflow then send a bulk immediately and reset
//
if (totalBytes.longValue() + totalToAdd.longValue() >= maxPayloadSize) {
totalBytes.setValue(0);
sendBulk(chunk);
chunk.clear();
}
totalBytes.add(totalToAdd);
chunk.add(event);
}
} finally {
it.remove();
}
}
if (chunk.isEmpty()) {
//
// ~ NO-OP (very unlikely)
//
} else {
sendBulk(chunk);
}
outboundCounter.increment(size);
} finally {
timer.stop(outboundLag);
}
}
if (trace) {
now = System.currentTimeMillis() - now; // measure
addInfo(String.format("%s (items: %d, took: %d ms, await: %.2fms)", current.getName().toLowerCase(), size, now, await));
}
} catch (Throwable err) {
addError("failed to send bulk", err); // just in case
}
}
}
//
// ~ simply clear queue
//
queue.clear();
}
protected void put(SequencedDeferredEvent next) {
if (neverBlock) {
boolean sent = queue.offer(next); // just offer and never block
if (BooleanUtils.isFalse(sent)) {
//
// ~ make sure we are not leaving it without attention
//
discarded.increment();
}
} else {
//
// ~ might cause blocking of current thread
// ~ should be used only for testing locally
//
queue.add(next);
long lag = System.currentTimeMillis() - next.timestamp();
inboundLag.record(lag, TimeUnit.MILLISECONDS);
}
}
}
@ToString
@RequiredArgsConstructor(access = AccessLevel.PRIVATE)
@Getter
@Accessors(fluent = true)
protected static class SequencedDeferredEvent implements ILoggingEvent {
private final long seq;
@Delegate
private final ILoggingEvent event;
public long timestamp() {
return event.getTimeStamp();
}
@Override
public int hashCode() {
return Objects.hash(seq, event);
}
@Override
public boolean equals(Object obj) {
SequencedDeferredEvent other = (SequencedDeferredEvent) obj;
return new EqualsBuilder().append(seq, other.seq).append(event, other.event).isEquals();
}
}
}
