Skip to content

Add Topic compression and processing duration histograms #778

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
KirillKurdyukov wants to merge 1 commit into
base: topic-session-errors
Choose a base branch
from
Open

Add Topic compression and processing duration histograms #778

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 13 additions & 1 deletion topic/src/main/java/tech/ydb/topic/read/impl/MessageDecoder.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import tech.ydb.core.metrics.Meter;
import tech.ydb.topic.description.CodecRegistry;
import tech.ydb.topic.impl.SerialRunnable;

Expand All @@ -23,15 +24,21 @@ public class MessageDecoder {

private final Executor decompressionExecutor;
private final CodecRegistry codecRegistry;
private final ReaderMetrics metrics;
private final Queue<ReadPartitionDecoder.EncodedMessage> decodingQueue = new ConcurrentLinkedQueue<>();
private final SerialRunnable decodeNext = new SerialRunnable(new DecodeNext());
private volatile boolean isStopped = false;

public MessageDecoder(ReadConfig config) {
this(config.getMaxMemoryUsageBytes(), config.getDecompressor(), config.getCodecRegistry());
this(config.getMaxMemoryUsageBytes(), config.getDecompressor(), config.getCodecRegistry(), config.getMetrics());
}

MessageDecoder(long maxBufferSize, Executor decompressionExecutor, CodecRegistry codecRegistry) {
this(maxBufferSize, decompressionExecutor, codecRegistry, new ReaderMetrics(Meter.NOOP, null, null));
}

private MessageDecoder(long maxBufferSize, Executor decompressionExecutor, CodecRegistry codecRegistry,
ReaderMetrics metrics) {
if (maxBufferSize <= 0) {
throw new IllegalArgumentException("maxBufferSize must be positive, but got " + maxBufferSize);
}
Expand All @@ -40,6 +47,11 @@ public MessageDecoder(ReadConfig config) {
this.totalAvailable = new AtomicLong(maxBufferSize);
this.decompressionExecutor = decompressionExecutor;
this.codecRegistry = codecRegistry;
this.metrics = metrics;
}

ReaderMetrics getMetrics() {
return metrics;
}

public void decodeNext() {
Expand Down
20 changes: 19 additions & 1 deletion topic/src/main/java/tech/ydb/topic/read/impl/ReadPartitionDecoder.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,8 @@ private class RawMessage extends MessageImpl {
RawMessage(BatchMeta meta, OffsetsRange range, YdbTopic.StreamReadMessage.ReadResponse.MessageData msg) {
super(partition, committer, meta, range, msg);
this.data = msg.getData().toByteArray();
decoder.getMetrics().reportProcessing(System.nanoTime() - getReceivedAt(), meta.getCodec(),
partition.getPath(), null);
}

@Override
Expand Down Expand Up @@ -155,6 +157,8 @@ public boolean isReady() {
public void setError(Throwable th) {
problem = new IOException("Decompression for " + getPartitionSession() + " error", th);
releaseRange(OffsetsRange.of(getOffset()));
decoder.getMetrics().reportProcessing(System.nanoTime() - getReceivedAt(), codecCode,
partition.getPath(), th);
isReady = true;
notifyReady();
}
Expand All @@ -181,6 +185,7 @@ public void decode(CodecRegistry registry) {
return;
}

Throwable error = null;
try {
Codec codec = registry.getCodec(codecCode);
if (codec == null) {
Expand All @@ -190,22 +195,35 @@ public void decode(CodecRegistry registry) {
}

logger.trace("[{}] Started decoding batch", traceID);
long compressionStarted = System.nanoTime();
try (InputStream encoded = origin.newInput(); InputStream decoded = codec.decode(encoded)) {
data = ByteStreams.toByteArray(decoded);
logger.trace("[{}] Finished decoding batch", traceID);
} catch (IOException ex) {
error = ex;
decoder.getMetrics().reportCompression(System.nanoTime() - compressionStarted, codecCode,
partition.getPath(), ex);
logger.warn("[{}] Exception was thrown while decoding a message: ", traceID, ex);
problem = ex;
} catch (RuntimeException ex) {
error = ex;
decoder.getMetrics().reportCompression(System.nanoTime() - compressionStarted, codecCode,
partition.getPath(), ex);
logger.warn("[{}] RuntimeException was thrown while decoding a message: ", traceID, ex);
problem = new IOException("Cannot decode message", ex);
}
if (error == null) {
decoder.getMetrics().reportCompression(System.nanoTime() - compressionStarted, codecCode,
partition.getPath(), null);
logger.trace("[{}] Finished decoding batch", traceID);
}
} finally {
if (problem == null) {
origin = null;
} else {
data = null;
}
decoder.getMetrics().reportProcessing(System.nanoTime() - getReceivedAt(), codecCode,
partition.getPath(), error == null ? problem : error);
isReady = true;
notifyReady();
}
Expand Down
29 changes: 29 additions & 0 deletions topic/src/main/java/tech/ydb/topic/read/impl/ReaderMetrics.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
import tech.ydb.core.Status;
import tech.ydb.core.StatusCode;
import tech.ydb.core.metrics.Attr;
import tech.ydb.core.metrics.DoubleHistogram;
import tech.ydb.core.metrics.LongCounter;
import tech.ydb.core.metrics.Meter;
import tech.ydb.core.metrics.MetricRegistration;
Expand All @@ -22,6 +23,8 @@ final class ReaderMetrics {
private final LongCounter commitQueued;
private final LongCounter commitAcknowledged;
private final LongCounter sessionErrors;
private final DoubleHistogram compressionDuration;
private final DoubleHistogram processingDuration;
private final Attr[] commonAttributes;
private final boolean enabled;
private final Meter meter;
Expand All @@ -48,6 +51,10 @@ final class ReaderMetrics {
"The number of messages acknowledged by advances of the committed offset.");
this.sessionErrors = meter.createCounter("ydb.topic.reader.session.errors", "{error}",
"The number of reader stream session errors by retry decision.");
this.compressionDuration = meter.createHistogram("ydb.topic.reader.compression.duration", "s",
"The time spent decompressing a message, excluding queueing.");
this.processingDuration = meter.createHistogram("ydb.topic.reader.message.processing.duration", "s",
"The time from receipt until a message is ready for delivery.");
this.commonAttributes = createCommonAttributes(consumer, readerName);
}

Expand Down Expand Up @@ -122,6 +129,28 @@ void reportCommitAcknowledged(long messages, String topic) {
report(commitAcknowledged, messages, topic);
}

void reportCompression(long durationNanos, int codec, String topic, Throwable error) {
recordDuration(compressionDuration, durationNanos, codec, topic, error);
}

void reportProcessing(long durationNanos, int codec, String topic, Throwable error) {
recordDuration(processingDuration, durationNanos, codec, topic, error);
}

private void recordDuration(DoubleHistogram histogram, long durationNanos, int codec, String topic,
Throwable error) {
if (enabled) {
Attr[] attributes = Arrays.copyOf(commonAttributes, commonAttributes.length + (error == null ? 3 : 4));
attributes[commonAttributes.length] = Attr.of("topic", topic);
attributes[commonAttributes.length + 1] = Attr.of("codec", Integer.toString(codec));
attributes[commonAttributes.length + 2] = Attr.of("outcome", error == null ? "ok" : "error");
if (error != null) {
attributes[commonAttributes.length + 3] = Attr.of("error.type", error.getClass().getName());
}
histogram.record(durationNanos / 1_000_000_000d, attributes);
}
}

private void report(LongCounter counter, long messages, String topic) {
if (enabled && messages > 0) {
record(counter, messages, Attr.of("topic", topic));
Expand Down
29 changes: 29 additions & 0 deletions topic/src/main/java/tech/ydb/topic/write/impl/WriterMetrics.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
import tech.ydb.core.Status;
import tech.ydb.core.StatusCode;
import tech.ydb.core.metrics.Attr;
import tech.ydb.core.metrics.DoubleHistogram;
import tech.ydb.core.metrics.LongCounter;
import tech.ydb.core.metrics.Meter;
import tech.ydb.core.metrics.MetricRegistration;
Expand All @@ -20,13 +21,17 @@ final class WriterMetrics {
private final LongCounter sendingBytes;
private final LongCounter writtenMessages;
private final LongCounter sessionErrors;
private final DoubleHistogram compressionDuration;
private final DoubleHistogram processingDuration;
private final Attr[] commonAttributes;
private final boolean enabled;
private final Meter meter;
private MetricRegistration bufferUsedGauge = MetricRegistration.NOOP;
private MetricRegistration bufferLimitGauge = MetricRegistration.NOOP;

WriterMetrics(Meter meter, String topic, String writerName) {
this.meter = meter;
this.enabled = meter != Meter.NOOP;
this.sendingMessages = meter.createCounter("ydb.topic.writer.sending.messages", MESSAGE_UNIT,
"The number of messages accepted by the SDK for sending.");
this.sendingBytes = meter.createCounter("ydb.topic.writer.sending.bytes", "By",
Expand All @@ -35,6 +40,10 @@ final class WriterMetrics {
"The number of messages confirmed written by the server, including already written messages.");
this.sessionErrors = meter.createCounter("ydb.topic.writer.session.errors", "{error}",
"The number of writer stream session errors by retry decision.");
this.compressionDuration = meter.createHistogram("ydb.topic.writer.compression.duration", "s",
"The time spent compressing a message, excluding queueing.");
this.processingDuration = meter.createHistogram("ydb.topic.writer.message.processing.duration", "s",
"The time from buffer acceptance until a message is ready for sending.");
this.commonAttributes = writerName == null
? new Attr[0]
: new Attr[]{Attr.of("topic", topic), Attr.of("writer.name", writerName)};
Expand Down Expand Up @@ -65,6 +74,26 @@ void reportWritten() {
writtenMessages.add(1, commonAttributes);
}

void reportCompression(long durationNanos, int codec, Throwable error) {
recordDuration(compressionDuration, durationNanos, codec, error);
}

void reportProcessing(long durationNanos, int codec, Throwable error) {
recordDuration(processingDuration, durationNanos, codec, error);
}

private void recordDuration(DoubleHistogram histogram, long durationNanos, int codec, Throwable error) {
if (enabled) {
Attr[] attributes = Arrays.copyOf(commonAttributes, commonAttributes.length + (error == null ? 2 : 3));
attributes[commonAttributes.length] = Attr.of("codec", Integer.toString(codec));
attributes[commonAttributes.length + 1] = Attr.of("outcome", error == null ? "ok" : "error");
if (error != null) {
attributes[commonAttributes.length + 2] = Attr.of("error.type", error.getClass().getName());
}
histogram.record(durationNanos / 1_000_000_000d, attributes);
}
}

void reportSessionError(Status status, boolean retry) {
StatusCode code = status.getCode();
Attr[] attributes = Arrays.copyOf(commonAttributes, commonAttributes.length + 3);
Expand Down
23 changes: 18 additions & 5 deletions topic/src/main/java/tech/ydb/topic/write/impl/WriterQueue.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -232,21 +232,25 @@ private long reservationSizeBytes(int inputSizeBytes) {
}

private CompletableFuture<WriteAck> accept(Message message, YdbTransaction tx, long reservedSizeBytes) {
long acceptedAt = System.nanoTime();
EnqueuedMessage msg = new EnqueuedMessage(new MessageMeta(message, tx), reservedSizeBytes);
lastAcceptedAckFuture = msg.getAckFuture();
queue.add(msg);
metrics.reportSending(message.getData().length);

if (codec.getId() == Codec.RAW) {
// fast track without compression
msg.completeWithData(UnsafeByteOperations.unsafeWrap(message.getData()), reservedSizeBytes);
ByteString data = UnsafeByteOperations.unsafeWrap(message.getData());
metrics.reportProcessing(System.nanoTime() - acceptedAt, codec.getId(), null);
msg.completeWithData(data, reservedSizeBytes);
readyNotify.run();
return msg.getAckFuture();
}

try {
compressionExecutor.execute(() -> encode(message.getData(), reservedSizeBytes, msg));
compressionExecutor.execute(() -> encode(message.getData(), reservedSizeBytes, msg, acceptedAt));
} catch (Throwable ex) {
metrics.reportProcessing(System.nanoTime() - acceptedAt, codec.getId(), ex);
logger.warn("[{}] Message wasn't sent because of processing error", debugId, ex);
msg.completeWithProblem(ex);
readyNotify.run();
Expand All @@ -255,16 +259,23 @@ private CompletableFuture<WriteAck> accept(Message message, YdbTransaction tx, l
return msg.getAckFuture();
}

private void encode(byte[] data, long reservedSize, EnqueuedMessage msg) {
private void encode(byte[] data, long reservedSize, EnqueuedMessage msg, long acceptedAt) {
if (msg.isReady()) {
return;
}

logger.trace("[{}] Started encoding message", debugId);
try (ByteString.Output encoded = ByteString.newOutput()) {
try (OutputStream os = codec.encode(encoded)) {
os.write(data, 0, data.length);
long compressionStarted = System.nanoTime();
try {
try (OutputStream os = codec.encode(encoded)) {
os.write(data, 0, data.length);
}
} catch (Throwable ex) {
metrics.reportCompression(System.nanoTime() - compressionStarted, codec.getId(), ex);
throw ex;
}
metrics.reportCompression(System.nanoTime() - compressionStarted, codec.getId(), null);

if (logger.isTraceEnabled()) {
logger.trace("[{}] Message compressed from {} to {} bytes", debugId, data.length, encoded.size());
Expand All @@ -286,8 +297,10 @@ private void encode(byte[] data, long reservedSize, EnqueuedMessage msg) {
}

bufferSizeBytes = updatedBufferSizeBytes;
metrics.reportProcessing(System.nanoTime() - acceptedAt, codec.getId(), null);
msg.completeWithData(encodedData, bufferSizeBytes);
} catch (Throwable ex) {
metrics.reportProcessing(System.nanoTime() - acceptedAt, codec.getId(), ex);
logger.warn("[{}] Message wasn't sent because of encoding error", debugId, ex);
msg.completeWithProblem(ex);
}
Expand Down
Loading