diff --git a/pom.xml b/pom.xml index 4d18540051..ef7f72ce3b 100644 --- a/pom.xml +++ b/pom.xml @@ -203,6 +203,11 @@ software.amazon.awssdk sts + + + software.amazon.awssdk + s3 + com.datastax.oss java-driver-core @@ -302,6 +307,13 @@ testcontainers-junit-jupiter test + + + com.adobe.testing + s3mock-testcontainers + 5.1.0 + test + com.github.docker-java docker-java-api diff --git a/src/main/java/io/stargate/sgv2/jsonapi/api/request/RequestContext.java b/src/main/java/io/stargate/sgv2/jsonapi/api/request/RequestContext.java index 10ddb2a9d9..29868fe35a 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/api/request/RequestContext.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/api/request/RequestContext.java @@ -15,7 +15,7 @@ import io.stargate.sgv2.jsonapi.config.feature.ApiFeatures; import io.stargate.sgv2.jsonapi.config.feature.FeaturesConfig; import io.stargate.sgv2.jsonapi.logging.LoggingMDCContext; -import io.stargate.sgv2.jsonapi.service.provider.Billing; +import io.stargate.sgv2.jsonapi.service.billing.Billing; import io.stargate.sgv2.jsonapi.service.schema.SchemaRegistry; import io.vertx.ext.web.RoutingContext; import jakarta.enterprise.context.RequestScoped; diff --git a/src/main/java/io/stargate/sgv2/jsonapi/config/BillingConfig.java b/src/main/java/io/stargate/sgv2/jsonapi/config/BillingConfig.java index 08b9985400..7d6d4a3934 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/config/BillingConfig.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/config/BillingConfig.java @@ -2,12 +2,19 @@ import io.smallrye.config.ConfigMapping; import io.smallrye.config.WithDefault; -import io.stargate.sgv2.jsonapi.service.provider.BillingEventType; +import io.stargate.sgv2.jsonapi.service.billing.BillingEventType; import java.util.List; import java.util.Optional; import java.util.Set; -/** Configuration for the billing event pipeline. */ +/** + * Configuration for the billing event pipeline. + * + *

NOTE: This enables the collection of billing events and configures their structure, the + * events are then send to the logger named {@link + * io.stargate.sgv2.jsonapi.service.billing.DefaultBilling#BILLING_LOGGER_NAME}. Use {@link + * BillingS3UploadConfig} to configure sending them to S3, or configure a log handler manually. + */ @ConfigMapping(prefix = "stargate.jsonapi.billing") public interface BillingConfig { diff --git a/src/main/java/io/stargate/sgv2/jsonapi/config/BillingS3UploadConfig.java b/src/main/java/io/stargate/sgv2/jsonapi/config/BillingS3UploadConfig.java new file mode 100644 index 0000000000..7bedf55f3e --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/config/BillingS3UploadConfig.java @@ -0,0 +1,122 @@ +package io.stargate.sgv2.jsonapi.config; + +import io.smallrye.config.ConfigMapping; +import io.smallrye.config.WithDefault; +import io.stargate.sgv2.jsonapi.service.billing.BillingS3Lifecycle; +import io.stargate.sgv2.jsonapi.service.billing.BillingUploadingLogHandler; +import java.time.Duration; +import java.util.Optional; +import software.amazon.awssdk.core.retry.RetryMode; + +/** + * Configuration for the billing S3 export (see {@link BillingS3Lifecycle}). + * + *

See also {@link BillingConfig} + */ +@ConfigMapping(prefix = "stargate.jsonapi.billing.s3") +public interface BillingS3UploadConfig { + + /** When true billing events are sent to S3 using the config below. */ + @WithDefault("false") + boolean enabled(); + + /** + * When true adding the S3 handler for logging at run time removes any other handler + * the logger has installed. NOTE: is only applied IF S3 is enabled + */ + @WithDefault("true") + boolean disableOtherHandlers(); + + /** Required, S3 bucket region to send billing events to. */ + @WithDefault("us-east-2") + String region(); + + /** Required, S3 bucket name to send billing events to. */ + @WithDefault("serverless-usage") + String bucket(); + + /** + * Required, path prefix that billing events are added under. See {@link + * io.stargate.sgv2.jsonapi.service.billing.S3BatchedLogUploader} for the full path. + */ + @WithDefault("data-api") + String s3PathPrefix(); + + /** + * When uploading to S3, the timeout to use fo a single upload request. See {@link + * io.stargate.sgv2.jsonapi.service.billing.S3BatchedLogUploader} + */ + @WithDefault("PT10S") + Duration s3CallAttemptTimeout(); + + /** + * When uploading to S3, the total time all attempts to upload may take. See {@link + * io.stargate.sgv2.jsonapi.service.billing.S3BatchedLogUploader} + */ + @WithDefault("PT30S") + Duration s3TotalCallTimeout(); + + /** See S3 client {@link RetryMode} */ + @WithDefault("STANDARD") + RetryMode s3RetryMode(); + + /** Overrides the path for S2 to be used in testing such as S3Mock in tests. */ + Optional endpointOverride(); + + /** + * Maximum number of events to put into a single batch of buffered billing events. When the buffer + * has this many events a new batch is created. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer} + */ + @WithDefault("5000") + int bufferMaxBatchSize(); + + /** + * Max bytes to include in a batch, NOTE: if a single event is bigger than this it will be sent in + * a batch still. 2097152 == 2 MB which is approx 5,000 events at 400 Bytes each. When the buffer + * has this many bytes a new batch is created. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer} + */ + @WithDefault("2097152") + long bufferMaxBatchBytes(); + + /** + * Maximum age the first (head) billing event in the buffer can get to before triggering a batch + * being created. See {@link io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer} + */ + @WithDefault("PT60S") + Duration bufferMaxBatchAge(); + + /** + * Maximum number of events that can be held in the buffer before events are dropped. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer} and {@link + * io.stargate.sgv2.jsonapi.service.billing.BillingUploadingLogHandler} + */ + @WithDefault("50000") + int bufferCapacity(); + + /** + * Length of time the billing log handler should sleep before checking if a new batch(s) is + * available from the logging buffer. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BillingUploadingLogHandler} + */ + @WithDefault("PT60S") + Duration handlerSleepDuration(); + + /** + * Length of time the thread doing uploading from the logging handler will wait for the S3 upload + * to complete. NOTE that while there are timeouts etc above for S3, they are passed into the AWS + * client. This is the timeout the uploading thread uses incase the upload stalls. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BillingUploadingLogHandler} + */ + @WithDefault("PT30S") + Duration handlerUploadSafetyDeadline(); + + /** + * Length of time the thread used to call {@link BillingUploadingLogHandler#close()} will wait + * forthe uploading thread to have completed uploading all remaining events. See {@link + * io.stargate.sgv2.jsonapi.service.billing.BillingUploadingLogHandler} + */ + @WithDefault("PT30S") + Duration handlerUploadShutdownDeadline(); +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/config/feature/ApiFeatures.java b/src/main/java/io/stargate/sgv2/jsonapi/config/feature/ApiFeatures.java index 2357ba741c..4d683c978a 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/config/feature/ApiFeatures.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/config/feature/ApiFeatures.java @@ -3,6 +3,7 @@ import io.stargate.sgv2.jsonapi.api.request.RequestContext; import java.util.Collections; import java.util.Map; +import java.util.Objects; /** * Accessor for combined state of feature flags; typically based on static configuration (with its @@ -30,11 +31,13 @@ public static ApiFeatures empty() { public static ApiFeatures fromConfigAndRequest( FeaturesConfig config, RequestContext.HttpHeaderAccess httpHeaders) { - Map fromConfig = config.flags(); - if (fromConfig == null) { - fromConfig = Collections.emptyMap(); - } - return new ApiFeatures(fromConfig, httpHeaders); + Objects.requireNonNull(config, "config cannot be null"); + return fromConfigAndRequest(config.flags(), httpHeaders); + } + + public static ApiFeatures fromConfigAndRequest( + Map flags, RequestContext.HttpHeaderAccess httpHeaders) { + return new ApiFeatures(flags == null ? Collections.emptyMap() : flags, httpHeaders); } public boolean isFeatureEnabled(ApiFeature flag) { diff --git a/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogBufferMetrics.java b/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogBufferMetrics.java new file mode 100644 index 0000000000..583561e383 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogBufferMetrics.java @@ -0,0 +1,66 @@ +package io.stargate.sgv2.jsonapi.metrics; + +import io.micrometer.core.instrument.Counter; +import io.micrometer.core.instrument.Gauge; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.TimeGauge; +import io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; + +/** + * Metrics for the log buffer {@link io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer} + * + *

NOTE: A single instance of the buffer is expected to as the application runs, and it + * must call {@link #registerBuffer(BatchedLogBuffer)} when created. + * + *

Note: not recording events dropped at shutdown as a metric because when shutting down the + * metrics still need to be scrapped to be useful. Do it as a log message that is persistent. + */ +public final class BatchedLogBufferMetrics extends MetricsBase { + + private final AtomicBoolean bufferRegister = new AtomicBoolean(false); + + public final Counter offered; + public final Counter dropped; + + // these are nullable, they are set when registerBuffer is called. + public TimeGauge headAgeMs; + public Gauge size; + public Gauge remainingCapacity; + public Gauge bytes; + + /** Creates a new instance, remember to call {@link #registerBuffer(BatchedLogBuffer)} */ + public BatchedLogBufferMetrics(MeterRegistry meterRegistry, String prefix) { + super(meterRegistry, prefix); + + this.offered = newCounter("buffer.offered"); + this.dropped = newCounter("buffer.dropped"); + } + + /** + * Registers the supplued buffer as the source for metrics thats are pulled from the buffer. Can + * only be called once. + */ + public void registerBuffer(BatchedLogBuffer buffer) { + + if (!bufferRegister.compareAndSet(false, true)) { + throw new IllegalStateException("registerBuffer() already called"); + } + + headAgeMs = + newTimeGauge( + "buffer.head_age_ms", () -> buffer.headEntryAge().toMillis(), TimeUnit.MILLISECONDS); + size = newGauge("buffer.size", buffer::size); + remainingCapacity = newGauge("buffer.remaining_capacity", buffer::remainingCapacity); + bytes = newGauge("buffer.bytes", buffer::queuedBytes); + } + + public void incrementOffered() { + offered.increment(); + } + + public void incrementDropped() { + dropped.increment(); + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogUploaderMetrics.java b/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogUploaderMetrics.java new file mode 100644 index 0000000000..c7141123d0 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/metrics/BatchedLogUploaderMetrics.java @@ -0,0 +1,50 @@ +package io.stargate.sgv2.jsonapi.metrics; + +import io.micrometer.core.instrument.Counter; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Timer; +import io.stargate.sgv2.jsonapi.service.billing.BatchedLogBuffer; +import java.util.Objects; + +/** + * Metrics for uploading billing events, mostly around what is sent to S3 See {@link + * io.stargate.sgv2.jsonapi.service.billing.S3BatchedLogUploader} + */ +public final class BatchedLogUploaderMetrics extends MetricsBase { + + public final Counter uploadedBatches; + public final Counter uploadedBytes; + public final Timer uploadedHeadAgeMs; + public final Counter uploadedEvents; + + public final Counter failedBatches; + public final Counter failedEvents; + + public BatchedLogUploaderMetrics(MeterRegistry meterRegistry, String prefix) { + super(meterRegistry, prefix); + + this.uploadedBatches = newCounter("uploaded.batches"); + this.uploadedBytes = newCounter("uploaded.bytes"); + this.uploadedEvents = newCounter("uploaded.events"); + this.uploadedHeadAgeMs = newTimer("uploaded.oldest_event"); + + this.failedBatches = newCounter("failed.batches"); + this.failedEvents = newCounter("failed.events"); + } + + public void recordBatchDelivered(BatchedLogBuffer.Batch batch) { + + Objects.requireNonNull(batch, "batch must not be null"); + uploadedBatches.increment(); + uploadedBytes.increment(batch.bytes()); + uploadedHeadAgeMs.record(batch.oldestEventAtDuration()); + uploadedEvents.increment(batch.size()); + } + + public void recordBatchFailed(BatchedLogBuffer.Batch batch) { + + Objects.requireNonNull(batch, "batch must not be null"); + failedBatches.increment(); + failedEvents.increment(batch.size()); + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/metrics/MetricsBase.java b/src/main/java/io/stargate/sgv2/jsonapi/metrics/MetricsBase.java new file mode 100644 index 0000000000..3882585a42 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/metrics/MetricsBase.java @@ -0,0 +1,72 @@ +package io.stargate.sgv2.jsonapi.metrics; + +import io.micrometer.core.instrument.*; +import java.util.Objects; +import java.util.concurrent.TimeUnit; +import java.util.function.Supplier; + +/** + * Common base for classes that create metric measures + * + *

Use this so that metrics have a common name, and use the factory functions when creating new + * metrics so we can push them through a single point of control + */ +public abstract class MetricsBase { + + protected final MeterRegistry meterRegistry; + protected final String prefix; + + /** + * Creates a new instance. + * + * @param meterRegistry Registry that metrics will be registered with. + * @param prefix Prefix that is given to all metrics created with the factory functions + */ + protected MetricsBase(MeterRegistry meterRegistry, String prefix) { + + this.meterRegistry = Objects.requireNonNull(meterRegistry, "meterRegistry must not be null"); + this.prefix = Objects.requireNonNull(prefix, "prefix must not be null"); + if (prefix.isBlank()) { + throw new IllegalArgumentException("prefix must not be blank"); + } + } + + protected String validateName(String name) { + Objects.requireNonNull(name, "name must not be null"); + if (name.isBlank()) { + throw new IllegalArgumentException("name must not be blank"); + } + + return name.charAt(0) == '.' ? name : "." + name; + } + + protected String fullName(String name) { + return prefix + validateName(name); + } + + protected Counter newCounter(String name) { + return meterRegistry.counter(fullName(name)); + } + + protected Gauge newGauge(String name, Supplier func) { + // no null checks in the builder below + Objects.requireNonNull(func, "func must not be null"); + + return Gauge.builder(fullName(name), func) + .strongReference(true) // is set in builder() above just being explicit + .register(meterRegistry); + } + + protected Timer newTimer(String name) { + return newTimer(name, 0.5, 0.95, 0.99); + } + + protected Timer newTimer(String name, double... percentiles) { + return Timer.builder(fullName(name)).publishPercentiles(percentiles).register(meterRegistry); + } + + protected TimeGauge newTimeGauge(String name, Supplier func, TimeUnit unit) { + + return TimeGauge.builder(fullName(name), func, unit).register(meterRegistry); + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/AsyncBatchedLogUploader.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/AsyncBatchedLogUploader.java new file mode 100644 index 0000000000..df4b5242dc --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/AsyncBatchedLogUploader.java @@ -0,0 +1,28 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import io.smallrye.mutiny.Uni; + +/** A function that uploads a batch of log records, normally to S3. */ +@FunctionalInterface +public interface AsyncBatchedLogUploader extends AutoCloseable { + + /** + * Called to upload the batch of records. + * + * @param batch The batch of log records to upload + * @return A Uni of the result of the operation + */ + Uni upload(BatchedLogBuffer.Batch batch); + + /** Overridden to remove the throwable declared in {@link AutoCloseable#close()} */ + @Override + default void close() {} + + /** + * Result of the upload call. + * + * @param batch The batch that was uploaded, or attempted to be uploaded. + * @param throwable The throwable associated with an error state. + */ + record UploadResult(BatchedLogBuffer.Batch batch, Throwable throwable) {} +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBuffer.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBuffer.java new file mode 100644 index 0000000000..ff59d6a8e4 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBuffer.java @@ -0,0 +1,431 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.ClassUtils.classSimpleName; + +import com.fasterxml.uuid.Generators; +import com.fasterxml.uuid.NoArgGenerator; +import com.google.common.annotations.VisibleForTesting; +import io.stargate.sgv2.jsonapi.metrics.BatchedLogBufferMetrics; +import java.time.Clock; +import java.time.Duration; +import java.time.Instant; +import java.util.*; +import java.util.concurrent.ArrayBlockingQueue; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicLong; +import java.util.logging.LogRecord; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * Buffer for {@link LogRecord} that batches them according to the configuration when created. + * + *

There are two users of this class: + * + *

+ * + * The buffer is designed to handle these as concurrent calls from different threads, and tracks + * metrics for its use. + */ +public class BatchedLogBuffer { + + private static final Logger LOGGER = LoggerFactory.getLogger(BatchedLogBuffer.class); + + @VisibleForTesting static final Clock DEFAULT_CLOCK = Clock.systemUTC(); + + private final int maxBatchSize; + private final long maxBatchBytes; + private final Duration maxBatchAge; + + // don't really need to keep this, just here for debugging + private final int capacity; + + // Clock we use to get the current time when checking age. + // so it can be controlled when testing + private final Clock clock; + + private final BlockingQueue queue; + private final AtomicLong queuedBytes = new AtomicLong(0); + private final BatchedLogBufferMetrics metrics; + + /** + * Creates a new instance using the {@link #DEFAULT_CLOCK}. + * + *

See {@link #BatchedLogBuffer(int, long, Duration, int, BatchedLogBufferMetrics, Clock)} + */ + BatchedLogBuffer( + int maxBatchSize, + long maxBatchBytes, + Duration maxBatchAge, + int capacity, + BatchedLogBufferMetrics metrics) { + this(maxBatchSize, maxBatchBytes, maxBatchAge, capacity, metrics, DEFAULT_CLOCK); + } + + /** + * Creates a new instance of the buffer with configuration. + * + *

NOTE: this ctor is for use in testing when the Clock is overridden, use the other + * ctor in regular code. + * + * @param maxBatchSize Maximum number of log records in a batch, when the buffer has more than + * this many entries a new batch is made available which will contain no more than this many + * lines. Batch maybe smaller if maxBatchBytes is hit. + * @param maxBatchBytes Maximum numbers of bytes in a batch, when the buffer has more than this + * many entries a new batch is made available which may contain more than this many bytes. The + * batch will have more than maxBatchBytes if there is a single log record that is bigger. + * @param maxBatchAge Maximum age the head log record should have in the buffer before a new batch + * is available. When a batch is triggered from max age the batch is filled, even if the other + * messages have not reached their max age. + * @param capacity Total number of log records to buffer. Beyond this called to {@link + * #offer(LogRecord)} will fail to add the message. + * @param metrics Metrics recording object. + * @param clock The {@link Clock} implementation to use when checking the age of a message, this + * should only be overridden in testing. DO NOT USE IN PROD CODE. If null uses {@link + * #DEFAULT_CLOCK} + */ + @VisibleForTesting + BatchedLogBuffer( + int maxBatchSize, + long maxBatchBytes, + Duration maxBatchAge, + int capacity, + BatchedLogBufferMetrics metrics, + Clock clock) { + + if (maxBatchSize < 1) { + throw new IllegalArgumentException("maxBatchSize must be >= 1, got: " + maxBatchSize); + } + if (maxBatchBytes < 1) { + throw new IllegalArgumentException("maxBatchBytes must be >= 1, got: " + maxBatchBytes); + } + if (maxBatchAge == null || maxBatchAge.isNegative() || maxBatchAge.isZero()) { + throw new IllegalArgumentException("maxAge must be positive, got: " + maxBatchAge); + } + + this.maxBatchSize = maxBatchSize; + this.maxBatchBytes = maxBatchBytes; + this.maxBatchAge = maxBatchAge; + this.capacity = capacity; + this.metrics = Objects.requireNonNull(metrics, "billingMetrics must not be null"); + + this.clock = clock == null ? DEFAULT_CLOCK : clock; + if (this.clock != DEFAULT_CLOCK) { + LOGGER.warn( + "BatchedLogBuffer - WARNING - CONFIGURED TO USE A CUSTOM CLOCK, DO NOT USE IN PRODUCTION."); + } + // must be concurrent to handle multiple threads + this.queue = new ArrayBlockingQueue<>(capacity); + + // just to be safe, register after queue created in case metrics are scrapped + this.metrics.registerBuffer(this); + } + + /** + * Appends the LogRecord to the buffer if the buffer has capacity. + * + *

NOTE: because this is used for billing information if the record is null or has an + * empty message an exception is thrown rather than silently dropping it. We expect this situation + * to be an exception and it should fail. + * + * @param record {@link LogRecord} to add to the buffer. + * @return true if the record was added to be buffer, false if the buffer did not have capacity. + */ + public boolean offer(LogRecord record) { + + Objects.requireNonNull(record, "record must not be null"); + + var logLine = record.getMessage(); + if (logLine == null || logLine.isBlank()) { + throw new IllegalArgumentException("record.getMessage() must not be null or blank"); + } + var newEntry = new Entry(record.getInstant(), logLine); + + metrics.incrementOffered(); + if (!queue.offer(newEntry)) { + // Bounded buffer full, drop and count + LOGGER.warn("offer() - buffer full, dropping new entry: {}", newEntry); + metrics.incrementDropped(); + return false; + } + + queuedBytes.addAndGet(newEntry.lineBytes()); + return true; + } + + /** + * Returns the next batch of messages from the {@link LogRecord}'s added to the buffer, if one is + * available. + * + *

Designed to be called from different threads than the producers called {@link + * #offer(LogRecord)} + * + * @param drainFully when True a new batch is created without checking the configured rules, use + * this when draining the buffer and there may only be a partial batch. + * @return A new {@link Batch} of log messages all of which have been removed from the buffer, or + * null if there is no next batch. Keep calling with drainFully true + * until a null is returned to drain the buffer. + */ + public Batch nextBatch(boolean drainFully) { + + var batchReason = decideNextBatch(drainFully); + if (batchReason == null) { + return null; + } + + List batchLines = new ArrayList<>(maxBatchSize); + Instant oldestEventAt = null; + long batchBytes = 0; + Entry peeked; + + // Decided we want a batch, lets fill it. + // No matter why we started we create a full batch, e.g. we could start because the oldest + // entry is past maxAge, but we still fill the batch. + while (batchLines.size() < maxBatchSize && ((peeked = queue.peek()) != null)) { + + var lineBytes = peeked.lineBytes(); + if (batchBytes + lineBytes > maxBatchBytes && !batchLines.isEmpty()) { + // adding the next line will be too many bytes, we can only do this if the batch + // is empty, so a single big message can be put into a batch and not block everyone else + // break out of here. + break; + } + + // OK to remove entry from buffer and add to batch + // there is only this thread as a consumer, no race condition + var polled = queue.poll(); + // sanity check + if (polled != peeked) { + throw new IllegalStateException( + "nextBatch() - peeked entry is not same object as polled entry"); + } + if (oldestEventAt == null || polled.eventAt().isBefore(oldestEventAt)) { + oldestEventAt = polled.eventAt(); + } + batchLines.add(polled.line()); + queuedBytes.addAndGet(-lineBytes); + batchBytes += lineBytes; + } + + if (batchLines.isEmpty() && !queue.isEmpty()) { + // sanity check + // there is messages in the queue, but we did not put any in the batch, something wrong + // but it could be a race condition - things may be added after the loop finish + // so do not throw, just log + LOGGER.warn( + "nextBatch() - did not add any lines for next batch, but queue is not empty. May be logic bug or expected race condition. queue.size:{}", + queue.size()); + return null; + } + + var batch = new Batch(batchReason, batchLines, batchBytes, oldestEventAt, clock); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("nextBatch() - next batch created, batch:{}", batch); + } + return batch; + } + + /** Gets a copy of the contents of the buffer in a new array list, for testing. */ + @VisibleForTesting + List peekBuffer() { + return new ArrayList<>(queue); + } + + public boolean isEmpty() { + return queue.isEmpty(); + } + + public int size() { + return queue.size(); + } + + public long queuedBytes() { + return queuedBytes.get(); + } + + public int remainingCapacity() { + return queue.remainingCapacity(); + } + + /** + * Gets the age of the item at the head of the buffer. + * + *

Age is determined by the clock used to create the buffer. + * + * @return age of the head item in the buffer, or null if no items in the buffer. + */ + public Duration headEntryAge() { + return entryAge(queue.peek()); + } + + @VisibleForTesting + Duration entryAge(Entry entry) { + return entry == null ? Duration.ZERO : Duration.between(entry.eventAt(), clock.instant()).abs(); + } + + private BillingBatchReason decideNextBatch(boolean drainFully) { + + BillingBatchReason decision; + if (queue.isEmpty()) { + decision = null; + } else if (drainFully) { + decision = BillingBatchReason.DRAINING; + } else if (queue.size() >= maxBatchSize) { + decision = BillingBatchReason.MAX_SIZE_EXCEEDED; + } else if (queuedBytes.get() >= maxBatchBytes) { + decision = BillingBatchReason.MAX_BYTES_EXCEEDED; + } else if (headEntryAge().compareTo(maxBatchAge) >= 0) { + decision = BillingBatchReason.MAX_AGE_EXCEEDED; + } else { + decision = null; + } + if (LOGGER.isTraceEnabled()) { + LOGGER.trace("decideNextBatch() - drainFully:{} , decision:{}", drainFully, decision); + } + return decision; + } + + @Override + public String toString() { + return new StringBuilder(classSimpleName(this) + "{") + .append("maxBatchSize=") + .append(maxBatchSize) + .append(", maxBatchBytes=") + .append(maxBatchBytes) + .append(", maxBatchAge=") + .append(maxBatchAge) + .append(", size=") + .append(size()) + .append("}") + .toString(); + } + + /** + * The reason a batch was created by the buffer. + * + *

... + */ + public enum BillingBatchReason { + DRAINING, + MAX_SIZE_EXCEEDED, + MAX_BYTES_EXCEEDED, + MAX_AGE_EXCEEDED + } + + /** + * A batch of log messages created by the buffer. + * + *

See {@link BatchedLogBuffer#nextBatch(boolean)} + */ + public static final class Batch { + + private static final NoArgGenerator UUID_V7_GENERATOR = Generators.timeBasedEpochGenerator(); + + private final UUID id = UUID_V7_GENERATOR.generate(); + private final BillingBatchReason reason; + private final List lines; + private final long bytes; + private final Instant oldestEventAt; + private final Clock clock; + + Batch(BillingBatchReason reason, List lines, long bytes, Instant oldestEventAt) { + this(reason, lines, bytes, oldestEventAt, DEFAULT_CLOCK); + } + + private Batch( + BillingBatchReason reason, + List lines, + long bytes, + Instant oldestEventAt, + Clock clock) { + this.reason = Objects.requireNonNull(reason, "reason must not be null"); + this.lines = + Collections.unmodifiableList(Objects.requireNonNull(lines, "lines must not be null")); + this.bytes = bytes; + this.oldestEventAt = Objects.requireNonNull(oldestEventAt, "oldestEventAt must not be null"); + this.clock = Objects.requireNonNull(clock, "clock must not be null"); + } + + public UUID id() { + return id; + } + + public BillingBatchReason reason() { + return reason; + } + + public List lines() { + return lines; + } + + public Instant oldestEventAt() { + return oldestEventAt; + } + + public Duration oldestEventAtDuration() { + // using the outer buffers clock, so any tests that change the clock + // get a consistent results + return Duration.between(oldestEventAt(), clock.instant()).abs(); + } + + public int size() { + return lines.size(); + } + + public long bytes() { + return bytes; + } + + @Override + public String toString() { + return new StringBuilder(classSimpleName(this) + "{") + .append("id=") + .append(id) + .append(", reason=") + .append(reason) + .append(", oldestEventAt=") + .append(oldestEventAt) + .append(", size=") + .append(size()) + .append(", bytes=") + .append(bytes()) + .append("}") + .toString(); + } + } + + /** + * An entry in a batch, this is one log message passed to the buffer. + * + * @param eventAt When the log event happened + * @param line The log message + */ + public record Entry(Instant eventAt, String line) { + + /** + * Gets the length of the line in bytes, + * + *

Kind of a hack, we are counting Unicode code points and calling that 1 byte. Should work + * for ascii text, will undercount if there is non ASCII chars but everything in billing should + * be ascii + * + * @return length of the line in bytes, included a carriage return for `\n` + */ + public int lineBytes() { + return lineBytes(line); + } + + /** + * @return length of the line in bytes, included a carriage return for `\n` + */ + @VisibleForTesting + static int lineBytes(String line) { + return line.length() + 1; + } + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/Billing.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/Billing.java similarity index 55% rename from src/main/java/io/stargate/sgv2/jsonapi/service/provider/Billing.java rename to src/main/java/io/stargate/sgv2/jsonapi/service/billing/Billing.java index 3bb0a72549..6ae650596a 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/Billing.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/Billing.java @@ -1,35 +1,22 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import io.stargate.sgv2.jsonapi.config.BillingConfig; import io.stargate.sgv2.jsonapi.config.feature.ApiFeature; import io.stargate.sgv2.jsonapi.config.feature.ApiFeatures; +import io.stargate.sgv2.jsonapi.service.provider.ModelUsage; import java.util.Objects; /** * Per-request billing sink for model calls. * *

Get an instance via {@code requestContext.billing()}, which delegates to {@link - * #create(BillingConfig, ApiFeatures)} to pick the right implementation for the request: + * #create(BillingConfig, ApiFeatures)} to pick the right implementation for the request * - *

- * - * Pass each aggregated {@link ModelUsage} to {@link #emitEvent(ModelUsage)}. {@code modelUsage} - * must be non-null — callers are responsible for ensuring usage data exists before invoking. + *

Call {@link #emitEvent(ModelUsage)} to generate a billing event for the model usage, the + * implementation takes care of where the event goes. */ public interface Billing { - /** - * Emits billing events for the given aggregated model usage. - * - * @param modelUsage usage data for the model call; must not be null. - */ - void emitEvent(ModelUsage modelUsage); - /** * Shared NO-OP {@link Billing}. Still enforces the non-null {@code modelUsage} contract so tests * (and the feature-disabled production path) don't accidentally mask null-passing bugs in calling @@ -38,17 +25,29 @@ public interface Billing { Billing NO_OP = modelUsage -> Objects.requireNonNull(modelUsage, "modelUsage must not be null"); /** - * Factory that picks the right {@link Billing} implementation for the current request. - * Centralizes the {@code DefaultBilling vs NO_OP} dispatch so callers (e.g. {@link - * io.stargate.sgv2.jsonapi.api.request.RequestContext}) don't have to know the rule. Reads {@code - * config} only when the feature is enabled — when disabled it is fine to pass any value, - * including one that would not validate as a real config. + * Emits billing events for the given model usage. + * + * @param modelUsage usage data for the model call; must not be null. + */ + void emitEvent(ModelUsage modelUsage); + + /** + * Factory to create the correct instance of {@link Billing} for a given request. + * + *

* * @param config billing configuration; only consulted when the feature is enabled * @param apiFeatures the request's resolved feature set; must not be null */ static Billing create(BillingConfig config, ApiFeatures apiFeatures) { + Objects.requireNonNull(apiFeatures, "apiFeatures must not be null"); + return apiFeatures.isFeatureEnabled(ApiFeature.BILLING_EVENTS_LOGGING) ? new DefaultBilling(config) : NO_OP; diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEvent.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEvent.java similarity index 98% rename from src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEvent.java rename to src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEvent.java index 2f2bbcdfa3..9ec7e70e45 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEvent.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEvent.java @@ -1,4 +1,4 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import com.fasterxml.jackson.annotation.JsonInclude; import com.fasterxml.jackson.annotation.JsonProperty; @@ -13,7 +13,7 @@ * A billing event emitted as a structured JSON log line for downstream billing pipelines. * *

Each event represents a single billable unit from a user request (e.g. token usage or egress - * bytes for an embedding or reranking call). Constructed and emitted by {@link Billing}. + * bytes for an embedding or reranking call). Constructed and emitted by {@link DefaultBilling}. * *

Example serialized form: * diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventType.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventType.java similarity index 94% rename from src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventType.java rename to src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventType.java index 43f90cb2d0..9626f46b62 100644 --- a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventType.java +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventType.java @@ -1,4 +1,4 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import com.fasterxml.jackson.annotation.JsonValue; import java.util.EnumSet; @@ -43,8 +43,7 @@ public enum Metric { private final Metric metric; BillingEventType(String eventName, boolean internal, Metric metric) { - // Event names are emitted lower-case in the JSON billing event payload; normalize defensively - // so a stray uppercase character in the literal can't break downstream consumers. + // Event names are emitted lower-case in the JSON billing event payload this.eventName = eventName.toLowerCase(); this.internal = internal; this.metric = metric; diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3Lifecycle.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3Lifecycle.java new file mode 100644 index 0000000000..d07ff50d92 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3Lifecycle.java @@ -0,0 +1,142 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import com.google.common.annotations.VisibleForTesting; +import io.micrometer.core.instrument.MeterRegistry; +import io.quarkus.runtime.ShutdownEvent; +import io.quarkus.runtime.StartupEvent; +import io.smallrye.mutiny.infrastructure.Infrastructure; +import io.stargate.sgv2.jsonapi.config.BillingS3UploadConfig; +import io.stargate.sgv2.jsonapi.metrics.BatchedLogBufferMetrics; +import io.stargate.sgv2.jsonapi.metrics.BatchedLogUploaderMetrics; +import jakarta.enterprise.context.ApplicationScoped; +import jakarta.enterprise.event.Observes; +import jakarta.inject.Inject; +import java.util.logging.Logger; +import org.slf4j.LoggerFactory; + +/** + * Lifecycle management for sending billing events to S3. + * + *

If configured to upload to S3, a long-running task is started using the {@link + * Infrastructure#getDefaultWorkerPool()} in the background for the {@link + * BillingUploadingLogHandler#startUploading()} to run on. + * + *

S3 uploading is controlled with the {@link BillingS3UploadConfig} + * + *

+ */ +@ApplicationScoped +public class BillingS3Lifecycle { + + private static final org.slf4j.Logger LOGGER = LoggerFactory.getLogger(BillingS3Lifecycle.class); + + public static final String METRICS_PREFIX = "billing"; + + private final BillingS3UploadConfig config; + private final MeterRegistry meterRegistry; + + private volatile BillingUploadingLogHandler handler; + + @Inject + public BillingS3Lifecycle(BillingS3UploadConfig config, MeterRegistry meterRegistry) { + this.config = config; + this.meterRegistry = meterRegistry; + } + + @VisibleForTesting + protected BillingUploadingLogHandler handler() { + return this.handler; + } + + void onStart(@Observes StartupEvent event) { + + if (!config.enabled()) { + LOGGER.info("onStart() - S3 export disabled"); + return; + } + + LOGGER.info("onStart() - S3 export enabled"); + + var uploader = + S3BatchedLogUploader.create( + config.region(), + config.bucket(), + config.endpointOverride().orElse(null), + config.s3PathPrefix(), + config.s3CallAttemptTimeout(), + config.s3TotalCallTimeout(), + config.s3RetryMode(), + new BatchedLogUploaderMetrics(meterRegistry, METRICS_PREFIX + ".s3")); + LOGGER.info("onStart() - using uploader: {}", uploader); + + var buffer = + new BatchedLogBuffer( + config.bufferMaxBatchSize(), + config.bufferMaxBatchBytes(), + config.bufferMaxBatchAge(), + config.bufferCapacity(), + new BatchedLogBufferMetrics(meterRegistry, METRICS_PREFIX)); + LOGGER.info("onStart() - using log buffer: {}", buffer); + + this.handler = + new BillingUploadingLogHandler( + buffer, + uploader, + config.handlerSleepDuration(), + config.handlerUploadSafetyDeadline(), + config.handlerUploadShutdownDeadline()); + LOGGER.info("onStart() - using handler: {}", handler); + + var billingLogger = Logger.getLogger(DefaultBilling.BILLING_LOGGER_NAME); + if (config.disableOtherHandlers()) { + LOGGER.info("onStart() - removing existing log handlers"); + for (var existing : billingLogger.getHandlers()) { + LOGGER.info("onStart() - removing existing log handler. existing:{} ", existing); + billingLogger.removeHandler(existing); + } + } else { + LOGGER.info("onStart() - leaving existing log handlers"); + } + + billingLogger.addHandler(this.handler); + LOGGER.info( + "onStart() - attached log handler to logger. BILLING_LOGGER_NAME: {}", + DefaultBilling.BILLING_LOGGER_NAME); + + Infrastructure.getDefaultWorkerPool() + .execute( + () -> { + LOGGER.info( + "onStart() - on worked pool thread, calling handler.startUploading() on this thread"); + this.handler.startUploading(); + }); + } + + void onStop(@Observes ShutdownEvent event) { + + if (this.handler == null) { + LOGGER.info("onStop() - handler was null, nothing to close"); + return; + } + + Logger.getLogger(DefaultBilling.BILLING_LOGGER_NAME).removeHandler(this.handler); + LOGGER.info( + "onStop() - handler removed from logger. BILLING_LOGGER_NAME:{}", + DefaultBilling.BILLING_LOGGER_NAME); + + // close() isn't expected to throw, but if it does (e.g. client.close() failing), letting it + // propagate would disrupt other components' cleanup in Quarkus's shutdown sequence. + try { + LOGGER.debug("onStop() - calling handler.close()"); + this.handler.close(); + LOGGER.info("onStop() - handler was closed without error"); + } catch (Exception e) { + LOGGER.warn("onStop() - error calling handler.close(), swallowing", e); + } + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandler.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandler.java new file mode 100644 index 0000000000..7d3091ba25 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandler.java @@ -0,0 +1,382 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.ClassUtils.classSimpleName; + +import com.google.common.annotations.VisibleForTesting; +import io.smallrye.mutiny.Uni; +import java.time.Duration; +import java.util.Objects; +import java.util.concurrent.Semaphore; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.logging.Handler; +import java.util.logging.LogRecord; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * A Logging handler designed to be used with the Billing system. It accepts billing event log + * messages, batches them, and then sends to S3. + * + *

See {@link BillingS3Lifecycle} for setup. + * + *

Designed to be used in two ways: + * + *

+ */ +public final class BillingUploadingLogHandler extends Handler { + + // Logger for this handler, not the destination we are sending events to. + private static final Logger LOGGER = LoggerFactory.getLogger(BillingUploadingLogHandler.class); + + /** + * When true means the Handler has been closed via {@link #close()} and it will silently drop any + * further calls to publish log entries. This also cause the upload thread to empty the buffer + */ + private final AtomicBoolean isClosed = new AtomicBoolean(false); + + /** + * Disposable permitting system for forcing wakeup in the uploading thread. startUploading() will + * tryAcquire() but because the permit count is 0 will always timeout, this is the timeout to wake + * and check buffer. When we want to force wakeup, e.g. flush(), we call release() that means any + * tryAcquire() returns and decrements count to 0. Resetting back to initial state. Because the + * wakeup permit lasts until tryAcquire it removes race conditions that could happen when + * flush()/notify() on an object lands before the upload thread is in wait() - if we used + * Object.notify() and .wait() + */ + private final Semaphore wakeupPermit = new Semaphore(0); + + /** + * There is only 1 permit for the upload process to be running. When {@link #startUploading()} + * starts it takes the permit, gives it back when the function exits (after {@link #close()}. + * close() uses this to make sure uploading has finished. + */ + private final Semaphore uploadPermit = new Semaphore(1); + + private final AsyncBatchedLogUploader uploader; + private final BatchedLogBuffer buffer; + private final Duration uploadSleepDuration; + private final Duration uploaderSafetyDeadline; + private final Duration uploadShutdownDeadline; + + /** + * Creates a new instance, see {@link BillingS3Lifecycle} + * + * @param buffer A configured buffer that is used to buffer incoming log messages + * @param uploader {@link AsyncBatchedLogUploader} to upload messages when the buffer has a new + * batch. + * @param uploadSleepDuration Duration the thread running {@link #startUploading()} will sleep + * waiting for a new batch from the buffer. + * @param uploaderSafetyDeadline Duration to wait for the uploader to return from uploading. NOTE: + * the uploader should have its own internal timeouts, this is to prevent the uploading thread + * blocking. + * @param uploadShutdownDeadline Duration a call to {@link #close()} should wait for the uploading + * thread to complete flushing remaining events. + */ + BillingUploadingLogHandler( + BatchedLogBuffer buffer, + AsyncBatchedLogUploader uploader, + Duration uploadSleepDuration, + Duration uploaderSafetyDeadline, + Duration uploadShutdownDeadline) { + + this.buffer = Objects.requireNonNull(buffer, "buffer must not be null"); + this.uploader = Objects.requireNonNull(uploader, "uploader must not be null"); + this.uploadSleepDuration = + Objects.requireNonNull(uploadSleepDuration, "uploadSleepDuration must not be null"); + this.uploaderSafetyDeadline = + Objects.requireNonNull(uploaderSafetyDeadline, "uploaderSafetyDeadline must not be null"); + this.uploadShutdownDeadline = + Objects.requireNonNull(uploadShutdownDeadline, "uploadShutdownDeadline must not be null"); + } + + /** + * WARNING - sets the flag for closing but does not run the full close. just here for testing how + * uploading wakes up when flush called. + */ + @VisibleForTesting + void unsafeClose() { + LOGGER.warn("WARNING - unsafeClose() called, must only be used in testing"); + isClosed.set(true); + } + + /** + * WARNING - acquires the upload permit, this stops the startUpload() function and close() from + * working normally. For testing only. + */ + @VisibleForTesting + void unsafeAcquireUploadPermit() { + LOGGER.warn("WARNING - unsafeAcquireUploadPermit() called, must only be used in testing"); + uploadPermit.acquireUninterruptibly(); + } + + // ============================================================ + // Overrides for java.util.logging.Handler + // ============================================================ + + /** + * Buffers and then publishes the record to S3. + * + * @param record description of the log event. A null record is silently ignored and is not + * published. + */ + @Override + public void publish(LogRecord record) { + + // Sanity check + if (record == null) { + return; + } + + if (isClosed.get()) { + LOGGER.warn("publish() - called when closed, dropping record:{}", record); + return; + } + + // buffer handles metrics + if (!buffer.offer(record)) { + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "publish() - buffer.offer() rejected, dropping record:{}", record.getMessage()); + } + } else if (LOGGER.isTraceEnabled()) { + LOGGER.trace("publish() - buffer.offer() accepted, record:{}", record.getMessage()); + } + } + + /** + * Wakes up the uploading thread to check the buffer for batches. + * + *

This will only drain the buffer fully (i.e. including partial batches) if {@link #close()} + * is called or {@link #isClosed} is set. + */ + @Override + public void flush() { + maybeTrace("flush() - called"); + notifyUploading(); + } + + /** + * Closes the LogHandler so that it will drop any records sent to {@link #publish(LogRecord)} and + * drain the buffer fully to send all batches to the uploader. + */ + @Override + public void close() { + + LOGGER.info( + "closing() - marking handler closed, flushing, and waiting for uploads to complete. uploadShutdownDeadline:{}", + uploadShutdownDeadline); + + // mark as closed to stop accepting further events and tell the upload thread + // to drain the buffer fully. + isClosed.set(true); + flush(); + + try { + // Check uploading is not running by trying to get the single uploading permit + if (!uploadPermit.tryAcquire(uploadShutdownDeadline.toMillis(), TimeUnit.MILLISECONDS)) { + LOGGER.warn( + "close() - Failed to get uploading permit, upload failed to stop. uploadShutdownDeadline:{}", + uploadShutdownDeadline); + } else { + uploadPermit.release(); + LOGGER.debug("close() - acquired uploading permit, uploading has completed."); + } + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + LOGGER.warn("close() - Interrupted waiting for billing upload loop to finish"); + } finally { + uploader.close(); + } + } + + // ============================================================ + // Flush pipeline + // ============================================================ + + /** + * Call this on a worker thread to start uploading, will start a loop of waiting for batches from + * the buffer and uploading them. + * + *

Call {@link #close()} to signal this function to stop waiting, upload all events, and + * return. + */ + void startUploading() { + + LOGGER.info("startUploading() - handler:{}, buffer:{}, uploader:{}", this, buffer, uploader); + + boolean hasUploadPermit = false; + BatchedLogBuffer.Batch batch; + try { + if (!(hasUploadPermit = uploadPermit.tryAcquire())) { + throw new IllegalStateException( + "startUploading() - unable to acquire uploadPermit, was function already called?"); + } + + while (true) { + + // if the handler is closed we do not want to go to sleep again because it is closing + // down. + if (!isClosed.get()) { + try { + maybeTrace( + "startUploading() - waiting for wakeupPermit. isClosed:{}, uploadSleepDuration:{}", + isClosed.get(), + uploadSleepDuration); + var acquiredWakePermit = + wakeupPermit.tryAcquire(uploadSleepDuration.toMillis(), TimeUnit.MILLISECONDS); + // is not important if we got a permit to wake, or timed out, just for logging + maybeTrace( + "startUploading() - wakeup permit or timeout, isClosed:{}, acquiredWakePermit:{}", + isClosed.get(), + acquiredWakePermit); + + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + dumpBuffer(); + return; + } + } else { + maybeTrace( + "startUploading() - not waiting for wakeupPermit because isClosed:{}", + isClosed.get()); + } + + // Get the next batches, if isClosed is true then we want to drain all events + // which may mean creating a batch when we do not have a full one. + while ((batch = buffer.nextBatch(isClosed.get())) != null) { + uploadBatch(batch); + } + + if (isClosed.get()) { + // Handler is closing down, time to get out of this crazy loop + break; + } + } + } finally { + // release the uploading permit if we have it, to signal close() to stop waiting + if (hasUploadPermit) { + uploadPermit.release(); + maybeTrace("startUploading() - releasing upload permit"); + } else { + maybeTrace("startUploading() - upload permit was not acquired, not releasing"); + } + } + + if (!buffer.isEmpty()) { + LOGGER.warn( + "startUploading() - finished with abandoned billing events, billingQueue.size():{} ", + buffer.size()); + } + + LOGGER.info( + "startUploading() - stopped uploading. handler:{}, buffer:{}, uploader:{}", + this, + buffer, + uploader); + } + + /** Signals the thread running {@link #startUploading()} to wake up and check for work. */ + private void notifyUploading() { + // Adds a permit to the wakeupPermit so the uploading thread will wakeup and do some work. + wakeupPermit.release(); + } + + private static void maybeTrace(String message, Object... args) { + if (LOGGER.isTraceEnabled()) { + LOGGER.trace(message, args); + } + } + + /** Creates a Uni that will upload the provided batch. */ + private void uploadBatch(BatchedLogBuffer.Batch batch) { + + LOGGER.info( + "uploadBatch() - starting to upload. uploaderSafetyDeadline:{}, batch:{}", + uploaderSafetyDeadline, + batch); + + // while the uploader should take of all the timeout and retry logic + // as a client of the uploader adding a safety timeout here in case it breaks. + // we do not want the uploader hanging to block this thread. + + // using deferred so that an error in upload() before it returns the Uni is then + // treated as an error through the Uni pipeline + var uploadResult = + Uni.createFrom() + .deferred(() -> uploader.upload(batch)) + .ifNoItem() + .after(uploaderSafetyDeadline) + .fail() + .onFailure() + .recoverWithItem( + t -> onUploaderFailure(batch, t)) // TimeoutException id deadline exceeded + .await() + .indefinitely(); // the deadline above covers it, this causes deferred to start exec'ing + + if (uploadResult.throwable() == null) { + onBatchSuccess(uploadResult); + } else { + onBatchFailure(uploadResult); + } + } + + /** + * There was an unhandled error from the uploader(). + * + *

Could be from in upload() before it returned or from running the Uni to do the upload. Just + * map this unhandled back into the UploadResult so we can deal with error in standard way + */ + private AsyncBatchedLogUploader.UploadResult onUploaderFailure( + BatchedLogBuffer.Batch batch, Throwable throwable) { + LOGGER.error( + "onUploaderFailure() - throwable from uploader, adding to UploadResult. batch:{}, throwable:{}", + batch, + throwable.toString()); + return new AsyncBatchedLogUploader.UploadResult(batch, throwable); + } + + private void onBatchSuccess(AsyncBatchedLogUploader.UploadResult uploadResult) { + LOGGER.info("onBatchSuccess() - successfully uploaded batch:{}", uploadResult.batch()); + } + + private void onBatchFailure(AsyncBatchedLogUploader.UploadResult uploadResult) { + LOGGER.error("onBatchFailure() - failed to upload batch:{}", uploadResult.batch()); + dumpBuffer(); + } + + /** TODO: dump buffer or a failed batch to regular logs or whatever */ + private void dumpBuffer() { + LOGGER.warn("dumpBuffer() - DUMP BUFFER CALLED, NOT IMPLEMENTED YET!"); + } + + private void dumpBatch(BatchedLogBuffer.Batch batch) { + LOGGER.warn("dumpBuffer() - DUMP BATCH CALLED, NOT IMPLEMENTED YET!"); + } + + @Override + public String toString() { + return new StringBuilder(classSimpleName(this) + "{") + .append("uploadSleepDuration=") + .append(uploadSleepDuration) + .append(", uploadShutdownDeadline=") + .append(uploadShutdownDeadline) + .append(", uploaderSafetyDeadline=") + .append(uploaderSafetyDeadline) + .append(", isClosed=") + .append(isClosed) + .append(", wakeupPermit.availablePermits=") + .append(wakeupPermit.availablePermits()) + .append(", uploadPermit.availablePermits=") + .append(uploadPermit.availablePermits()) + .append("}") + .toString(); + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBilling.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBilling.java new file mode 100644 index 0000000000..2b58d8401e --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBilling.java @@ -0,0 +1,131 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.StringUtil.requireNonBlank; + +import com.fasterxml.jackson.core.JacksonException; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.ObjectWriter; +import com.google.common.annotations.VisibleForTesting; +import io.stargate.sgv2.jsonapi.config.BillingConfig; +import io.stargate.sgv2.jsonapi.service.provider.ModelUsage; +import java.time.Instant; +import java.util.ArrayList; +import java.util.List; +import java.util.Objects; +import java.util.Set; +import java.util.UUID; +import java.util.function.Function; +import org.apache.commons.lang3.tuple.Pair; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * {@link Billing} implementation that emits structured JSON log lines on the {@code billing.events} + * logger for downstream billing pipelines. + * + *

For each {@link ModelUsage}, up to three events are emitted, for the egress and ingress bytes + * of the request and the total number of tokens used. See {@link BillingEventType} for which ones + * should be used. + * + *

NOTE: this class relies on the configured format for the billing logger called {@link + * #BILLING_LOGGER_NAME}, it should only log the message on the line because that has the JSON of + * the {@link BillingEvent} + */ +public class DefaultBilling implements Billing { + + /** Name of the logger that billing events will be sent to. */ + public static final String BILLING_LOGGER_NAME = "billing.events"; + + private static final Logger BILLING_LOGGER = LoggerFactory.getLogger(BILLING_LOGGER_NAME); + private static final Logger LOGGER = LoggerFactory.getLogger(DefaultBilling.class); + + private static final ObjectWriter OBJECT_WRITER = new ObjectMapper().writer(); + + // There are three metrics, but 6 Event Types, because 3 each for internal or external provider. + // this is the mapping of the metric and where we get it from + private static final List>> + METRICS_PER_USAGE = + List.of( + Pair.of(BillingEventType.Metric.TOTAL_TOKENS, ModelUsage::totalTokens), + Pair.of(BillingEventType.Metric.EGRESS_BYTES, ModelUsage::requestBytes), + Pair.of(BillingEventType.Metric.INGRESS_BYTES, ModelUsage::responseBytes)); + + private final String product; + private final String resourceType; + private final Set internalModelProviders; + private final Set enabledEventTypes; + + public DefaultBilling(BillingConfig config) { + Objects.requireNonNull(config, "config must not be null"); + + this.product = requireNonBlank(config.product(), "billing.product"); + this.resourceType = requireNonBlank(config.resourceType(), "billing.resource_type"); + this.internalModelProviders = Set.copyOf(config.internalModelProviders()); + this.enabledEventTypes = + config.enabledEventTypes().map(Set::copyOf).orElse(BillingEventType.ALL); + } + + /** + * Emits billing events for the given aggregated model usage. + * + * @param modelUsage usage data for the model call; must not be null. + */ + @Override + public void emitEvent(ModelUsage modelUsage) { + Objects.requireNonNull(modelUsage, "modelUsage must not be null"); + + if (!BILLING_LOGGER.isInfoEnabled()) { + return; + } + + for (var event : buildEvents(modelUsage)) { + try { + BILLING_LOGGER.info(OBJECT_WRITER.writeValueAsString(event)); + } catch (JacksonException e) { + LOGGER.error("Failed to serialize billing event of type {}", event.eventType(), e); + } + } + } + + /** + * Builds the list of billing events for one {@link ModelUsage}: one event per billable metric + * (total tokens, egress bytes, ingress bytes), with the {@code internal_*} or {@code external_*} + * variant chosen based on {@link BillingConfig#internalModelProviders()}. + * + *

All events from a single {@code ModelUsage} share one timestamp so they can be correlated in + * the billing logs. + */ + @VisibleForTesting + List buildEvents(ModelUsage modelUsage) { + + var internal = internalModelProviders.contains(modelUsage.modelProvider().apiName()); + var region = modelUsage.tenant().region(); + var resourceId = modelUsage.tenant().toString(); + var providerName = modelUsage.modelProvider().apiName(); + var modelName = modelUsage.modelName(); + var timestamp = Instant.now(); + var events = new ArrayList(3); + + for (Pair> pair : METRICS_PER_USAGE) { + + var metric = pair.getLeft(); + var eventType = BillingEventType.of(metric, internal); + var supplier = pair.getRight(); + + if (!enabledEventTypes.contains(eventType)) { + continue; + } + + var properties = + new BillingEvent.BillingProperties( + supplier.apply(modelUsage), + region, + resourceType, + resourceId, + providerName, + modelName); + events.add(new BillingEvent(UUID.randomUUID(), timestamp, product, eventType, properties)); + } + return events; + } +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploader.java b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploader.java new file mode 100644 index 0000000000..cfd234bf40 --- /dev/null +++ b/src/main/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploader.java @@ -0,0 +1,268 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.ClassUtils.classSimpleName; + +import com.google.common.annotations.VisibleForTesting; +import io.smallrye.mutiny.Uni; +import io.smallrye.mutiny.infrastructure.Infrastructure; +import io.stargate.sgv2.jsonapi.metrics.BatchedLogUploaderMetrics; +import java.net.URI; +import java.nio.charset.StandardCharsets; +import java.time.Duration; +import java.time.ZoneOffset; +import java.time.format.DateTimeFormatter; +import java.util.Objects; +import java.util.concurrent.CompletionException; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import software.amazon.awssdk.awscore.exception.AwsServiceException; +import software.amazon.awssdk.core.async.AsyncRequestBody; +import software.amazon.awssdk.core.retry.RetryMode; +import software.amazon.awssdk.regions.Region; +import software.amazon.awssdk.services.s3.S3AsyncClient; +import software.amazon.awssdk.services.s3.model.PutObjectRequest; + +/** + * Uploads sealed billing batches to S3 as NDJSON objects under time-partitioned keys. + * + *

TODO: checksums ? .requestChecksumCalculation(RequestChecksumCalculation.WHEN_SUPPORTED) + * .responseChecksumValidation(ResponseChecksumValidation.WHEN_SUPPORTED) + */ +public class S3BatchedLogUploader implements AsyncBatchedLogUploader { + + private static final Logger LOGGER = LoggerFactory.getLogger(S3BatchedLogUploader.class); + + // this header not defined in standard libs + @VisibleForTesting public static final String CONTENT_TYPE_NDJSON = "application/x-ndjson"; + private static final DateTimeFormatter OBJECT_KEY_FORMATTER = + DateTimeFormatter.ofPattern("yyyy/MM/dd/HH/mm").withZone(ZoneOffset.UTC); + + private final S3AsyncClient client; + private final String region; + private final String bucket; + private final String pathPrefix; + private final BatchedLogUploaderMetrics metrics; + + /** + * Visible for testing, use the {@link #create(String, String, String, String, Duration, Duration, + * RetryMode, BatchedLogUploaderMetrics)} to get a new instance. + */ + @VisibleForTesting + protected S3BatchedLogUploader( + S3AsyncClient client, + String region, + String bucket, + String pathPrefix, + BatchedLogUploaderMetrics metrics) { + this.client = client; + this.region = region; + this.bucket = bucket; + this.pathPrefix = pathPrefix; + this.metrics = metrics; + } + + /** + * Factory to create a new instance, including creating and configuring the AWS client + * + * @param region S3 region to send events to + * @param bucket S3 bucket to send events to + * @param endpointOverride nullable override for the S3 end point, used for testing. + * @param pathPrefix Prefix to store events under, the path also has the event time and a UUId in + * it. + * @param s3CallAttemptTimeout Timeout for a single call to S3 + * @param s3TotalCallTimeout Timeout for the total time calling s3, including retries + * @param s3RetryMode retry strategy, see S3 docs. + * @param metrics Metrics instance to track with. + * @return + */ + public static S3BatchedLogUploader create( + String region, + String bucket, + String endpointOverride, + String pathPrefix, + Duration s3CallAttemptTimeout, + Duration s3TotalCallTimeout, + RetryMode s3RetryMode, + BatchedLogUploaderMetrics metrics) { + + if (region == null || region.isBlank()) { + throw new IllegalArgumentException("region must not be null or blank"); + } + if (bucket == null || bucket.isBlank()) { + throw new IllegalArgumentException("bucket must not be null or blank"); + } + if (pathPrefix == null || pathPrefix.isBlank()) { + throw new IllegalArgumentException("pathPrefix must not be null or blank"); + } + Objects.requireNonNull(s3TotalCallTimeout, "s3TotalCallTimeout must not be null"); + Objects.requireNonNull(s3CallAttemptTimeout, "s3CallAttemptTimeout must not be null"); + Objects.requireNonNull(s3RetryMode, "s3RetryMode must not be null"); + Objects.requireNonNull(metrics, "metrics must not be null"); + + // Credentials resolve from the SDK's default provider chain (env vars, web-identity/OIDC + // token, instance/container roles), left implicit so the client owns — and closes — the + // provider. This transparently supports federated (AssumeRoleWithWebIdentity) and + // cross-account access: the bucket may live in a different account (per IAM + bucket + // policy); its region is set via .region(). + LOGGER.info( + "create() - region:{}, bucket:{}, pathPrefix:{}, s3TotalCallTimeout:{}, s3CallAttemptTimeout:{}, s3RetryMode:{}", + region, + bucket, + pathPrefix, + s3TotalCallTimeout, + s3CallAttemptTimeout, + s3RetryMode); + + var builder = + S3AsyncClient.builder() + .region(Region.of(region)) + .overrideConfiguration( + config -> + config + .retryStrategy(s3RetryMode) + .apiCallAttemptTimeout(s3CallAttemptTimeout) + .apiCallTimeout(s3TotalCallTimeout)); + + // Real AWS S3 needs no endpoint: the SDK endpoint rules (s3 SDK's DefaultS3EndpointProvider) + // derive https://.s3..amazonaws.com from region + partition dnsSuffix. + // An override is only for a non-AWS S3 (S3Mock in tests): it bypasses those rules and forces + // path-style, since a localhost host can't virtual-host the bucket as a subdomain. + if (endpointOverride != null) { + LOGGER.warn( + "create() - WARNING - using endpointOverride this should only be used in testing. endpointOverride: {}", + endpointOverride); + builder.endpointOverride(URI.create(endpointOverride)).forcePathStyle(Boolean.TRUE); + } + + return new S3BatchedLogUploader(builder.build(), region, bucket, pathPrefix, metrics); + } + + /** + * Starts uploading the supplied batch to S3. + * + *

+ * + * @param batch The batch of log records to upload + * @return Uni for uploading the batch to S3. The returned Uni will be working to complete the + * task (i.e. not deferred), and will be emitted on the {@link + * Infrastructure#getDefaultWorkerPool()} + */ + @Override + public Uni upload(BatchedLogBuffer.Batch batch) { + + Objects.requireNonNull(batch, "batch must not be null"); + + var location = objectLocation(batch); + var body = objectContent(batch); + + LOGGER.info( + "upload() - starting to upload batch, batch:{}, location:{}, body.size:{}", + batch, + location, + body.length); + + // retry and timeout are set when we created the client. + var putRequest = + PutObjectRequest.builder() + .bucket(location.bucket()) + .key(location.key()) + .contentType(CONTENT_TYPE_NDJSON) + .build(); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("upload() - got putRequest. batch:{}, putRequest: {}", batch, putRequest); + } + + // Call to S3 client comes back on its own worker thread + // using emit() so following processing happens on a quarkus worker thread + return Uni.createFrom() + .completionStage(client.putObject(putRequest, AsyncRequestBody.fromBytes(body))) + .emitOn(Infrastructure.getDefaultWorkerPool()) + .onItemOrFailure() + .transform( + (resp, failure) -> { + var success = failure == null; + var cause = (failure instanceof CompletionException) ? failure.getCause() : failure; + // get from error if there is an error, so we dont rely on the response in an error + // state + String requestId = null; + if (cause instanceof AwsServiceException ase) { + requestId = ase.getMessage(); + } else if (resp != null && resp.responseMetadata() != null) { + requestId = resp.responseMetadata().requestId(); + } + + if (!success) { + metrics.recordBatchFailed(batch); + LOGGER.error( + "upload() - error uploading billing to S3. batch:{}, location:{}, requestId:{}", + batch, + location, + requestId, + cause); + } else { + metrics.recordBatchDelivered(batch); + LOGGER.info( + "upload() - success uploading billing to S3. batch:{}, location:{}, requestId:{}, eTag:{}, status:{}", + batch, + location, + requestId, + resp.eTag(), + resp.sdkHttpResponse().statusCode()); + } + return new UploadResult(batch, failure); + }); + } + + @Override + public void close() { + client.close(); + } + + @Override + public String toString() { + return new StringBuilder(classSimpleName(this) + "{") + .append("region=") + .append(region) + .append(", bucket=") + .append(bucket) + .append(", pathPrefix=") + .append(pathPrefix) + .append("}") + .toString(); + } + + @VisibleForTesting + protected S3Location objectLocation(BatchedLogBuffer.Batch batch) { + + var objectKey = + pathPrefix + + "/" + + OBJECT_KEY_FORMATTER.format(batch.oldestEventAt()) + + "/" + + batch.id() + + ".jsonl"; + + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("objectLocation() - batch:{}, objectKey:{}", batch, objectKey); + } + return new S3Location(region, bucket, objectKey); + } + + @VisibleForTesting + byte[] objectContent(BatchedLogBuffer.Batch batch) { + + StringBuilder sb = new StringBuilder(); + for (String line : batch.lines()) { + sb.append(line).append('\n'); + } + var bytes = sb.toString().getBytes(StandardCharsets.UTF_8); + + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("objectContent() - batch:{}, bytes.length:{}", batch, bytes.length); + } + return bytes; + } + + @VisibleForTesting + protected record S3Location(String region, String bucket, String key) {} +} diff --git a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBilling.java b/src/main/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBilling.java deleted file mode 100644 index 9ab810bd4a..0000000000 --- a/src/main/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBilling.java +++ /dev/null @@ -1,148 +0,0 @@ -package io.stargate.sgv2.jsonapi.service.provider; - -import static io.stargate.sgv2.jsonapi.util.StringUtil.requireNonBlank; - -import com.fasterxml.jackson.core.JacksonException; -import com.fasterxml.jackson.databind.ObjectMapper; -import com.fasterxml.jackson.databind.ObjectWriter; -import com.google.common.annotations.VisibleForTesting; -import io.stargate.sgv2.jsonapi.config.BillingConfig; -import io.stargate.sgv2.jsonapi.config.feature.ApiFeature; -import java.time.Instant; -import java.util.ArrayList; -import java.util.List; -import java.util.Objects; -import java.util.Set; -import java.util.UUID; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -/** - * {@link Billing} implementation that emits structured JSON log lines on the {@code billing.events} - * logger for downstream billing pipelines. - * - *

Construction is driven by {@link - * io.stargate.sgv2.jsonapi.api.request.RequestContext#billing()}: the request context decides - * between this implementation and {@link Billing#NO_OP} based on whether {@link - * ApiFeature#BILLING_EVENTS_LOGGING} is enabled for the request. This class therefore assumes - * billing is enabled and unconditionally emits — it does not re-check the feature flag. - * - *

For each {@link ModelUsage}, up to three events are emitted, one per billable metric ({@link - * BillingEventType.Metric#TOTAL_TOKENS TOTAL_TOKENS}, {@link BillingEventType.Metric#EGRESS_BYTES - * EGRESS_BYTES}, {@link BillingEventType.Metric#INGRESS_BYTES INGRESS_BYTES}). The {@code - * internal_*} variant is used when the model provider is listed in {@link - * BillingConfig#internalModelProviders()}; otherwise the {@code external_*} variant is used. Events - * whose type is not in {@link BillingConfig#enabledEventTypes()} are dropped. - * - *

{@link #emitEvent(ModelUsage)} requires a non-null {@link ModelUsage} — callers must guarantee - * usage data exists before invoking. The region for each event is read from {@link - * ModelUsage#tenant()} ({@code Tenant.region()}). - */ -public class DefaultBilling implements Billing { - - private static final Logger BILLING_LOGGER = LoggerFactory.getLogger("billing.events"); - private static final Logger LOGGER = LoggerFactory.getLogger(DefaultBilling.class); - - private static final ObjectWriter OBJECT_WRITER = new ObjectMapper().writer(); - - private final String product; - private final String resourceType; - private final Set internalModelProviders; - private final Set enabledEventTypes; - - public DefaultBilling(BillingConfig config) { - Objects.requireNonNull(config, "config must not be null"); - this.product = requireNonBlank(config.product(), "billing.product"); - this.resourceType = requireNonBlank(config.resourceType(), "billing.resource_type"); - this.internalModelProviders = Set.copyOf(config.internalModelProviders()); - this.enabledEventTypes = - config.enabledEventTypes().map(Set::copyOf).orElse(BillingEventType.ALL); - } - - /** - * Emits billing events for the given aggregated model usage. The {@code billing.events} logger - * level is checked first so we skip event construction when the logger is silenced at runtime. - * - * @param modelUsage usage data for the model call; must not be null. Callers are expected to - * ensure they have usage data before invoking. - */ - @Override - public void emitEvent(ModelUsage modelUsage) { - Objects.requireNonNull(modelUsage, "modelUsage must not be null"); - if (!BILLING_LOGGER.isInfoEnabled()) { - return; - } - for (var event : buildEvents(modelUsage)) { - try { - BILLING_LOGGER.info(OBJECT_WRITER.writeValueAsString(event)); - } catch (JacksonException e) { - LOGGER.error("Failed to serialize billing event of type {}", event.eventType(), e); - } - } - } - - /** - * Builds the list of billing events for one {@link ModelUsage}: one event per billable metric - * (total tokens, egress bytes, ingress bytes), with the {@code internal_*} or {@code external_*} - * variant chosen based on {@link BillingConfig#internalModelProviders()}. Events whose type is - * not in {@link BillingConfig#enabledEventTypes()} are filtered out. All events from a single - * {@code ModelUsage} share one timestamp so they can be correlated in the billing logs. - */ - @VisibleForTesting - List buildEvents(ModelUsage modelUsage) { - var internal = internalModelProviders.contains(modelUsage.modelProvider().apiName()); - var region = modelUsage.tenant().region(); - var resourceId = modelUsage.tenant().toString(); - var providerName = modelUsage.modelProvider().apiName(); - var modelName = modelUsage.modelName(); - var timestamp = Instant.now(); - - var events = new ArrayList(3); - addEventIfEnabled( - events, - BillingEventType.of(BillingEventType.Metric.TOTAL_TOKENS, internal), - modelUsage.totalTokens(), - region, - resourceId, - providerName, - modelName, - timestamp); - addEventIfEnabled( - events, - BillingEventType.of(BillingEventType.Metric.EGRESS_BYTES, internal), - modelUsage.requestBytes(), - region, - resourceId, - providerName, - modelName, - timestamp); - addEventIfEnabled( - events, - BillingEventType.of(BillingEventType.Metric.INGRESS_BYTES, internal), - modelUsage.responseBytes(), - region, - resourceId, - providerName, - modelName, - timestamp); - return events; - } - - private void addEventIfEnabled( - List events, - BillingEventType eventType, - long usage, - String region, - String resourceId, - String providerName, - String modelName, - Instant timestamp) { - if (!enabledEventTypes.contains(eventType)) { - return; - } - var properties = - new BillingEvent.BillingProperties( - usage, region, resourceType, resourceId, providerName, modelName); - events.add(new BillingEvent(UUID.randomUUID(), timestamp, product, eventType, properties)); - } -} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/TestConstants.java b/src/test/java/io/stargate/sgv2/jsonapi/TestConstants.java index e0c42122bc..8dd3949a92 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/TestConstants.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/TestConstants.java @@ -18,11 +18,11 @@ import io.stargate.sgv2.jsonapi.config.constants.DocumentConstants; import io.stargate.sgv2.jsonapi.config.feature.ApiFeatures; import io.stargate.sgv2.jsonapi.metrics.JsonProcessingMetricsReporter; +import io.stargate.sgv2.jsonapi.service.billing.Billing; import io.stargate.sgv2.jsonapi.service.cqldriver.CQLSessionCache; import io.stargate.sgv2.jsonapi.service.cqldriver.executor.*; import io.stargate.sgv2.jsonapi.service.embedding.operation.EmbeddingProvider; import io.stargate.sgv2.jsonapi.service.embedding.operation.EmbeddingProviderFactory; -import io.stargate.sgv2.jsonapi.service.provider.Billing; import io.stargate.sgv2.jsonapi.service.reranking.operation.RerankingProviderFactory; import io.stargate.sgv2.jsonapi.service.schema.*; import io.stargate.sgv2.jsonapi.service.schema.collections.CollectionLexicalDefSchemaFactory; diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/BillingS3UploadIntegrationTest.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/BillingS3UploadIntegrationTest.java new file mode 100644 index 0000000000..469f4c3db9 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/BillingS3UploadIntegrationTest.java @@ -0,0 +1,302 @@ +package io.stargate.sgv2.jsonapi.api.v1; + +import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.*; +import static io.stargate.sgv2.jsonapi.util.MetricsITAssertions.assertMetricTotal; +import static org.assertj.core.api.Assertions.assertThat; +import static org.awaitility.Awaitility.await; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.node.JsonNodeType; +import io.quarkus.test.common.WithTestResource; +import io.quarkus.test.junit.QuarkusIntegrationTest; +import io.stargate.sgv2.jsonapi.TestConstants; +import io.stargate.sgv2.jsonapi.service.billing.BillingEventType; +import io.stargate.sgv2.jsonapi.testresource.DseTestResource; +import io.stargate.sgv2.jsonapi.testresource.S3MockTestResource; +import java.net.URI; +import java.time.Duration; +import java.util.ArrayList; +import java.util.HashSet; +import java.util.List; +import java.util.Set; +import java.util.regex.Pattern; +import org.junit.jupiter.api.*; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import software.amazon.awssdk.auth.credentials.AwsBasicCredentials; +import software.amazon.awssdk.auth.credentials.StaticCredentialsProvider; +import software.amazon.awssdk.regions.Region; +import software.amazon.awssdk.services.s3.S3Client; +import software.amazon.awssdk.services.s3.model.GetObjectRequest; +import software.amazon.awssdk.services.s3.model.S3Object; + +/** + * Integration tests for billing that use a mock S3 backend to confirm events are sent to S3 that + * look OK. And that S3 being down does not fail Data API Commands. + * + *

NOTE: we first made billing for findAndRerank / rerank models, these tests ony use + * $vectorize with insert, not findAndRerank, because we have test infra for a custom vectorizer + * + *

TestMethodOrder is used because the second test turns off the S3 container so we need that to + * be last + */ +@QuarkusIntegrationTest +@WithTestResource(value = DseTestResource.class) +@WithTestResource(value = S3MockTestResource.class) +@TestMethodOrder(MethodOrderer.OrderAnnotation.class) // needed because we turn off mock S3 +public class BillingS3UploadIntegrationTest extends AbstractCollectionIntegrationTestBase { + + private static final Logger LOGGER = + LoggerFactory.getLogger(BillingS3UploadIntegrationTest.class); + private static final ObjectMapper MAPPER = new ObjectMapper(); + + private final TestConstants TEST_CONSTANTS = new TestConstants(); + + private static final int DOCUMENT_COUNT = 10; + private static final Pattern KEY_PATTERN = + Pattern.compile("data-api/\\d{4}/\\d{2}/\\d{2}/\\d{2}/\\d{2}/[0-9a-f-]{36}\\.jsonl"); + private static final Set EVENT_TYPES = + new HashSet<>(BillingEventType.ALL.stream().map(BillingEventType::eventName).toList()); + + @BeforeAll + public void setup() { + assertDatabaseCommand() + .templated() + .createKeyspace(TEST_CONSTANTS.KEYSPACE_NAME) + .wasSuccessful(); + + createCollection(); + } + + @AfterAll + public void tearDown() { + assertDatabaseCommand().templated().dropKeyspace(TEST_CONSTANTS.KEYSPACE_NAME).wasSuccessful(); + } + + /** + * Successfully send events to the (mock) S3. + * + * @throws Exception + */ + @Test + public void billingEventsSentToS3() throws Exception { + + try (var s3Client = s3ClientForVerification()) { + + insertDocs("billingEventsSentToS3()"); + + // need to wait for billing to send events to S3. + // there should be at least 1 billing event per document we sent + await() + .atMost(Duration.ofSeconds(60)) + .pollInterval(Duration.ofSeconds(2)) + .untilAsserted( + () -> + assertThat(allLinesInAllObjectsInBucket(s3Client)) + .hasSizeGreaterThanOrEqualTo(DOCUMENT_COUNT)); + + var allS3Objects = allObjectsInBucket(s3Client); + + // Do all the keys match the expected pattern ? + assertThat(allS3Objects).isNotEmpty(); + for (var s3Object : allS3Objects) { + assertThat(s3Object.key()) + .as("billingEventsSentToS3() - object key matches expected pattern") + .matches(KEY_PATTERN); + } + + // get the metadata for the first Object we got back + // here "HEAD" means get the headers, leave the body. + // Kind of like "Leave the gun take the cannoli" but less shooty + var head = + s3Client.headObject( + b -> b.bucket(S3MockTestResource.BUCKET).key(allS3Objects.getFirst().key())); + assertThat(head.contentType()) + .as("billingEventsSentToS3() - ContentType of first object matches expected") + .isEqualTo("application/x-ndjson"); + + // Validate the billing events we have are valid JSON and do some simple property checks + // not checking the values make sense, just the ones we expect to be set and a few things. + // this is not checking that the event is "well-formed" + var allBillingLines = allLinesInAllObjectsInBucket(s3Client); + Set seenIds = new HashSet<>(); + + // JSON Pointers + var requiredTextMembers = + List.of( + "/id", + "/timestamp", + "/product", + "/event_type", + "/properties/resource_type", + "/properties/provider", + "/properties/model"); + var requiredNumericMembers = List.of("/properties/usage"); + + for (String line : allBillingLines) { + var event = MAPPER.readTree(line); + + assertIsSet(JsonNodeType.STRING, event, requiredTextMembers); + assertIsSet(JsonNodeType.NUMBER, event, requiredNumericMembers); + + assertThat(seenIds.add(event.path("id").asText())) + .as("billing event id duplicated across export: " + event.path("id").asText()) + .isTrue(); + assertThat(event.path("product").asText()) + .as("event product is expected") + .isEqualTo("serverless"); + assertThat(event.path("event_type").asText()) + .as("event type is from expected set: " + EVENT_TYPES) + .isIn(EVENT_TYPES); + + assertThat(event.at("/properties/usage").asLong()) + .as("event properties.usage is > 0") + .isGreaterThanOrEqualTo(0L); + assertThat(event.at("/properties/resource_type").asText()) + .as("event properties.resource_type is expected") + .isEqualTo("serverless_database"); + assertThat(event.at("/properties/provider").asText()) + .as("event properties.provider is expected from collection creation") + .isEqualTo("custom"); + + // The billed model is what the provider reports in ModelUsage — for the IT provider that + // is its internal model config ("test-model"), not the createCollection modelName. + assertThat(event.at("/properties/model").asText()).isEqualTo("test-model"); + } + } // end of S3 resource + + // Check the metrics reflect that we sent the expected number of events + assertMetricTotal( + "billing.s3.uploaded.events", (a) -> a.isGreaterThanOrEqualTo(DOCUMENT_COUNT)); + assertMetricTotal("billing.buffer.offered", (a) -> a.isGreaterThanOrEqualTo(DOCUMENT_COUNT)); + assertMetricTotal("billing.buffer.dropped", (a) -> a.isZero()); + } + + /** + * Confirm the API still works when the S3 backend is offline. + * + *

NOTE: must run last so because the S3 resource is shared and this tests turns if off + * ! + */ + @Test + @Order(Integer.MAX_VALUE) + public void exportFailureDoesNotAffectTheApi() { + S3MockTestResource.stopContainer(); + + // assert happens in the function, this is the test, could we insert docs ? + insertDocs("exportFailureDoesNotAffectTheApi() - 1st"); + + // wait until we register a failed upload + assertMetricTotal("billing.s3.failed.batches", (a) -> a.isGreaterThan(0)); + assertMetricTotal("billing.s3.failed.events", (a) -> a.isGreaterThan(0)); + + // double check API still works + insertDocs("exportFailureDoesNotAffectTheApi() - 2nd"); + } + + // ============================================================ + // Scaffold + // ============================================================ + + private void createCollection() { + var collectionOptions = + """ + { + "vector": { + "metric": "cosine", + "dimension": 5, + "service": { + "provider": "custom", + "modelName": "text-embedding-ada-002", + "authentication": { + "providerKey" : "shared_creds.providerKey" + }, + "parameters": { + "projectId": "test project" + } + } + } + } + """; + + assertNamespaceCommand(TEST_CONSTANTS.KEYSPACE_NAME) + .templated() + .createCollection(TEST_CONSTANTS.COLLECTION_NAME, collectionOptions) + .wasSuccessful(); + } + + private void insertDocs(String idPrefix) { + for (int i = 0; i < DOCUMENT_COUNT; i++) { + var id = "doc-%s-%d".formatted(idPrefix, i); + var doc = + """ + { + "_id": "doc-%s", + "description": "billing export test document %s", + "$vectorize": "billing export test document %s" + }""" + .formatted(id, id, id); + assertTableCommand(TEST_CONSTANTS.KEYSPACE_NAME, TEST_CONSTANTS.COLLECTION_NAME) + .templated() + .insertOne(doc) + .wasSuccessful(); + } + } + + private void assertIsSet(JsonNodeType nodeType, JsonNode parent, List memberPointers) { + + for (var pointer : memberPointers) { + var child = parent.at(pointer); + assertThat(child.isMissingNode()).as("child member expected pointer:" + pointer).isFalse(); + assertThat(child.getNodeType()).as("node type is expected:" + nodeType).isEqualTo(nodeType); + + switch (nodeType) { + case STRING -> assertThat(child.asText()).isNotBlank(); + case NUMBER -> assertThat(child.isNumber()).isTrue(); + default -> { + throw new IllegalStateException("assertIsSet() - Unexpected node type: " + nodeType); + } + } + ; + } + } + + private static S3Client s3ClientForVerification() { + + return S3Client.builder() + .region(Region.of(S3MockTestResource.REGION)) + .credentialsProvider( + StaticCredentialsProvider.create( + AwsBasicCredentials.create( + S3MockTestResource.ACCESS_KEY, S3MockTestResource.SECRET_KEY))) + .endpointOverride(URI.create(S3MockTestResource.endpoint())) + .forcePathStyle(true) + .build(); + } + + private static List allObjectsInBucket(S3Client s3Client) { + var objects = + s3Client + .listObjectsV2(b -> b.bucket(S3MockTestResource.BUCKET).prefix("data-api/")) + .contents(); + LOGGER.info("allObjectInBucket() - objects: {}", objects); + return objects; + } + + private static List allLinesInAllObjectsInBucket(S3Client s3Client) { + + List lines = new ArrayList<>(); + for (var s3Object : allObjectsInBucket(s3Client)) { + + var request = + GetObjectRequest.builder().bucket(S3MockTestResource.BUCKET).key(s3Object.key()).build(); + LOGGER.info("allLinesInAllObjectsInBucket() - getting file. request: {}", request); + + var objectBody = s3Client.getObjectAsBytes(request).asUtf8String(); + objectBody.lines().filter(line -> !line.isBlank()).forEach(lines::add); + } + LOGGER.info("allLinesInAllObjectsInBucket() - got all lines from S3. lines:{}", lines); + return lines; + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/RerankFeatureDisabledIntegrationTest.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/RerankFeatureDisabledIntegrationTest.java index bf2e6571cd..aba271b8f0 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/RerankFeatureDisabledIntegrationTest.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/RerankFeatureDisabledIntegrationTest.java @@ -1,6 +1,6 @@ package io.stargate.sgv2.jsonapi.api.v1; -import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertGeneralCommand; +import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertDatabaseCommand; import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertNamespaceCommand; import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertTableCommand; @@ -46,7 +46,7 @@ public String getFeatureFlagReranking() { @Order(1) @Test public void failFindRerankingProviders() { - assertGeneralCommand() + assertDatabaseCommand() .postFindRerankingProviders() .hasSingleApiError( SchemaException.Code.RERANKING_FEATURE_NOT_ENABLED, SchemaException.class); @@ -56,7 +56,7 @@ public void failFindRerankingProviders() { @Order(2) @Test public void okFindRerankingProviders() { - assertGeneralCommand() + assertDatabaseCommand() .header(ApiFeature.RERANKING.httpHeaderName(), "true") .postFindRerankingProviders() .wasSuccessful(); diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/mcp/McpFeatureDisabledIntegrationTest.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/mcp/McpFeatureDisabledIntegrationTest.java index 8ec8e4294b..c2e2212f75 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/mcp/McpFeatureDisabledIntegrationTest.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/mcp/McpFeatureDisabledIntegrationTest.java @@ -1,6 +1,6 @@ package io.stargate.sgv2.jsonapi.api.v1.mcp; -import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertGeneralCommand; +import static io.stargate.sgv2.jsonapi.api.v1.util.DataApiCommandSenders.assertDatabaseCommand; import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.*; @@ -41,7 +41,7 @@ public String getFeatureFlagMcp() { @Test public void restCommandsStillWorkWhenMcpDisabled() { // REST API commands should still function even when MCP feature flag is disabled - assertGeneralCommand().postFindEmbeddingProviders().wasSuccessful(); + assertDatabaseCommand().postFindEmbeddingProviders().wasSuccessful(); } @Test diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiCommandSenders.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiCommandSenders.java index b9cdff0495..68bd4d0714 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiCommandSenders.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiCommandSenders.java @@ -3,8 +3,8 @@ /** Helper class used for constructing and sending commands to the Data API */ public class DataApiCommandSenders { - public static DataApiGeneralCommandSender assertGeneralCommand() { - return new DataApiGeneralCommandSender(); + public static DataApiDatabaseCommandSender assertDatabaseCommand() { + return new DataApiDatabaseCommandSender(); } public static DataApiKeyspaceCommandSender assertNamespaceCommand(String keyspace) { diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiGeneralCommandSender.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiDatabaseCommandSender.java similarity index 51% rename from src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiGeneralCommandSender.java rename to src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiDatabaseCommandSender.java index bc4a39b56b..d658d01f5c 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiGeneralCommandSender.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiDatabaseCommandSender.java @@ -4,8 +4,18 @@ import io.stargate.sgv2.jsonapi.api.model.command.CommandName; import io.stargate.sgv2.jsonapi.api.v1.GeneralResource; -public class DataApiGeneralCommandSender - extends DataApiCommandSenderBase { +public class DataApiDatabaseCommandSender + extends DataApiCommandSenderBase { + + private final DatabaseTemplates templates; + + public DataApiDatabaseCommandSender() { + this.templates = new DatabaseTemplates(this); + } + + public DatabaseTemplates templated() { + return this.templates; + } public DataApiResponseValidator postFindEmbeddingProviders() { return postCommand(CommandName.FIND_EMBEDDING_PROVIDERS, "{}"); @@ -15,6 +25,14 @@ public DataApiResponseValidator postFindRerankingProviders() { return postCommand(CommandName.FIND_RERANKING_PROVIDERS, "{}"); } + public DataApiResponseValidator postCreateKeyspace(String jsonClause) { + return postCommand(CommandName.CREATE_KEYSPACE, jsonClause); + } + + public DataApiResponseValidator postDropKeyspace(String jsonClause) { + return postCommand(CommandName.DROP_KEYSPACE, jsonClause); + } + protected io.restassured.response.Response postInternal(RequestSpecification request) { return request.post(GeneralResource.BASE_PATH); } diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiResponseValidator.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiResponseValidator.java index f471786523..a061bca243 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiResponseValidator.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DataApiResponseValidator.java @@ -69,6 +69,8 @@ public DataApiResponseValidator(CommandName commandName, ValidatableResponse res case COUNT_DOCUMENTS -> responseIsCountSuccess(); case FIND_EMBEDDING_PROVIDERS, FIND_RERANKING_PROVIDERS -> responseIsFindProvidersSuccess(); + case CREATE_KEYSPACE, CREATE_NAMESPACE, DROP_KEYSPACE, DROP_NAMESPACE -> + responseIsDDLSuccess(); default -> throw new IllegalArgumentException( "DataApiResponseValidator: Unexpected command name: " + commandName); @@ -146,6 +148,9 @@ public DataApiResponseValidator wasSuccessful() { case FIND_EMBEDDING_PROVIDERS, FIND_RERANKING_PROVIDERS -> { return hasNoErrors(); } + case CREATE_KEYSPACE, CREATE_NAMESPACE, DROP_KEYSPACE, DROP_NAMESPACE -> { + return hasNoErrors().hasStatusOK(); + } default -> throw new IllegalArgumentException( "DataApiResponseValidator: Unexpected command name: " + commandName); diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DatabaseTemplates.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DatabaseTemplates.java new file mode 100644 index 0000000000..c3ccf17c94 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/DatabaseTemplates.java @@ -0,0 +1,37 @@ +package io.stargate.sgv2.jsonapi.api.v1.util; + +/** Templates command that run against a Database */ +public class DatabaseTemplates extends TemplateRunner { + + private DataApiDatabaseCommandSender sender; + + public DatabaseTemplates(DataApiDatabaseCommandSender sender) { + this.sender = sender; + } + + // =================================================================================================================== + // DDL - TABLES + // =================================================================================================================== + + public DataApiResponseValidator createKeyspace(String keyspaceName) { + var json = + """ + { + "name": "%s" + } + """ + .formatted(keyspaceName); + return sender.postCreateKeyspace(json); + } + + public DataApiResponseValidator dropKeyspace(String keyspaceName) { + var json = + """ + { + "name": "%s" + } + """ + .formatted(keyspaceName); + return sender.postDropKeyspace(json); + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/KeyspaceTemplates.java b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/KeyspaceTemplates.java index 34ae68dd49..c5da659134 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/KeyspaceTemplates.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/api/v1/util/KeyspaceTemplates.java @@ -242,13 +242,18 @@ public DataApiResponseValidator listTables(boolean explain) { // =================================================================================================================== public DataApiResponseValidator createCollection(String collectionName) { + return createCollection(collectionName, "{}"); + } + + public DataApiResponseValidator createCollection(String collectionName, String options) { var json = """ { - "name": "%s" + "name": "%s", + "options": %s } """ - .formatted(collectionName); + .formatted(collectionName, options); return sender.postCreateCollection(json); } } diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBufferTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBufferTest.java new file mode 100644 index 0000000000..a2766b1405 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BatchedLogBufferTest.java @@ -0,0 +1,591 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.ClassUtils.classSimpleName; +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; +import static org.awaitility.Awaitility.await; +import static org.mockito.Mockito.*; + +import io.stargate.sgv2.jsonapi.metrics.BatchedLogBufferMetrics; +import java.lang.ref.WeakReference; +import java.time.Duration; +import java.util.*; +import java.util.concurrent.*; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.stream.Stream; +import org.junit.jupiter.api.Test; + +/** + * Unit tests for {@link BatchedLogBuffer}\ + * + *

TODO: out of order log records gets correct oldest metric TODO: TEST a big line bigger than + * the max bytes gets through + */ +public class BatchedLogBufferTest extends BillingTestBase { + + // ********************************************************* + // Offer - Producer side of the buffer + // ********************************************************* + + /** When the buffer reaches capacity calling offer() fails. Single producer thread. */ + @Test + public void offerFailsAtCapacitySingleThread() { + + var fixture = defaultBufferFixture(false); + var slice = Slice.to(BUFFER_CAPACITY); + + // send full capacity to the buffer, should all work + fixture.assertOffer("offerFailsAtCapacitySingleThread() - prefill to capacity", slice); + + // Buffer should now be full, try to add one more + fixture.assertBufferFull("offerFailsAtCapacitySingleThread()", BUFFER_CAPACITY + 1); + } + + /** When the buffer reaches capacity calling offer() fails. Multiple producer threads. */ + @Test + public void offerFailsAtCapacityMultiThread() { + + var fixture = defaultBufferFixture(false); + var snapshot = BufferSnapshot.create(fixture); + var slice = Slice.to(BUFFER_CAPACITY); + + // fill the buffer to capacity from 6 threads calling offer() + // auto close will wait for tasks to finish in executor + try (var pool = Executors.newFixedThreadPool(6)) { + for (var record : slice.stream(fixture.logRecords()).toList()) { + pool.submit(() -> fixture.buffer().offer(record)); + } + } + + // check the change in the buffer is expected given the slice of source data + snapshot.assertAll("offerFailsAtCapacityMultiThread()", slice, false); + // Buffer should now be full, try to add one more + fixture.assertBufferFull("offerFailsAtCapacityMultiThread()", BUFFER_CAPACITY + 1); + } + + /** + * Verify that when offered a LogRecord the buffer does not hold reference to the LogRecord and it + * can be GC'd + */ + @Test + public void offerDoesNotHoldReferences() { + + var fixture = defaultBufferFixture(false); + + // do not use the records in the fixture, they are held in a list + var record = new LogRecord(Level.INFO, "offerDoesNotHoldReferences()"); + var ref = new WeakReference<>(record); + + fixture.buffer().offer(record); + record = null; + + // reference count for the object created for "record" above should now be zero + // will timeout if the object is not GC'd and error + await("offerDoesNotHoldReferences() - waiting for record to be GC'd") + .atMost(Duration.ofSeconds(5)) + .until( + () -> { + System.gc(); + return ref.get() == null; + }); + } + + @Test + public void offerNullRecord() { + var fixture = defaultBufferFixture(false); + + assertThatThrownBy(() -> fixture.buffer().offer(null)) + .as("offerNullRecord() null log record is an exception") + .isInstanceOf(NullPointerException.class); + } + + @Test + public void offerNullOrBlankMessage() { + var fixture = defaultBufferFixture(false); + + var nullRecord = new LogRecord(Level.INFO, null); + var blankRecord = new LogRecord(Level.INFO, " "); + + assertThatThrownBy(() -> fixture.buffer().offer(nullRecord)) + .as("offerNullOrBlankMessage() - null message is an error") + .isInstanceOf(IllegalArgumentException.class); + assertThatThrownBy(() -> fixture.buffer().offer(blankRecord)) + .as("offerNullOrBlankMessage() - blank message is an error") + .isInstanceOf(IllegalArgumentException.class); + } + + // ********************************************************* + // nextBatch - Consumer side of the buffer + // ********************************************************* + + /** When buffer is empty, there is no batch available. */ + @Test + public void nextBatchEmptyBufferNoBatch() { + + // lock the clock, do not want it to auto advance for batch testing + var fixture = defaultBufferFixture(true); + + assertThat(fixture.buffer().nextBatch(false)) + .as("nextBatchEmptyBufferNoBatch() - drainFully=false, no batch") + .isNull(); + + assertThat(fixture.buffer().nextBatch(true)) + .as("nextBatchEmptyBufferNoBatch() - drainFully=true, no batch") + .isNull(); + } + + /** Properties of the returned batch object are as expected. */ + @Test + public void nextBatchBatchProperties() { + + // lock the clock, do not want it to auto advance for batch testing + var fixture = defaultBufferFixture(true); + var slice = Slice.to(BUFFER_CAPACITY); + + // fill the buffer with all the records it will fit + fixture.assertOffer("nextBatchBatchProperties()", slice); + + // keep taking batches and check their properties + BatchedLogBuffer.Batch batch; + Set batchIds = new HashSet<>(); + while ((batch = fixture.buffer().nextBatch(true)) != null) { + + assertThat(batch.id()) + .as("nextBatchBatchProperties() - batch ID has not been seen") + .satisfies(batchIds::add); + + assertThat(batch.toString()) + .as("nextBatchBatchProperties() - batch toString has values") + .contains("id=" + batch.id()) + .contains("reason=" + batch.reason()) + .contains("size=" + batch.size()) + .contains("bytes=" + batch.bytes()); + } + + assertThat(fixture.buffer().isEmpty()) + .as("nextBatchBatchProperties() - drained buffer is empty") + .isTrue(); + } + + /** Metadata (size etc) for the buffer is updated after a batch is returned. */ + @Test + public void nextBatchMetaUpdatedAfterBatch() { + + // lock the clock, do not want it to auto advance for batch testing + var fixture = defaultBufferFixture(true); + var slice = Slice.to(MAX_BATCH_SIZE); + + // fill the buffer with 1 batch size and assert metadata + fixture.assertOffer("nextBatchMetaUpdatedAfterBatch()", slice); + + // take 1 batch + // we are only checking that the bookkeeping on the buffer changes, not checking + // rules for batch selections, this is done by assertNextBatch() + var batch1 = fixture.assertNextBatch("nextBatchMetaUpdatedAfterBatch() - 1st", false); + + // take a second batch and check again bookkeeping updated + var batch2 = fixture.assertNextBatch("nextBatchMetaUpdatedAfterBatch() - 2nd", false); + } + + /** Trigger a batch from the number of records added to buffer */ + @Test + public void nextBatchTriggerMaxSize() { + + // change so the template is small so does not trigger max bytes + // lock the clock, do not want it to auto advance for batch testing + var fixture = + Fixture.createFixture( + MAX_BATCH_SIZE, + MAX_BATCH_BYTES * 100, // big number so never batch because of bytes + MAX_AGE, + BUFFER_CAPACITY, + NUM_RECORDS, + LOG_LEVEL, + "test-", + true, + false, + false, + false); + + // Fill to 1 less than max batch size, should be no batch + var slice1 = Slice.to(MAX_BATCH_SIZE - 1); + fixture.assertOffer("nextBatchMetaUpdatedAfterBatch()", slice1); + var batch1 = fixture.buffer().nextBatch(false); + assertThat(batch1).as("nextBatchTriggerMaxSize() - < MAX_BATCH_SIZE, no batch").isNull(); + + // add one more record, should be a batch of MAX_BATCH_SIZE + var slice2 = Slice.slice(MAX_BATCH_SIZE - 1, MAX_BATCH_SIZE); + fixture.assertOffer("nextBatchMetaUpdatedAfterBatch()", slice2); + var batch2 = fixture.assertNextBatch("nextBatchMetaUpdatedAfterBatch() - 2nd", false); + + assertThat(batch2.size()) + .as("nextBatchTriggerMaxSize() - 2nd batch is full batch size") + .isEqualTo(MAX_BATCH_SIZE); + + assertThat(batch2.reason()) + .as( + "nextBatchTriggerMaxSize() - 2nd batch because " + + BatchedLogBuffer.BillingBatchReason.MAX_SIZE_EXCEEDED) + .isEqualTo(BatchedLogBuffer.BillingBatchReason.MAX_SIZE_EXCEEDED); + + // add one more record, should be no more batches + var slice3 = Slice.slice(MAX_BATCH_SIZE, MAX_BATCH_SIZE + 1); + fixture.assertOffer("nextBatchMetaUpdatedAfterBatch() - 3rd", slice3); + var batch3 = fixture.buffer().nextBatch(false); + assertThat(batch3).as("nextBatchTriggerMaxSize() - 3rd - no batch").isNull(); + } + + /** Trigger a batch from the byte size in the buffer */ + @Test + public void nextBatchTriggerMaxBytes() { + + // default fixture will only fit + // the MAX_BATCH_BYTES_NUM_MESSAGES which is less than MAX_SIZE + // lock the clock, do not want it to auto advance for batch testing + var fixture = defaultBufferFixture(true); + + // Fill to 1 message less than max bytes size, should be no batch + var slice1 = Slice.to(MAX_BATCH_BYTES_NUM_MESSAGES - 1); + fixture.assertOffer("nextBatchTriggerMaxBytes()", slice1); + var batch1 = fixture.buffer().nextBatch(false); + assertThat(batch1).as("nextBatchTriggerMaxSize() - < MAX_BATCH_BYTES, no batch").isNull(); + + // add one more , should be a batch of full batch bytes + var slice2 = Slice.slice(MAX_BATCH_BYTES_NUM_MESSAGES - 1, MAX_BATCH_BYTES_NUM_MESSAGES); + fixture.assertOffer("nextBatchTriggerMaxBytes()", slice2); + var batch2 = fixture.assertNextBatch("nextBatchTriggerMaxBytes() - 2nd", false); + + // we know how many we put in there + assertThat(batch2.bytes()) + .as("nextBatchTriggerMaxBytes() - 2nd batch byte size match") + .isEqualTo(MAX_BATCH_BYTES_NUM_MESSAGES * MESSAGE_LENGTH_IN_BUFFER); + + assertThat(batch2.reason()) + .as( + "nextBatchTriggerMaxBytes() - 2nd batch because " + + BatchedLogBuffer.BillingBatchReason.MAX_BYTES_EXCEEDED) + .isEqualTo(BatchedLogBuffer.BillingBatchReason.MAX_BYTES_EXCEEDED); + + // add one more, should be no more batches + var slice3 = Slice.slice(MAX_BATCH_BYTES_NUM_MESSAGES, MAX_BATCH_BYTES_NUM_MESSAGES + 1); + fixture.assertOffer("nextBatchTriggerMaxBytes() - 3rd", slice3); + var batch3 = fixture.buffer().nextBatch(false); + assertThat(batch3).as("nextBatchTriggerMaxBytes() - 3rd - no batch").isNull(); + } + + /** Trigger a batch from the maximum age of the first element in the buffer */ + @Test + public void nextBatchTriggerMaxAge() { + + // lock the clock, do not want it to auto advance for batch testing + // NOTE: WE ARE USING THE MOCK CLOCK IN THIS TEST, WE CONTROL TIME + var fixture = defaultBufferFixture(true); + + // Add only 3 messages, we will not trip size or bytes tigger + final int ADDED_RECORDS = 3; + var slice1 = Slice.to(ADDED_RECORDS); + fixture.assertOffer("nextBatchTriggerMaxAge()", slice1); + + // the clock has not moved, there should be no batch + var batch1 = fixture.buffer().nextBatch(false); + assertThat(batch1).as("nextBatchTriggerMaxAge() - clock as not moved, no batch").isNull(); + + // Every LogRecord created in fixture has an instanceAt of 1 second after the previous + // the first LogRecord has the same instanceAt as when the clock started. + // so if we advance the clock to be MAX_AGE after when it started the only LogRecord that will + // be too old is the first, the others are all 1+ seconds younger + var newNow = fixture.clock().startedAt().plus(MAX_AGE); + fixture.clock().setInstant(newNow); + + // The buffer should now think the time is "newNow" + // Sanity check, before getting the batch check that only the first log record is MAX_AGE + // checking all this junk did what I think + int i = 0; + var peekedBuffer = fixture.buffer().peekBuffer(); + for (var peekEntry : peekedBuffer) { + var entryAge = fixture.buffer().entryAge(peekEntry); + if (i == 0) { + assertThat(entryAge) + .as("nextBatchTriggerMaxAge() - clock moved, first entry should be MAX_AGE old") + .isEqualTo(MAX_AGE); + } else { + assertThat(entryAge) + .as( + "nextBatchTriggerMaxAge() - clock moved, non first entry should be < MAX_AGE old. i: " + + i) + .isLessThan(MAX_AGE); + } + i++; + } + + // with the clock advanced the buffer should now trigger a batch because + // MAX_AGE_EXCEEDED + var batch2 = fixture.assertNextBatch("nextBatchTriggerMaxAge() - 2nd", false); + + assertThat(batch2.reason()) + .as( + "nextBatchTriggerMaxAge() - 2nd batch because " + + BatchedLogBuffer.BillingBatchReason.MAX_AGE_EXCEEDED) + .isEqualTo(BatchedLogBuffer.BillingBatchReason.MAX_AGE_EXCEEDED); + + // should have drained all the messages, even if they were not too old + assertThat(fixture.buffer().size()) + .as("nextBatchTriggerMaxAge() - 2nd batch buffer, size") + .isEqualTo(0); + assertThat(fixture.buffer().isEmpty()) + .as("nextBatchTriggerMaxAge() - 2nd batch buffer, isEmpty") + .isTrue(); + assertThat(fixture.buffer().queuedBytes()) + .as("nextBatchTriggerMaxAge() - 2nd batch buffer, bytes") + .isEqualTo(0); + + // sanity check, we should have ADDED_RECORDS entries in the batch + // and the oldest should be the first one we created + assertThat(batch2.size()) + .as("nextBatchTriggerMaxAge() - 2nd batch buffer, size expected") + .isEqualTo(ADDED_RECORDS); + assertThat(batch2.oldestEventAt()) + .as("nextBatchTriggerMaxAge() - 2nd batch buffer, oldest event expected") + .isEqualTo(fixture.logRecords().getFirst().getInstant()); + + // add one more record, should be no more batches + var slice3 = Slice.slice(ADDED_RECORDS, ADDED_RECORDS + 1); + fixture.assertOffer("nextBatchTriggerMaxAge() - 3rd", slice3); + var batch3 = fixture.buffer().nextBatch(false); + assertThat(batch3).as("nextBatchTriggerMaxAge() - 3rd - no batch").isNull(); + } + + /** + * Trigger a batch because drainFully=true so we want everything from it regardless of size, + * bytes, age + */ + @Test + public void nextBatchTriggerDrain() { + + // lock the clock, do not want it to auto advance for batch testing + var fixture = defaultBufferFixture(true); + + // Fill so we have 1 full batch and 1 partial batch + var PARTIAL_BATCH_SIZE = 10; + var slice1 = Slice.to(MAX_BATCH_BYTES_NUM_MESSAGES + PARTIAL_BATCH_SIZE); + fixture.assertOffer("nextBatchTriggerDrain()", slice1); + + // 1st - drainFully - should get a full batch + var batch1 = fixture.assertNextBatch("nextBatchTriggerDrain() - 1st - full batch", true); + assertThat(batch1.reason()) + .as( + "nextBatchTriggerDrain() - 1st - reason is " + + BatchedLogBuffer.BillingBatchReason.DRAINING) + .isEqualTo(BatchedLogBuffer.BillingBatchReason.DRAINING); + assertThat(batch1.size()) + .as("nextBatchTriggerDrain() - 1st - full batch, size") + .isEqualTo(MAX_BATCH_BYTES_NUM_MESSAGES); + + // 2nd - drainFully - should get a partial batch + var batch2 = fixture.assertNextBatch("nextBatchTriggerDrain() - 2nd - partial batch", true); + assertThat(batch2.reason()) + .as( + "nextBatchTriggerDrain() - 2nd - reason is " + + BatchedLogBuffer.BillingBatchReason.DRAINING) + .isEqualTo(BatchedLogBuffer.BillingBatchReason.DRAINING); + assertThat(batch2.size()) + .as("nextBatchTriggerDrain() - 2nd - partial batch, size") + .isEqualTo(PARTIAL_BATCH_SIZE); + + // 3rs - drainFully - no more batch + var batch3 = fixture.buffer().nextBatch(true); + assertThat(batch3).as("nextBatchTriggerMaxBytes() - 3rd - no batch").isNull(); + } + + /** + * Multiple producers sending to the buffer, and one consumer reading from it concurrently. + * + *

NOTE: ttest takes 7 or 8 seconds, if you change the sleep time it may mean there are + * no batches collected after shutdown because producers go fast + */ + @Test + public void multiThreadedProducerConsumer() { + + var fixture = defaultBufferFixture(false); + + // Setup a Consumer thread, it will keep running until we set consumerShutdown + var normalBatches = new ArrayList(); + var shutdownBatches = new ArrayList(); + var consumerShutdown = new AtomicBoolean(false); + var consumerExecutor = + Executors.newSingleThreadExecutor(Thread.ofPlatform().name("consumer-", 0).factory()); + + var consumerFuture = + consumerExecutor.submit( + () -> { + // this is the consumer in normal operations, read batches, if none sleep, read again + while (!consumerShutdown.get()) { + BatchedLogBuffer.Batch consumerNormalBatch; + // drainFully=false - because not trying to shutdown + while ((consumerNormalBatch = fixture.buffer().nextBatch(false)) != null) { + normalBatches.add(consumerNormalBatch); + // fake that we do some work with the batch, e.g. upload it + threadSleep(50); + } + // fake the sleep between waking up to check for a batch + threadSleep(50); + } + + // now into the shutdown mode, so drainFully=true to empty the buffer + BatchedLogBuffer.Batch consumerShutdownBatch; + while ((consumerShutdownBatch = fixture.buffer().nextBatch(true)) != null) { + shutdownBatches.add(consumerShutdownBatch); + // fake that we do some work with the batch, e.g. upload it + threadSleep(50); + } + }); + // the consumer is running async looping waiting for batches from the buffer + + // Now setup producers to send data for it, we are going to send all the records we + // created, this will be more than the buffer capacity. + var NUM_PRODUCER_THREADS = 4; + var slice = Slice.to(NUM_RECORDS); + var threadFactory = Thread.ofPlatform().name("producer-", 0).factory(); + var producedCount = new AtomicLong(); + // we want to pause all producers half way through producing so we can + // shutdown the consumer and then produce the remaining records + var producerHalfwayLatch = new CountDownLatch(NUM_PRODUCER_THREADS); + + try (var pool = Executors.newFixedThreadPool(NUM_PRODUCER_THREADS, threadFactory)) { + for (var record : slice.stream(fixture.logRecords()).toList()) { + + // Append the thread name to the log record for debugging + // this will break the config at top of class about how many messages per batch + pool.submit( + () -> { + record.setMessage( + record.getMessage() + " - THREAD " + Thread.currentThread().getName()); + fixture.buffer().offer(record); + + if ((producedCount.incrementAndGet() >= (slice.size() / 2)) + && (!consumerShutdown.get())) { + // this thread got at least half way, mark that and wait for all others + // to get this far + producerHalfwayLatch.countDown(); + waitOnLatch(producerHalfwayLatch); + + // Signal the consumer to shut down, next time it wakes it will start using + // drainFully + consumerShutdown.set(true); + } else { + // Fake that we are doing other things, do not do if we paused cause we want to + // get back to producing ASAP + threadSleep(25); + } + }); + } + } // try, will block waiting for threads to finish when closing Executor + + // wait for consumer to finish + try { + consumerFuture.get(5, TimeUnit.SECONDS); + } catch (InterruptedException | ExecutionException | TimeoutException e) { + throw new RuntimeException(e); + } finally { + // close consumer thread pool + consumerExecutor.close(); + } + + // Now we can check consumer got all the data + // all the batches from normal processing should be either max size or bytes + for (var batch : normalBatches) { + + assertThat(batch.reason()) + .as("multiThreadedProducerConsumer() - normal batch reason is size or bytes") + .isIn( + List.of( + BatchedLogBuffer.BillingBatchReason.MAX_SIZE_EXCEEDED, + BatchedLogBuffer.BillingBatchReason.MAX_BYTES_EXCEEDED)); + // sanity check that the messages in the batch came from a producer thread. + for (var line : batch.lines()) { + assertThat(line) + .as("multiThreadedProducerConsumer() - normal batch line created by producer thread.") + .contains("THREAD producer-"); + } + } + + // all the batches from shutdown processing must be due to draining + for (var batch : shutdownBatches) { + + assertThat(batch.reason()) + .as("multiThreadedProducerConsumer() - normal batch reason is draining") + .isEqualTo(BatchedLogBuffer.BillingBatchReason.DRAINING); + // sanity check that the messages in the batch came from a producer thread. + for (var line : batch.lines()) { + assertThat(line) + .as("multiThreadedProducerConsumer() - shutdown batch line created by producer thread.") + .contains("THREAD producer-"); + } + } + + // total lines from normal and shutdown must be total from producers + var totalBatchLines = + Stream.concat(shutdownBatches.stream(), normalBatches.stream()) + .mapToInt(BatchedLogBuffer.Batch::size) + .sum(); + assertThat(totalBatchLines) + .as( + "multiThreadedProducerConsumer() - lines from batches same number as produced: " + + producedCount.get()) + .isEqualTo(producedCount.get()); + + // sanity check - did every producer thread produce at least one log record ? + // log message will look like: "Total of 25 chars 059 - THREAD producer-1" + for (int i = 0; i < NUM_PRODUCER_THREADS; i++) { + var threadSuffix = "- THREAD producer-" + i; + var found = + Stream.concat(shutdownBatches.stream(), normalBatches.stream()) + .flatMap(batch -> batch.lines().stream()) + .anyMatch(line -> line.endsWith(threadSuffix)); + assertThat(found).as("Producer thread created record, thread:" + threadSuffix).isTrue(); + } + } + + // ********************************************************* + // Basic object testing + // ********************************************************* + + @Test + public void testConstructor() { + + var metrics = mock(BatchedLogBufferMetrics.class); + assertThatThrownBy( + () -> new BatchedLogBuffer(0, 1, Duration.ofSeconds(1), 10, metrics), + "maxBatchSize < 1") + .isInstanceOf(IllegalArgumentException.class); + assertThatThrownBy( + () -> new BatchedLogBuffer(1, 0, Duration.ofSeconds(1), 10, metrics), + "maxBatchBytes < 1") + .isInstanceOf(IllegalArgumentException.class); + assertThatThrownBy( + () -> new BatchedLogBuffer(1, 1, Duration.ofSeconds(-1), 10, metrics), + "maxBatchAge < 1") + .isInstanceOf(IllegalArgumentException.class); + assertThatThrownBy( + () -> new BatchedLogBuffer(1, 1, Duration.ofSeconds(0), 10, metrics), "maxBatchAge = 0") + .isInstanceOf(IllegalArgumentException.class); + assertThatThrownBy( + () -> new BatchedLogBuffer(1, 1, Duration.ofSeconds(1), 0, metrics), "queueCapacity =0") + .isInstanceOf(IllegalArgumentException.class); + + clearInvocations(metrics); + var buffer = new BatchedLogBuffer(1, 2, Duration.ofSeconds(1), 10, metrics); + verify(metrics, times(1).description("buffer registers with metrics")).registerBuffer(any()); + + assertThat(buffer.toString()) + .as("buffer toString has correct values") + .startsWith(classSimpleName(buffer)) + .contains("maxBatchSize=1") + .contains("maxBatchBytes=2") + .contains("maxBatchAge=PT1S") + .contains("size=0"); + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventTest.java similarity index 58% rename from src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventTest.java rename to src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventTest.java index dbeca3f937..66e5036de0 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingEventTest.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingEventTest.java @@ -1,14 +1,17 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import static net.javacrumbs.jsonunit.JsonAssert.assertJsonEquals; +import static org.assertj.core.api.Assertions.assertThat; import com.fasterxml.jackson.databind.ObjectMapper; +import io.stargate.sgv2.jsonapi.util.recordable.PrettyPrintable; import java.time.Instant; import java.util.UUID; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.EnumSource; -class BillingEventTest { +/** Tests for the {@link BillingEventType} */ +public class BillingEventTest { private static final ObjectMapper MAPPER = new ObjectMapper(); @@ -25,6 +28,7 @@ private static BillingEvent.BillingProperties props() { @ParameterizedTest(name = "{0}") @EnumSource(BillingEventType.class) void serializesEventToExpectedJson(BillingEventType type) throws Exception { + UUID id = UUID.fromString("c0ffee01-1234-5678-9abc-def012345678"); Instant timestamp = Instant.parse("2026-05-19T00:29:21.506481Z"); BillingEvent event = new BillingEvent(id, timestamp, "serverless", type, props()); @@ -50,5 +54,29 @@ void serializesEventToExpectedJson(BillingEventType type) throws Exception { """ .formatted(type.eventName()); assertJsonEquals(expectedJson, actualJson); + + // just testing recordTo works, this is used with tracing + var pprint = PrettyPrintable.pprint(event); + // below is what it was when test created, white space is ignored in assert + var expectedPPrint = + """ + BillingEvent{ + id=c0ffee01-1234-5678-9abc-def012345678, + timestamp=2026-05-19T00:29:21.506481Z, + product=serverless, + event_type=%s, + properties=BillingProperties{ + usage=123, + region=us-west-2, + resource_type=serverless_database, + resource_id=tenant-x, + provider=nvidia, + model=nvidia/llama-3.2-nv-rerankqa-1b-v2 } + } + """ + .formatted(type.eventName()); + assertThat(pprint) + .as("Event recordTo includes expected values. type:" + type) + .isEqualToNormalizingWhitespace(expectedPPrint); } } diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3LifecycleTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3LifecycleTest.java new file mode 100644 index 0000000000..1bb3402988 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingS3LifecycleTest.java @@ -0,0 +1,167 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static io.stargate.sgv2.jsonapi.util.SmallRyeConfigTestUtil.addPropertyTo; +import static org.assertj.core.api.Assertions.assertThat; + +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import io.quarkus.runtime.ShutdownEvent; +import io.quarkus.runtime.StartupEvent; +import io.smallrye.config.SmallRyeConfigBuilder; +import io.stargate.sgv2.jsonapi.config.BillingS3UploadConfig; +import java.util.Arrays; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.logging.Handler; +import java.util.logging.Logger; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +/** Test the {@link BillingS3Lifecycle} gets correct config when creating the objects */ +public class BillingS3LifecycleTest { + + private Logger logger; + private Handler[] saved; + + @BeforeEach + void saveHandlers() { + logger = Logger.getLogger(DefaultBilling.BILLING_LOGGER_NAME); + saved = logger.getHandlers(); + } + + @AfterEach + void restoreHandlers() { + for (var h : logger.getHandlers()) { + logger.removeHandler(h); + } + for (var h : saved) { + logger.addHandler(h); + } + } + + /** + * Start billing upload, remove other handlers for the logger {@link + * DefaultBilling#BILLING_LOGGER_NAME} + */ + @Test + void onStartBillingEnabledOthersDisabled() { + + var config = new HashMap(); + addPropertyTo(config, BillingS3UploadConfig::enabled, true); + addPropertyTo(config, BillingS3UploadConfig::disableOtherHandlers, true); + var installer = createInstaller(config, null); + + assertHandlers(installer, true, false); + } + + /** + * Start billing upload, do not remove other handlers for the logger {@link + * DefaultBilling#BILLING_LOGGER_NAME} + */ + @Test + void onStartBillingEnabledOthersEnabled() { + + var config = new HashMap(); + addPropertyTo(config, BillingS3UploadConfig::enabled, true); + addPropertyTo(config, BillingS3UploadConfig::disableOtherHandlers, false); + var installer = createInstaller(config, null); + + assertHandlers(installer, true, true); + } + + /** + * Disable billing upload, keep other handlers for the logger {@link + * DefaultBilling#BILLING_LOGGER_NAME} + */ + @Test + void onStartBillingDisabledOthersDisabled() { + + var config = new HashMap(); + addPropertyTo(config, BillingS3UploadConfig::enabled, false); + addPropertyTo(config, BillingS3UploadConfig::disableOtherHandlers, true); + var installer = createInstaller(config, null); + + // even though disabling others is enabled, billing s3 is disabled so that should not impact + assertHandlers(installer, false, true); + } + + /** + * Disable billing upload, keep other handlers for the logger {@link + * DefaultBilling#BILLING_LOGGER_NAME} EVEN THOUGH config says disable them, because we ignore if + * S3 billing disabled + */ + @Test + void onStartBillingDisabledOthersEnabled() { + + var config = new HashMap(); + addPropertyTo(config, BillingS3UploadConfig::enabled, false); + addPropertyTo(config, BillingS3UploadConfig::disableOtherHandlers, false); + var installer = createInstaller(config, null); + + // even though disabling others is enabled, billing s3 is disabled so that should not impact + assertHandlers(installer, false, true); + } + + // ==================================== + // Scaffold + // ==================================== + + private void assertHandlers( + BillingS3Lifecycle installer, boolean expectS3Handler, boolean expectOtherHandlers) { + + try { + installer.onStart(new StartupEvent()); + var onStartHandlers = installedHandlers(); + if (expectS3Handler) { + assertThat(onStartHandlers).as("onStart attached S3 handler").contains(installer.handler()); + } + if (expectOtherHandlers) { + assertThat(onStartHandlers.size()) + .as("onStart left other handler in place") + .isGreaterThanOrEqualTo(expectS3Handler ? 2 : 1); + } else { + assertThat(onStartHandlers.size()) + .as("onStart removed other handlers.") + .isGreaterThanOrEqualTo(expectS3Handler ? 1 : 1); + } + + } finally { + installer.onStop(new ShutdownEvent()); + } + var onStopHandlers = installedHandlers(); + + // always expect that the S3 handler is removed. + assertThat(installedHandlers()) + .as("onStop removes S3 handler") + .doesNotContain(installer.handler()); + + if (expectOtherHandlers) { + assertThat(onStopHandlers.size()) + .as("onStart left other handler in place") + .isGreaterThanOrEqualTo(1); + } else { + assertThat(onStopHandlers.size()).as("onStart removed all handlers.").isEqualTo(0); + } + } + + private static List installedHandlers() { + return Arrays.stream(Logger.getLogger(DefaultBilling.BILLING_LOGGER_NAME).getHandlers()) + .toList(); + } + + private static BillingS3Lifecycle createInstaller( + Map configOverride, MeterRegistry meterRegistry) { + + var builder = new SmallRyeConfigBuilder().withMapping(BillingS3UploadConfig.class); + if (configOverride != null) { + configOverride.forEach(builder::withDefaultValue); + } + var config = builder.build().getConfigMapping(BillingS3UploadConfig.class); + + meterRegistry = meterRegistry == null ? new SimpleMeterRegistry() : meterRegistry; + + return new BillingS3Lifecycle(config, meterRegistry); + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTest.java similarity index 64% rename from src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingTest.java rename to src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTest.java index 399155d241..0a73887769 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/BillingTest.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTest.java @@ -1,4 +1,4 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.assertThatCode; @@ -7,26 +7,27 @@ import static org.mockito.Mockito.when; import io.stargate.sgv2.jsonapi.TestConstants; -import io.stargate.sgv2.jsonapi.api.request.RequestContext; import io.stargate.sgv2.jsonapi.config.BillingConfig; import io.stargate.sgv2.jsonapi.config.feature.ApiFeature; import io.stargate.sgv2.jsonapi.config.feature.ApiFeatures; -import io.stargate.sgv2.jsonapi.config.feature.FeaturesConfig; -import io.vertx.core.MultiMap; +import io.stargate.sgv2.jsonapi.service.provider.ModelInputType; +import io.stargate.sgv2.jsonapi.service.provider.ModelProvider; +import io.stargate.sgv2.jsonapi.service.provider.ModelType; +import io.stargate.sgv2.jsonapi.service.provider.ModelUsage; +import io.stargate.sgv2.jsonapi.util.ApiFeaturesTestUtil; import java.util.List; -import java.util.Map; import java.util.Optional; import org.junit.jupiter.api.Test; /** * Tests for the {@link Billing} interface itself: the {@link Billing#NO_OP} singleton and the - * {@link Billing#create(BillingConfig, ApiFeatures)} dispatch. Implementation-specific behavior of - * {@link DefaultBilling} (event building, properties etc.) is covered in {@link - * DefaultBillingTest}. + * {@link Billing#create(BillingConfig, ApiFeatures)} dispatch. + * + *

See also {@link DefaultBillingTest} */ class BillingTest { - private final TestConstants testConstants = new TestConstants(); + private final TestConstants TEST_CONSTANTS = new TestConstants(); // ============================================================ // NO_OP behavior @@ -37,10 +38,12 @@ void noOpDoesNothingForValidUsage() { assertThatCode(() -> Billing.NO_OP.emitEvent(stubUsage())).doesNotThrowAnyException(); } + /** + * Even the NO-OP enforces the non-null contract so callers can't accidentally pass null and have + * it silently swallowed in a test that uses the no-op. + */ @Test void noOpThrowsOnNullUsage() { - // Even the NO-OP enforces the non-null contract so callers can't accidentally pass null and - // have it silently swallowed in a test that uses the no-op. assertThatThrownBy(() -> Billing.NO_OP.emitEvent(null)) .isInstanceOf(NullPointerException.class) .hasMessageContaining("modelUsage"); @@ -71,39 +74,32 @@ void createReturnsNoOpWhenFeatureDisabled() { /** * If BILLING_EVENTS_LOGGING is enabled in startup config, a request header MUST NOT be able to - * turn it off — the config is authoritative. Verified at the dispatch layer because that's where - * the user-visible effect lands (you get DefaultBilling, not NO_OP). + * turn it off. */ @Test void createConfigEnabledIsNotOverriddenByHeader() { - var config = mock(FeaturesConfig.class); - when(config.flags()).thenReturn(Map.of(ApiFeature.BILLING_EVENTS_LOGGING, "true")); - var headers = MultiMap.caseInsensitiveMultiMap(); - headers.add(ApiFeature.BILLING_EVENTS_LOGGING.httpHeaderName(), "false"); - var apiFeatures = - ApiFeatures.fromConfigAndRequest(config, new RequestContext.HttpHeaderAccess(headers)); + // enabled in the config + // disabled by the header + var apiFeatures = featuresWithBilling(true, false); var billing = Billing.create(validConfig(), apiFeatures); assertThat(billing) - .as("config=true must win over header=false at dispatch") + .as("config=true must win over header=false") .isInstanceOf(DefaultBilling.class); } /** * Conversely, if startup config leaves the flag unset, a request header CAN enable it. Proves the - * header path is alive — without this, the test above would pass trivially. + * header path is alive */ @Test void createHeaderEnablesWhenConfigUnset() { - var config = mock(FeaturesConfig.class); - when(config.flags()).thenReturn(Map.of()); - var headers = MultiMap.caseInsensitiveMultiMap(); - headers.add(ApiFeature.BILLING_EVENTS_LOGGING.httpHeaderName(), "true"); - var apiFeatures = - ApiFeatures.fromConfigAndRequest(config, new RequestContext.HttpHeaderAccess(headers)); + // no value in the config + // enabled by the header + var apiFeatures = featuresWithBilling(null, true); var billing = Billing.create(validConfig(), apiFeatures); @@ -116,19 +112,23 @@ void createHeaderEnablesWhenConfigUnset() { /** Minimal valid {@link BillingConfig} — enough for {@link DefaultBilling} to construct. */ private static BillingConfig validConfig() { + var config = mock(BillingConfig.class); when(config.product()).thenReturn("serverless"); when(config.resourceType()).thenReturn("serverless_database"); when(config.internalModelProviders()).thenReturn(List.of("nvidia")); when(config.enabledEventTypes()).thenReturn(Optional.empty()); + return config; } private static ApiFeatures featuresWithBilling(boolean enabled) { - var config = mock(FeaturesConfig.class); - when(config.flags()) - .thenReturn(Map.of(ApiFeature.BILLING_EVENTS_LOGGING, String.valueOf(enabled))); - return ApiFeatures.fromConfigAndRequest(config, null); + return featuresWithBilling(enabled, null); + } + + private static ApiFeatures featuresWithBilling(Boolean configEnabled, Boolean headerEnabled) { + return ApiFeaturesTestUtil.withFeature( + ApiFeature.BILLING_EVENTS_LOGGING, configEnabled, headerEnabled); } private ModelUsage stubUsage() { @@ -136,7 +136,7 @@ private ModelUsage stubUsage() { ModelProvider.NVIDIA, ModelType.EMBEDDING, "model-x", - testConstants.TENANT, + TEST_CONSTANTS.TENANT, ModelInputType.INDEX, 100, 500, diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTestBase.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTestBase.java new file mode 100644 index 0000000000..38bceb85f6 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingTestBase.java @@ -0,0 +1,520 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.Mockito.*; + +import io.stargate.sgv2.jsonapi.metrics.BatchedLogBufferMetrics; +import io.stargate.sgv2.jsonapi.util.MetricsUnitAssertions; +import io.stargate.sgv2.jsonapi.util.MockClock; +import java.time.Duration; +import java.util.List; +import java.util.concurrent.*; +import java.util.concurrent.locks.LockSupport; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.stream.IntStream; +import java.util.stream.Stream; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** Common code for tests around billing events being buffered and uploaded */ +public abstract class BillingTestBase { + + private static final Logger LOGGER = LoggerFactory.getLogger(BillingTestBase.class); + + // ====================================================================== + // BUFFER config and values for the tests to use + // NOTE: these values are all balanced, see comments before changing + // ====================================================================== + + // want the line bytes when lines go into the buffer to be 25 + // template below is 21 bytes + // 3 chars for the index get added in createFixture() + // 1 char added in the buffer calc's for the `\n` to write out + protected static final int MESSAGE_LENGTH_IN_BUFFER = 25; + protected static final String TEMPLATE_25_CHARS = "Total of 25 chars "; + + protected static final int MAX_BATCH_SIZE = 100; + // The number of messages we can fit inside the max bytes setting + protected static final int MAX_BATCH_BYTES_NUM_MESSAGES = 20; + protected static final int MAX_BATCH_BYTES = + MESSAGE_LENGTH_IN_BUFFER * MAX_BATCH_BYTES_NUM_MESSAGES; + + // How many full batches, tracked by max size, we want to fit in the buffer + protected static final int BATCHES_BY_SIZE_PER_CAPACITY = 3; + protected static final int BUFFER_CAPACITY = MAX_BATCH_SIZE * BATCHES_BY_SIZE_PER_CAPACITY; + + // number of log records we create for each feature / test + protected static final int NUM_RECORDS = BUFFER_CAPACITY * 3; + // when using mock clock, we set the instant for each log record to be 1 "second" + // after the last, so we will create log records with up to + // NUM_RECORDS of seconds past when the clock was started + // used when testing the max age features + protected static final Duration MAX_AGE = Duration.ofSeconds(NUM_RECORDS); + protected static final Level LOG_LEVEL = Level.INFO; + + // ====================================================================== + // LOG HANDLER config and values for the tests to use + // ====================================================================== + + // sleep between checking the buffer, long we will normally use flush() to wake + // for tests + protected static final Duration UPLOAD_SLEEP_DURATION = Duration.ofSeconds(60); + protected static final Duration UPLOAD_SLEEP_DURATION_SHORT = Duration.ofMillis(100); + + // upload must complete in this time + protected static final Duration UPLOADER_SAFETY_DEADLINE = Duration.ofSeconds(30); + // close() will wait this long for startUploading() to finish + protected static final Duration UPLOAD_SHUTDOWN_DEADLINE = Duration.ofSeconds(30); + protected static final Duration UPLOAD_SHUTDOWN_DEADLINE_SHORT = Duration.ofSeconds(1); + + protected static void threadSleep(long millis) { + LockSupport.parkNanos(Duration.ofMillis(millis).toNanos()); + } + + protected static void waitOnLatch(CountDownLatch latch) { + try { + latch.await(); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new RuntimeException("interrupted waiting on latch", e); + } + } + + // ********************************************************* + // Fixture - used to group the test config and test data we need + // ********************************************************* + + /** Default fixture for buffer tests with config from the top of class */ + Fixture defaultBufferFixture() { + return defaultBufferFixture(false); + } + + Fixture defaultBufferFixture(boolean mockBufferClock) { + return Fixture.createFixture( + MAX_BATCH_SIZE, + MAX_BATCH_BYTES, + MAX_AGE, + BUFFER_CAPACITY, + NUM_RECORDS, + LOG_LEVEL, + TEMPLATE_25_CHARS, + mockBufferClock, + false, + false, + false); + } + + Fixture defaultLogHandlerFixture() { + return defaultLogHandlerFixture(true, false, false); + } + + Fixture defaultLogHandlerFixture( + boolean mockBuffer, boolean shortUploadSleep, boolean shortShutdownDuration) { + return Fixture.createFixture( + MAX_BATCH_SIZE, + MAX_BATCH_BYTES, + MAX_AGE, + BUFFER_CAPACITY, + NUM_RECORDS, + LOG_LEVEL, + TEMPLATE_25_CHARS, + false, + mockBuffer, + shortUploadSleep, + shortShutdownDuration); + } + + /** + * Tracks the config of the buffer, the buffer, the data we can use for each test to add to + * buffer, etc. + * + *

See {@link #defaultBufferFixture(boolean)} + */ + record Fixture( + int maxBatchSize, + long maxBytes, + Duration maxAge, + int queueCapacity, + List logRecords, + MetricsUnitAssertions metricsUtil, + BatchedLogBuffer buffer, + BatchedLogBufferMetrics bufferMetrics, + BillingUploadingLogHandler logHandler, + AsyncBatchedLogUploader uploader, + MockClock clock) { + + /** Create fixture, creates LogRecords that can be used to add to the buffer */ + static Fixture createFixture( + int maxBatchSize, + long maxBytes, + Duration maxAge, + int queueCapacity, + int numLogRecords, + Level logLevel, + String logRecordTemplate, + boolean mockBufferClock, + boolean mockBuffer, + boolean shortUploadSleepDuration, + boolean shortUploadShutdownDeadline) { + + if (mockBuffer && mockBufferClock) { + throw new IllegalArgumentException("cannot mock the buffer and the buffer clock"); + } + // Make sure to initialize the mock clock before creating the log messages + // so they are always after the start of the clock. + var mockClock = mockBufferClock ? new MockClock() : null; + + // + // fork the clock, we are going to use clockForRecords when creating the records + // and will advance it 1 second for each record, the original mockClock is for + // the buffer to use, so we let the test advance that + // NOTE: THIS MAY RESULT IN SOME NEGATIVE AGE, BATCH uses Duration.abs() to make sure it's ok + var clockForRecords = mockClock == null ? null : new MockClock(mockClock); + + var logRecords = + IntStream.range(0, numLogRecords) + .mapToObj(i -> logRecordTemplate + String.format("%03d", i)) + .map( + s -> { + var record = new LogRecord(logLevel, s); + if (clockForRecords != null) { + record.setInstant(clockForRecords.instant()); + clockForRecords.nextSecond(); + } + return record; + }) + .toList(); + + var metricsUtil = new MetricsUnitAssertions(); + var bufferMetrics = + new BatchedLogBufferMetrics(metricsUtil.registry(), BillingS3Lifecycle.METRICS_PREFIX); + + BatchedLogBuffer buffer; + if (mockBuffer) { + buffer = mock(BatchedLogBuffer.class); + // setup for an empty buffer when calling + when(buffer.offer(any())).thenReturn(true); + when(buffer.isEmpty()).thenReturn(true); + when(buffer.size()).thenReturn(0); + when(buffer.nextBatch(anyBoolean())).thenReturn(null); + } else { + buffer = + new BatchedLogBuffer( + maxBatchSize, + maxBytes, + maxAge, + queueCapacity, + bufferMetrics, + mockBufferClock ? mockClock : BatchedLogBuffer.DEFAULT_CLOCK); + } + var uploader = mock(AsyncBatchedLogUploader.class); + var logHandler = + new BillingUploadingLogHandler( + buffer, + uploader, + shortUploadSleepDuration ? UPLOAD_SLEEP_DURATION_SHORT : UPLOAD_SLEEP_DURATION, + UPLOADER_SAFETY_DEADLINE, + shortUploadShutdownDeadline + ? UPLOAD_SHUTDOWN_DEADLINE_SHORT + : UPLOAD_SHUTDOWN_DEADLINE); + + return new Fixture( + maxBatchSize, + maxBytes, + maxAge, + queueCapacity, + logRecords, + metricsUtil, + buffer, + bufferMetrics, + logHandler, + uploader, + mockClock); + } + + /** Assert the buffer is full, and so offer() fails */ + void assertBufferFull(String desc, int index) { + + // although the next log record is wafer-thin, it is too much for Mr Creosote + assertThat(buffer().offer(logRecords.get(index))).as(desc + " - fail at capacity").isFalse(); + + // Running again to confirm it is still full + assertThat(buffer().offer(logRecords.get(index))) + .as(desc + " - second - fail at capacity") + .isFalse(); + } + + /** + * Offer the log records selected by slice to the buffer, all should work, assert the buffer has + * the items the slice selected + */ + BufferSnapshot assertOffer(String desc, BatchedLogBufferTest.Slice slice) { + + var snapshot = BufferSnapshot.create(this); + + for (var record : slice.stream(logRecords).toList()) { + assertThat(buffer.offer(record)).as(desc + " - assertOffer() - offering").isTrue(); + } + + snapshot.assertAll(desc, slice, true); + return snapshot; + } + + /** + * Get a batch from the buffer, assert we got a batch that is legal, and assert the buffer has + * changed by the amount of the batch + */ + BatchedLogBuffer.Batch assertNextBatch(String desc, boolean drainFully) { + + var snapshot = BufferSnapshot.create(this); + var batch = buffer.nextBatch(drainFully); + + // assert the batch is what we expected. + assertThat(batch).as(desc + " - assertNextBatch() - batch is not null").isNotNull(); + + assertThat(batch.size()) + .as(desc + " - assertNextBatch() - batch size <= MAX_BATCH_SIZE") + .isLessThanOrEqualTo(maxBatchSize); + // note: it is legal to have a batch bigger than the maxBytes, specialised tests for that + // shoudl only happen when there is a single log record bigger than maxBytes + assertThat(batch.bytes()) + .as(desc + " - assertNextBatch() - batch bytes <= MAX_BATCH_BYTES") + .isLessThanOrEqualTo(maxBytes); + + // assert the buffer updated bookkeeping as we expect + snapshot.assertAll(desc, batch); + return batch; + } + + // just redeclare with no exception to make it easier + interface NoExceptionCloseable extends AutoCloseable { + @Override + void close(); + } + + /** + * Start the logHandler uploading on a daemon thread, and returns a closeable for killing the + * thread. + * + * @return + */ + NoExceptionCloseable startHandlerUploading(String desc) { + + var executor = + Executors.newSingleThreadExecutor(Thread.ofPlatform().daemon().name(desc).factory()); + + var uploadingFuture = + executor.submit( + () -> { + LOGGER.info("startHandlerUploading() - starting logHandler. desc:{}", desc); + logHandler.startUploading(); + }); + + return () -> { + LOGGER.info("startHandlerUploading() - stopping logHandler. desc:{}", desc); + try { + // this is waiting for the uploading thread to return + uploadingFuture.get(10, TimeUnit.SECONDS); + executor.awaitTermination(1000, TimeUnit.MILLISECONDS); + + LOGGER.info("startHandlerUploading() - stopped logHandler. desc:{}", desc); + + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + LOGGER.error("startHandlerUploading() - error 1", e); + throw new RuntimeException(e); + } catch (ExecutionException e) { + LOGGER.error("startHandlerUploading() - error 2", e); + + throw e.getCause() instanceof RuntimeException re + ? re + : new RuntimeException(e.getCause()); + } catch (TimeoutException e) { + LOGGER.error("startHandlerUploading() - error 3", e); + + throw new RuntimeException(e); + } finally { + executor.shutdownNow(); + } + }; + } + } + + /** + * A slice of a list, `from` is inclusive, `to` is exclusive + * + *

... + */ + record Slice(int from, int to) { + + public Stream stream(List list) { + return list.stream().skip(from).limit(to - from); + } + + public int size() { + return to - from; + } + + public static Slice to(int to) { + return new Slice(0, to); + } + + public static Slice from(int from) { + return new Slice(from, Integer.MAX_VALUE); + } + + public static Slice slice(int from, int to) { + return new Slice(from, to); + } + } + + /** + * Snapshot of the metadata (size etc) for the buffer, that can be used to compare how the buffer + * metadata has changed + * + *

... + */ + record BufferSnapshot( + boolean isEmpty, + int size, + long queuedBytes, + int remainingCapacity, + Fixture fixture, + MetricsUnitAssertions.MetricSnapshot metricSnapshot) { + + static BufferSnapshot create(Fixture fixture) { + + return new BufferSnapshot( + fixture.buffer().isEmpty(), + fixture.buffer().size(), + fixture.buffer().queuedBytes(), + fixture.buffer().remainingCapacity(), + fixture, + fixture.metricsUtil.createSnapshot()); + } + + /** + * Assert that the current metadata values for the buffer are the values in the snapshot PLUS + * the log records that were added by the Slice. + */ + void assertAll(String desc, Slice slice, boolean inOrder) { + assertBufferMetadata(desc, slice); + assertBufferItems(desc, slice, inOrder); + } + + /** + * Assert that the current metadata values for the buffer are the values in the snapshot MINUS + * the buffer entries that were removed in the batch + */ + void assertAll(String desc, BatchedLogBuffer.Batch batch) { + assertBufferMetadata(desc, batch); + assertBufferItems(desc, batch); + } + + /** current buffer metadata = snapshot + slice */ + void assertBufferMetadata(String desc, Slice slice) { + + if (slice.size() == 0) { + assertThat(fixture.buffer().isEmpty()) + .as(desc + " - isEmpty no change after empty slice") + .isEqualTo(isEmpty()); + } else { + assertThat(fixture.buffer().isEmpty()) + .as(desc + " - isEmpty false after non empty slice") + .isEqualTo(false); + } + + assertThat(fixture.buffer().size()) + .as(desc + " - post buffer size increased by slice") + .isEqualTo(size() + slice.size()); + // metric should be the size of the buffer, does not matter what metric snapshot was + fixture.metricsUtil.assertMetric(fixture.bufferMetrics.size, size() + slice.size()); + + // Buffer offered increases, dropped does not change + fixture.metricsUtil.assertMetric(metricSnapshot, fixture.bufferMetrics.offered, slice.size()); + fixture.metricsUtil.assertMetric(metricSnapshot, fixture.bufferMetrics.dropped, 0); + + // remaining is just a calculation, capacity - size + fixture.metricsUtil.assertMetric( + fixture.bufferMetrics.remainingCapacity, fixture.queueCapacity - fixture.buffer().size()); + + // head age is the age of the first item in the buffer, NOTE clock overrides can change time + var firstRecord = fixture.buffer().peekBuffer().getFirst(); + if (firstRecord != null) { + var clockForMetric = + fixture.clock() == null ? BatchedLogBuffer.DEFAULT_CLOCK : fixture.clock(); + // metric is calc's when read, so it may be younger (less ms) but never older (more ms) + fixture.metricsUtil.assertMetric( + fixture.bufferMetrics.headAgeMs, + (a) -> { + a.isLessThanOrEqualTo( + Duration.between(firstRecord.eventAt(), clockForMetric.instant()) + .abs() + .toMillis()); + }); + } + + long addedBytes = 0; + for (var record : slice.stream(fixture.logRecords).toList()) { + addedBytes += BatchedLogBuffer.Entry.lineBytes(record.getMessage()); + } + + assertThat(fixture.buffer().queuedBytes()) + .as(desc + " - post buffer bytes increased by slice") + .isEqualTo(queuedBytes + addedBytes); + fixture.metricsUtil.assertMetric(fixture.bufferMetrics.bytes, queuedBytes + addedBytes); + } + + /** current buffer metadata = snapshot - batch */ + void assertBufferMetadata(String desc, BatchedLogBuffer.Batch batch) { + + assertThat(fixture.buffer().size()) + .as(desc + " - buffer size decreased by batch size") + .isEqualTo(size() - batch.size()); + + assertThat(fixture.buffer().queuedBytes()) + .as(desc + " - buffer bytes size decreased by batch bytes") + .isEqualTo(queuedBytes - batch.bytes()); + } + + /** + * current buffer items contain items from slice inOrder - if we expect items in buffer to match + * order of the fixture + */ + void assertBufferItems(String desc, Slice slice, boolean inOrder) { + + var bufferItems = fixture.buffer().peekBuffer(); + + int i = slice.from() > bufferItems.size() ? 0 : slice.from(); + for (var record : slice.stream(fixture.logRecords).toList()) { + + if (inOrder) { + assertThat(record.getMessage()) + .as(desc + " - buffer items at position match exactly pos: " + i) + .isEqualTo(bufferItems.get(i++).line()); + } else { + + var entry = new BatchedLogBuffer.Entry(record.getInstant(), record.getMessage()); + assertThat(bufferItems) + .as(desc + " - buffer items contains entry: " + entry) + .contains(entry); + } + } + } + + /** current buffer items contain NONE of items in batch */ + void assertBufferItems(String desc, BatchedLogBuffer.Batch batch) { + + var peekedBuffer = fixture.buffer().peekBuffer(); + + for (var batchString : batch.lines()) { + + var found = peekedBuffer.stream().anyMatch(entry -> entry.line().equals(batchString)); + assertThat(found) + .as(desc + " - line from batch no longer in buffer: " + batchString) + .isFalse(); + } + } + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandlerTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandlerTest.java new file mode 100644 index 0000000000..d8931b5166 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/BillingUploadingLogHandlerTest.java @@ -0,0 +1,309 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; +import static org.mockito.Mockito.*; + +import io.smallrye.mutiny.Uni; +import java.util.List; +import java.util.logging.LogRecord; +import java.util.stream.IntStream; +import org.junit.jupiter.api.Test; +import org.mockito.ArgumentCaptor; +import org.mockito.verification.VerificationMode; + +/** Tests for the {@link BillingUploadingLogHandler} */ +public class BillingUploadingLogHandlerTest extends BillingTestBase { + + // ********************************************************* + // Handler interface - Producer side of the handler + // ********************************************************* + + /** Null record silently dropped by handler */ + @Test + public void publishSilentDropNulls() { + + var fixture = defaultLogHandlerFixture(); + + fixture.logHandler().publish(null); + fixture.logHandler().publish(null); + fixture.logHandler().publish(null); + + verify( + fixture.buffer(), + times(0).description("publishSilentDropNulls() - no calls to buffer.offer()")) + .offer(any()); + } + + /** Non null record silently dropped by handler when closed */ + @Test + public void publishSilentDropWhenClosed() { + + var fixture = defaultLogHandlerFixture(); + fixture.logHandler().close(); + + fixture.logHandler().publish(fixture.logRecords().getFirst()); + fixture.logHandler().publish(fixture.logRecords().getFirst()); + fixture.logHandler().publish(fixture.logRecords().getFirst()); + + verify( + fixture.buffer(), + times(0).description("publishSilentDropWhenClosed() - no calls to buffer.offer()")) + .offer(any()); + } + + /** Records published when buffer is full are dropped, no error */ + @Test + public void publishSilentWhenBufferFull() { + + var fixture = defaultLogHandlerFixture(); + + // return false, buffer full , go away + when(fixture.buffer().offer(any())).thenReturn(false); + + fixture.logHandler().publish(fixture.logRecords().getFirst()); + fixture.logHandler().publish(fixture.logRecords().getFirst()); + fixture.logHandler().publish(fixture.logRecords().getFirst()); + + verify( + fixture.buffer(), + times(3).description("publishSilentWhenBufferFull() - called offer for each record")) + .offer(fixture.logRecords().getFirst()); + } + + /** Passing record to handler, is then passed to the buffer. */ + @Test + public void publishOfferSucceed() { + + var fixture = defaultLogHandlerFixture(); + var slice = Slice.to(MAX_BATCH_BYTES_NUM_MESSAGES); + var expectedLogRecords = slice.stream(fixture.logRecords()).toList(); + + var argCaptor = ArgumentCaptor.forClass(LogRecord.class); + + for (var record : expectedLogRecords) { + fixture.logHandler().publish(record); + } + + verify( + fixture.buffer(), + times(expectedLogRecords.size()) + .description("publishOfferSucceed() - buffer called for each log record")) + .offer(argCaptor.capture()); + var actualLogRecords = argCaptor.getAllValues(); + + assertThat(actualLogRecords) + .as("publishOfferSucceed() - all and only expected records passed to the buffer") + .containsExactlyElementsOf(expectedLogRecords); + } + + /** Calling flush on handler that is NOT uploading does nothing */ + @Test + public void flushNullOpIfNotStarted() { + + var fixture = defaultLogHandlerFixture(); + + fixture.logHandler().flush(); + // there is no uploading, so should not ask for next batch + verify(fixture.buffer(), never()).nextBatch(anyBoolean()); + } + + /** + * Verify the number of times a function was called, but with a timeout to wait. e.g. when waiting + * for the uploading thread to wakeup + */ + private VerificationMode timeoutTimes(String desc, int times) { + return timeout(2000).times(times).description(desc); + } + + /** Calling flush on handler that is uploading causes handler to check buffer. */ + @Test + public void flushChecksForBatch() { + + var fixture1 = defaultLogHandlerFixture(); + try (var handlerThread = + fixture1.startHandlerUploading("flushChecksForBatch() - close not called")) { + fixture1.logHandler().flush(); + // close has not been called, so it should not drain + verify(fixture1.buffer(), timeoutTimes("nextBatch() called once with drain false", 1)) + .nextBatch(false); + + // this is a bit stupid, calling close to close the upload thread + fixture1.logHandler().close(); + } + + var fixture2 = defaultLogHandlerFixture(); + try (var handlerThread = + fixture2.startHandlerUploading("flushChecksForBatch() - close is called")) { + fixture2.logHandler().unsafeClose(); + fixture2.logHandler().flush(); + // close has been called, so it should drain buffer + verify(fixture2.buffer(), timeoutTimes("nextBatch() called once with drain true", 1)) + .nextBatch(true); + } + } + + @Test + public void closeWithoutUploadThreadReturns() { + + var fixture1 = defaultLogHandlerFixture(); + // NOT STARTING upload + fixture1.logHandler().close(); + // upload not running, should not try to get a batch + verify(fixture1.buffer(), timeoutTimes("nextBatch() never called", 0)).nextBatch(anyBoolean()); + // should have closed the uploader + verify(fixture1.uploader(), timeoutTimes("uploader.close() called", 1)).close(); + } + + /** + * Call close, but the upload thread has not released the upload permit, so close cannot detect + * upload has finished. + */ + @Test + public void closeReturnsWhenUploadUnstopped() { + + var fixture1 = defaultLogHandlerFixture(true, false, true); + // NOT STARTING upload, but acquire the permit it would take + fixture1.logHandler().unsafeAcquireUploadPermit(); + // close() will not return until it times out waiting for the upload thread to finish + fixture1.logHandler().close(); + } + + /** + * Calling close() when the handler is running should cause the buffer to be called to drain it. + */ + @Test + public void closeCausesBufferDrain() { + + var fixture1 = defaultLogHandlerFixture(); + try (var handlerThread = fixture1.startHandlerUploading("closeCausesBufferDrain()")) { + threadSleep(100); // give the uploader time to get into the wait on wakeup + + fixture1.logHandler().close(); + // close has been called, so it should drain + verify(fixture1.buffer(), timeoutTimes("nextBatch() called with drain=true", 1)) + .nextBatch(true); + verify(fixture1.uploader(), timeoutTimes("uploader.close() called", 1)).close(); + } + // the auto closable will wait for the upload thread to naturally exit + } + + // ********************************************************* + // startUploading - Consumer side of the handler + // ********************************************************* + + /** + * Calling startUpLoad twice on different threads, fails because there can be only one active + * thread running the function + * + *

Cannot call on same thread as it will be parked running the upload + */ + @Test + public void startUploadingCalledTwiceFails() { + + var fixture1 = defaultLogHandlerFixture(); + try (var handlerThread1 = + fixture1.startHandlerUploading("startUploadingCalledTwiceFails() - 1st")) { + // make sure the worker thread has time to start + threadSleep(10); + + // the exception will happen when startUploading is entered, but we + // wont get the error until calling close() which calls Future.get() + var closable = fixture1.startHandlerUploading("startUploadingCalledTwiceFails() - 2nd"); + // make sure the worker thread has time to start + threadSleep(10); + + assertThatThrownBy(closable::close, "startUploadingCalledTwiceFails() - second call") + .isInstanceOf(IllegalStateException.class); + + // stop the first thread that is running startUpload() + fixture1.logHandler().close(); + } + } + + /** In normal operation startUpload detects three batches and sends to uploader */ + @Test + public void startUploadingSendsToUploader() { + + var NUM_BATCHES = 3; + var fixture1 = defaultLogHandlerFixture(); + try (var handlerThread1 = + fixture1.startHandlerUploading("startUploadingSendsToUploader() - upload thread")) { + // make sure the worker thread has time to start and get to the sleep. + threadSleep(100); + + // ** TESTING NORMAL OPERATION + + // setup buffer to return three batches we will collect in normal operations + var expectedNormalBatches = mockUploading(fixture1, NUM_BATCHES, false); + // handler should be sleeping because of long sleep, flush will wake it up. + fixture1.logHandler().flush(); + // wait for it the handler to call the uploader + var normalCaptor = ArgumentCaptor.forClass(BatchedLogBuffer.Batch.class); + verify( + fixture1.uploader(), + timeoutTimes( + "startUploadingSendsToUploader() - normal mode", expectedNormalBatches.size())) + .upload(normalCaptor.capture()); + var actualNormalBatches = normalCaptor.getAllValues(); + + // ** TESTING CLOSE / SHUTDOWN OPERATION + + // reset counter , will already be NUM_BATCHES from the normal operation check above + clearInvocations(fixture1.uploader()); + // we are using the long upload sleep, uploader should be asleep again, send batches + // and close to see we get correct behavior + var expectedShutdownBatches = mockUploading(fixture1, NUM_BATCHES, true); + // close to get shutdown operations + fixture1.logHandler().close(); + // wait for it the handler to call the uploader + var shutdownCaptor = ArgumentCaptor.forClass(BatchedLogBuffer.Batch.class); + verify( + fixture1.uploader(), + timeoutTimes( + "startUploadingSendsToUploader() - shutdown mode", + expectedShutdownBatches.size())) + .upload(shutdownCaptor.capture()); + var actualShutdownBatches = shutdownCaptor.getAllValues(); + + assertThat(actualNormalBatches) + .as("startUploadingSendsToUploader() - batches from normal operation match") + .containsExactlyElementsOf(expectedNormalBatches); + + assertThat(actualShutdownBatches) + .as("startUploadingSendsToUploader() - batches from shutdown operation match") + .containsExactlyElementsOf(expectedShutdownBatches); + + // we have closed handler, should exit block now + } + } + + private List mockUploading( + Fixture fixture, int numBatches, boolean expectDrainFully) { + // by default the mock buffer will be returning null for nextBatch(), the + // log handler should be in a wait because we are using long upload sleep + + var expectedBatches = + IntStream.range(0, numBatches).mapToObj(i -> mock(BatchedLogBuffer.Batch.class)).toList(); + + // we expect the uploader to be called with these batches, and it needs to + // return a Uni with an UploadResult - but we dont need to keep the UploadResult + // MUST set up the uploader to return a value before putting batches into the buffer + for (var batch : expectedBatches) { + var result = new AsyncBatchedLogUploader.UploadResult(batch, null); + when(fixture.uploader().upload(batch)).thenReturn(Uni.createFrom().item(result)); + } + + // now connect the Batch's to the buffer so it will return them. Once this is done + // the upload thread will pick them up once woken + // expectDrainFully depends on if the test is closed the handler. + var nextBatchStub = when(fixture.buffer().nextBatch(expectDrainFully)); + for (var batch : expectedBatches) { + nextBatchStub = nextBatchStub.thenReturn(batch); + } + // now return null as sentinel for no more data + nextBatchStub.thenReturn(null); + + return expectedBatches; + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBillingTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBillingTest.java similarity index 93% rename from src/test/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBillingTest.java rename to src/test/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBillingTest.java index 7657c48282..4cb78a7af0 100644 --- a/src/test/java/io/stargate/sgv2/jsonapi/service/provider/DefaultBillingTest.java +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/DefaultBillingTest.java @@ -1,4 +1,4 @@ -package io.stargate.sgv2.jsonapi.service.provider; +package io.stargate.sgv2.jsonapi.service.billing; import static java.util.logging.Logger.getLogger; import static net.javacrumbs.jsonunit.JsonAssert.assertJsonEquals; @@ -9,6 +9,10 @@ import io.stargate.sgv2.jsonapi.TestConstants; import io.stargate.sgv2.jsonapi.config.BillingConfig; +import io.stargate.sgv2.jsonapi.service.provider.ModelInputType; +import io.stargate.sgv2.jsonapi.service.provider.ModelProvider; +import io.stargate.sgv2.jsonapi.service.provider.ModelType; +import io.stargate.sgv2.jsonapi.service.provider.ModelUsage; import java.time.Instant; import java.util.ArrayList; import java.util.Arrays; @@ -26,7 +30,10 @@ import org.junit.jupiter.params.provider.EnumSource; import org.junit.jupiter.params.provider.MethodSource; -class DefaultBillingTest { +/** Tests for {@link DefaultBilling} */ +public class DefaultBillingTest { + + private final TestConstants TEST_CONSTANTS = new TestConstants(); private static final String PRODUCT = "serverless"; private static final String RESOURCE_TYPE = "serverless_database"; @@ -42,8 +49,6 @@ class DefaultBillingTest { private static final UUID PLACEHOLDER_ID = new UUID(0L, 0L); private static final Instant PLACEHOLDER_TIMESTAMP = Instant.EPOCH; - private final TestConstants testConstants = new TestConstants(); - // ============================================================ // buildEvents // ============================================================ @@ -54,11 +59,10 @@ void buildEventsProducesExpectedEventsForEveryProviderAndModelType( ModelProvider provider, ModelType modelType) { // DefaultBilling does not read ModelType — events are identical across model types. Running // every (provider, modelType) combination guards against future regressions if either - // dimension gains handling. INTERNAL_PROVIDERS decides whether the provider gets internal_* - // or external_* event types. + // dimension gains handling. + var billing = newBilling(INTERNAL_PROVIDERS, Optional.empty()); var modelUsage = usage(provider, modelType); - var events = billing.buildEvents(modelUsage); var isInternal = INTERNAL_PROVIDERS.contains(provider.apiName()); @@ -195,7 +199,7 @@ public void flush() {} public void close() {} }; - var julLogger = getLogger("billing.events"); + var julLogger = getLogger(DefaultBilling.BILLING_LOGGER_NAME); julLogger.addHandler(handler); try { @@ -245,7 +249,7 @@ private ModelUsage usage(ModelProvider provider, ModelType modelType) { provider, modelType, MODEL_NAME, - testConstants.TENANT, + TEST_CONSTANTS.TENANT, ModelInputType.INDEX, 100, TOTAL_TOKENS, @@ -263,9 +267,9 @@ private BillingEvent expectedEvent(BillingEventType eventType, long usage, Strin var properties = new BillingEvent.BillingProperties( usage, - testConstants.TENANT.region(), + TEST_CONSTANTS.TENANT.region(), RESOURCE_TYPE, - testConstants.TENANT.toString(), + TEST_CONSTANTS.TENANT.toString(), providerName, MODEL_NAME); return new BillingEvent(PLACEHOLDER_ID, PLACEHOLDER_TIMESTAMP, PRODUCT, eventType, properties); @@ -298,9 +302,9 @@ private String expectedEventJson(BillingEventType eventType, long usage, String PRODUCT, eventType.eventName(), usage, - testConstants.TENANT.region(), + TEST_CONSTANTS.TENANT.region(), RESOURCE_TYPE, - testConstants.TENANT.toString(), + TEST_CONSTANTS.TENANT.toString(), providerName, MODEL_NAME); } diff --git a/src/test/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploaderTest.java b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploaderTest.java new file mode 100644 index 0000000000..43b7121d22 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/service/billing/S3BatchedLogUploaderTest.java @@ -0,0 +1,254 @@ +package io.stargate.sgv2.jsonapi.service.billing; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.Mockito.*; + +import io.smallrye.config.SmallRyeConfigBuilder; +import io.stargate.sgv2.jsonapi.api.v1.BillingS3UploadIntegrationTest; +import io.stargate.sgv2.jsonapi.config.BillingS3UploadConfig; +import io.stargate.sgv2.jsonapi.metrics.BatchedLogUploaderMetrics; +import java.nio.charset.StandardCharsets; +import java.time.Duration; +import java.time.Instant; +import java.time.temporal.ChronoUnit; +import java.util.List; +import java.util.concurrent.CompletableFuture; +import org.junit.jupiter.api.Test; +import org.mockito.ArgumentCaptor; +import software.amazon.awssdk.core.async.AsyncRequestBody; +import software.amazon.awssdk.http.SdkHttpResponse; +import software.amazon.awssdk.services.s3.S3AsyncClient; +import software.amazon.awssdk.services.s3.model.PutObjectRequest; +import software.amazon.awssdk.services.s3.model.PutObjectResponse; + +/** + * Tests for the {@link S3BatchedLogUploader} + * + *

These tests only check it calls the S3 client as expected, not that batches are sent anywhere. + * See {@link BillingS3UploadIntegrationTest} + */ +class S3BatchedLogUploaderTest { + + private static final Instant OLDEST_EVENT_AT = Instant.parse("2026-05-20T16:23:00Z"); + private static final String LINE_A = "{\"a\":1}"; // him + private static final String LINE_B = "{\"b\":2}"; + private static final int LINE_BYTE_SIZE = 16; // 7 chars per line and one for new line + private static final BatchedLogBuffer.Batch BATCH = + new BatchedLogBuffer.Batch( + BatchedLogBuffer.BillingBatchReason.DRAINING, + List.of(LINE_A, LINE_B), + LINE_BYTE_SIZE, // 7 chars per line and one for new line + OLDEST_EVENT_AT); + private static final String EXPECTED_KEY = + "data-api/2026/05/20/16/23/%s.jsonl".formatted(BATCH.id()); + + @Test + void createReadsConfig() { + + var fixture = Fixture.create(true); + + var toString = fixture.uploader.toString(); + + assertThat(toString) + .as("toString() contains region)") + .contains("region=" + fixture.config.region()); + assertThat(toString) + .as("toString() contains bucket)") + .contains("bucket=" + fixture.config.bucket()); + assertThat(toString) + .as("toString() contains pathPrefix)") + .contains("pathPrefix=" + fixture.config.s3PathPrefix()); + + // TODO: test for endpoint override. + } + + @Test + void closeCascadedToS3Client() { + + var fixture = Fixture.create(); + + fixture.uploader.close(); + verify(fixture.s3Client, times(1)).close(); + } + + /** ObjectKey is buikld using the properties of the Batch */ + @Test + void objectLocationUsesBatchProperties() { + + var fixture = Fixture.create(); + + var location = fixture.uploader.objectLocation(BATCH); + assertThat(location.region()).as("region is same as config").isEqualTo(fixture.config.region()); + + assertThat(location.bucket()).as("bucket is same as config").isEqualTo(fixture.config.bucket()); + + assertThat(location.key()).as("key is as expected").isEqualTo(EXPECTED_KEY); + } + + /** Object body built using properties of the Batch */ + @Test + void objectContentContainsBatchLines() { + + var fixture = Fixture.create(); + + var bytes = fixture.uploader.objectContent(BATCH); + + assertThat(bytes) + .as("bytes is as expected") + .isEqualTo((LINE_A + "\n" + LINE_B + "\n").getBytes(StandardCharsets.UTF_8)); + } + + /** Request to S3 clent matches the batch and config properties */ + @Test + void uploadUsesCorrectBatchProperties() { + var fixture = Fixture.create(); + + fixture.uploader.upload(BATCH); + + var requestCaptor = ArgumentCaptor.forClass(PutObjectRequest.class); + var bodyCaptor = ArgumentCaptor.forClass(AsyncRequestBody.class); + verify(fixture.s3Client, times(1)).putObject(requestCaptor.capture(), bodyCaptor.capture()); + + var request = requestCaptor.getValue(); + assertThat(request.bucket()).as("bucket is same as config").isEqualTo(fixture.config.bucket()); + assertThat(request.key()).as("key is as expected").isEqualTo(EXPECTED_KEY); + assertThat(request.contentType()) + .as("content type is as expected") + .isEqualTo(S3BatchedLogUploader.CONTENT_TYPE_NDJSON); + + var body = bodyCaptor.getValue(); + assertThat(body.contentLength()).as("content length matches batch").hasValue(BATCH.bytes()); + } + + /** Multiple calls to upload generate different keys, each matching batch properties */ + @Test + void uploadGeneratesUniqueKeys() { + var fixture = Fixture.create(); + + // second batch we will send, has diff Id and 1 hour later. + var oldestEvent2 = OLDEST_EVENT_AT.plus(1, ChronoUnit.HOURS); + var batch2 = + new BatchedLogBuffer.Batch( + BatchedLogBuffer.BillingBatchReason.MAX_BYTES_EXCEEDED, + BATCH.lines(), + LINE_BYTE_SIZE, + oldestEvent2); + + fixture.uploader.upload(BATCH); + fixture.uploader.upload(batch2); + + var requestCaptor = ArgumentCaptor.forClass(PutObjectRequest.class); + var bodyCaptor = ArgumentCaptor.forClass(AsyncRequestBody.class); + verify(fixture.s3Client, times(2)).putObject(requestCaptor.capture(), bodyCaptor.capture()); + + var requests = requestCaptor.getAllValues(); + + assertThat(requests.stream().map(PutObjectRequest::key)) + .as("all put requests keys are unique") + .doesNotHaveDuplicates(); + + assertThat(requests.getFirst().key()).as("key for batch 1 as expected").isEqualTo(EXPECTED_KEY); + + var expectedKey2 = "data-api/2026/05/20/17/23/%s.jsonl".formatted(batch2.id()); + assertThat(requests.get(1).key()).as("key for batch 2 as expected").isEqualTo(expectedKey2); + } + + @Test + void uploadS3FailureReturned() { + + var fixture = Fixture.create(); + var expectedThrowable = new RuntimeException("S3 Failed"); + when(fixture.s3Client.putObject(any(PutObjectRequest.class), any(AsyncRequestBody.class))) + .thenReturn(CompletableFuture.failedFuture(expectedThrowable)); + + var uploadResult = fixture.uploader.upload(BATCH).await().atMost(Duration.ofSeconds(10)); + + verify( + fixture.s3Client, + times(1) + .description("s3Client upload() called once, all retry is internal to s3 client")) + .putObject(any(PutObjectRequest.class), any(AsyncRequestBody.class)); + + assertThat(uploadResult).isNotNull(); + assertThat(uploadResult.throwable()) + .as("uploadResult has expected throwable instance") + .isSameAs(expectedThrowable); + assertThat(uploadResult.batch()).as("uploadResult has expected batch instance").isSameAs(BATCH); + } + + @Test + void uploadS3SuccessReturned() { + + var fixture = Fixture.create(); + + var uploadResult = fixture.uploader.upload(BATCH).await().atMost(Duration.ofSeconds(10)); + + verify( + fixture.s3Client, + times(1) + .description("s3Client upload() called once, all retry is internal to s3 client")) + .putObject(any(PutObjectRequest.class), any(AsyncRequestBody.class)); + + assertThat(uploadResult).isNotNull(); + assertThat(uploadResult.throwable()).as("uploadResult throwable is null when success").isNull(); + assertThat(uploadResult.batch()).as("uploadResult has expected batch instance").isSameAs(BATCH); + } + + // ============================================================ + // Scaffold + // ============================================================ + + private record Fixture( + S3BatchedLogUploader uploader, + S3AsyncClient s3Client, + PutObjectResponse putResponse, + BatchedLogUploaderMetrics metrics, + BillingS3UploadConfig config) { + + static Fixture create() { + return create(false); + } + + static Fixture create(boolean useFactory) { + + var config = + new SmallRyeConfigBuilder() + .withMapping(BillingS3UploadConfig.class) + .build() + .getConfigMapping(BillingS3UploadConfig.class); + + var metrics = mock(BatchedLogUploaderMetrics.class); + + var s3Client = mock(S3AsyncClient.class); + + var sdkResponse = SdkHttpResponse.builder().statusCode(200).build(); + var builder = PutObjectResponse.builder(); + // sdkHttpResponse is on an inherited builder, return type changes + builder.sdkHttpResponse(sdkResponse); + var putResponse = builder.build(); + + when(s3Client.putObject(any(PutObjectRequest.class), any(AsyncRequestBody.class))) + .thenReturn(CompletableFuture.completedFuture(putResponse)); + + S3BatchedLogUploader uploader; + if (useFactory) { + uploader = + S3BatchedLogUploader.create( + config.region(), + config.bucket(), + config.endpointOverride().orElse(null), + config.s3PathPrefix(), + config.s3CallAttemptTimeout(), + config.s3TotalCallTimeout(), + config.s3RetryMode(), + metrics); + } else { + uploader = + new S3BatchedLogUploader( + s3Client, config.region(), config.bucket(), config.s3PathPrefix(), metrics); + } + + return new Fixture(uploader, s3Client, putResponse, metrics, config); + } + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/testresource/S3MockTestResource.java b/src/test/java/io/stargate/sgv2/jsonapi/testresource/S3MockTestResource.java new file mode 100644 index 0000000000..8ac254e887 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/testresource/S3MockTestResource.java @@ -0,0 +1,112 @@ +package io.stargate.sgv2.jsonapi.testresource; + +import static io.stargate.sgv2.jsonapi.util.SmallRyeConfigTestUtil.addPropertyTo; + +import com.adobe.testing.s3mock.testcontainers.S3MockContainer; +import io.quarkus.test.common.QuarkusTestResourceLifecycleManager; +import io.stargate.sgv2.jsonapi.config.BillingS3UploadConfig; +import java.util.HashMap; +import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * Starts an S3Mock container (https://github.com/adobe/S3Mock) and configures billing to send + * events with short pauses. + */ +public class S3MockTestResource implements QuarkusTestResourceLifecycleManager { + + private static final Logger LOGGER = LoggerFactory.getLogger(S3MockTestResource.class); + + /** Container tag; keep in sync with the {@code s3mock-testcontainers} version in pom.xml. */ + private static final String S3MOCK_VERSION = "5.1.0"; + + public static final String BUCKET = "billing-events-it"; + public static final String REGION = "us-east-1"; + public static final String ACCESS_KEY = "s3mock-test"; + public static final String SECRET_KEY = "s3mock-test"; + + private static volatile String httpEndpoint; + + private static volatile S3MockContainer container; + + /** + * HTTP endpoint of the running S3Mock, for the test-side verification client. + * + *

... + */ + public static String endpoint() { + if (httpEndpoint == null) { + throw new IllegalStateException("S3MockTestResource has not been started"); + } + return httpEndpoint; + } + + /** + * Stops the S3Mock container, leaving nothing listening on the exported endpoint: every upload + * from then on fails with connection-refused. + */ + public static void stopContainer() { + if (container == null) { + throw new IllegalStateException("S3MockTestResource has not been started"); + } + container.stop(); + } + + @Override + public Map start() { + + LOGGER.info( + "start() - starting S3MockContainer. S3MOCK_VERSION:{}, BUCKET:{}", S3MOCK_VERSION, BUCKET); + container = new S3MockContainer(S3MOCK_VERSION).withInitialBuckets(BUCKET); + container.start(); + httpEndpoint = container.getHttpEndpoint(); + LOGGER.info( + "start() - S3MockContainer started, httpEndpoint:{}, container:{}", + httpEndpoint, + container); + + // Building the config properties for the S3 billing component, these will + // override whatever is it the test source tree, and enable S3 push with the + // config we need for testing + Map props = new HashMap<>(); + + // Enable Billing events at the feature flag level + // there is no direct property for this. + props.put("stargate.feature.flags.billing-events-logging", "true"); + + addPropertyTo(props, BillingS3UploadConfig::enabled, true); + addPropertyTo(props, BillingS3UploadConfig::region, REGION); + addPropertyTo(props, BillingS3UploadConfig::bucket, BUCKET); + addPropertyTo(props, BillingS3UploadConfig::endpointOverride, httpEndpoint); + + // reducing the buffer so we get events sent more frequently + addPropertyTo(props, BillingS3UploadConfig::bufferMaxBatchSize, 2); + addPropertyTo(props, BillingS3UploadConfig::bufferMaxBatchBytes, 1024); + addPropertyTo(props, BillingS3UploadConfig::bufferMaxBatchAge, "PT2S"); // 2 seconds + + // config the handler to wake up more often and be more aggressive in shutdown + // wake up every 2 seconds to check the buffer + addPropertyTo(props, BillingS3UploadConfig::handlerSleepDuration, "PT2S"); // 2 seconds + + // The uploader resolves credentials from the SDK default chain, whose first stop is the + // system-property provider. S3Mock accepts any signed request. + props.put("aws.accessKeyId", ACCESS_KEY); + props.put("aws.secretAccessKey", SECRET_KEY); + + props.forEach(System::setProperty); + LOGGER.info("start() - overridden properties for billing and S3. props:{}", props); + return props; + } + + @Override + public void stop() { + if (container != null) { + LOGGER.info("stop() - stopping container. container:{}", container); + container.stop(); + LOGGER.info("stop() - stopped container. container:{}", container); + } else { + LOGGER.info("stop() - container not running, nothing to do"); + } + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/util/ApiFeaturesTestUtil.java b/src/test/java/io/stargate/sgv2/jsonapi/util/ApiFeaturesTestUtil.java new file mode 100644 index 0000000000..b3ece42433 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/util/ApiFeaturesTestUtil.java @@ -0,0 +1,59 @@ +package io.stargate.sgv2.jsonapi.util; + +import io.stargate.sgv2.jsonapi.api.request.RequestContext; +import io.stargate.sgv2.jsonapi.config.feature.ApiFeature; +import io.stargate.sgv2.jsonapi.config.feature.ApiFeatures; +import io.vertx.core.MultiMap; +import java.util.Collections; +import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * Helpers for writing tests that use {@link io.stargate.sgv2.jsonapi.config.feature.ApiFeatures} + */ +public class ApiFeaturesTestUtil { + + private static final Logger LOGGER = LoggerFactory.getLogger(ApiFeaturesTestUtil.class); + + /** See {@link #withFeature(ApiFeature, Boolean, Boolean)} */ + public static ApiFeatures withFeature(ApiFeature feature, Boolean configEnabled) { + return ApiFeaturesTestUtil.withFeature(feature, configEnabled, null); + } + + /** + * Create a {@link ApiFeatures} that has either or both of the provided APIFeature specified by + * config or the header. + * + *

Example usage: + * + *

{@code
+   * ApiFeatures features = ApiFeaturesTestUtil.withFeature(
+   *       ApiFeature.BILLING_EVENTS_LOGGING, configEnabled, headerEnabled);
+   *
+   * }
+ * + * @param feature The {@link ApiFeature} we want to set value for + * @param configEnabled If the feature should be set via config, if null is ignored. + * @param headerEnabled If the feature should be set via HTTP Header, if null is ignored. + * @return Configured {@link ApiFeatures} + */ + public static ApiFeatures withFeature( + ApiFeature feature, Boolean configEnabled, Boolean headerEnabled) { + + Map flags = + configEnabled == null + ? Collections.emptyMap() + : Map.of(feature, String.valueOf(configEnabled)); + + RequestContext.HttpHeaderAccess headers = null; + if (headerEnabled != null) { + var rawHeaders = MultiMap.caseInsensitiveMultiMap(); + rawHeaders.add(feature.httpHeaderName(), String.valueOf(headerEnabled)); + headers = new RequestContext.HttpHeaderAccess(rawHeaders); + } + + LOGGER.debug("withFeature() - created APIFeatures. flags:{}, headers:{}", flags, headers); + return ApiFeatures.fromConfigAndRequest(flags, headers); + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsITAssertions.java b/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsITAssertions.java new file mode 100644 index 0000000000..3207455292 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsITAssertions.java @@ -0,0 +1,111 @@ +package io.stargate.sgv2.jsonapi.util; + +import static io.restassured.RestAssured.given; +import static org.assertj.core.api.Assertions.assertThat; +import static org.awaitility.Awaitility.await; + +import io.micrometer.core.instrument.Meter; +import java.time.Duration; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.function.Consumer; +import org.assertj.core.api.AbstractDoubleAssert; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** Assertions for working with metrics in **Integration Tests**. */ +public class MetricsITAssertions { + + private static final Logger LOGGER = LoggerFactory.getLogger(MetricsITAssertions.class); + + public static final Duration DEFAULT_AWAIT_DURATION = Duration.ofSeconds(60); + public static final Duration DEFAULT_POLL_DURATION = Duration.ofSeconds(2); + + /** + * Assert the metric sum is equal to metricValue + * + *

Example: + * + *

{@code
+   * assertMetricTotal("billing.s3.uploaded.events", 10);
+   * }
+ */ + public static void assertMetricTotal(String metricName, double metricValue) { + assertMetricTotal(metricName, metricValue, DEFAULT_AWAIT_DURATION, DEFAULT_POLL_DURATION); + } + + /** + * Example: + * + *
{@code
+   * assertMetricTotal("billing.s3.uploaded.events", (a) -> a.isGreaterThanOrEqualTo(10));
+   * }
+ */ + public static void assertMetricTotal( + String metricName, Consumer> assertConsumer) { + assertMetricTotal(metricName, assertConsumer, DEFAULT_AWAIT_DURATION, DEFAULT_POLL_DURATION); + } + + /** Assert the metric sum is equal to metricValue, using supplied timeouts */ + public static void assertMetricTotal( + String metricName, double metricValue, Duration awaitDuration, Duration pollInterval) { + assertMetricTotal(metricName, (a) -> a.isEqualTo(metricValue), awaitDuration, pollInterval); + } + + /** Assert the summ of the metric (across all tag values) using the assertConsumer */ + public static void assertMetricTotal( + String metricName, + Consumer> assertConsumer, + Duration awaitDuration, + Duration pollInterval) { + await() + .atMost(awaitDuration) + .pollInterval(pollInterval) + .untilAsserted( + () -> { + var asserts = + assertThat(metricTotal(metricName)) + .as("assertMetricTotal() - for metric " + metricName); + assertConsumer.accept(asserts); + }); + } + + public static double metricTotal(Meter.Id meterId) { + return metricTotal(meterId.getName()); + } + + public static double meterTotal(Meter meter) { + return metricTotal(meter.getId()); + } + + /** + * Sum across all tag combinations + * + * @param metricName name of the metric to read + * @return sum of the counter, 0 if the counter is not found. + */ + public static double metricTotal(String metricName) { + + // e.g. line on /metrics + // # TYPE billing_s3_uploaded_events counter + // # HELP billing_s3_uploaded_events + // billing_s3_uploaded_events_total{module="sgv2-jsonapi"} 30.0 + var metricLines = given().when().get("/metrics").then().statusCode(200).extract().asString(); + + AtomicBoolean foundOne = new AtomicBoolean(false); + var normalizedMetricName = metricName.replace(".", "_"); + var total = + metricLines + .lines() + .filter(line -> line.startsWith(normalizedMetricName)) + .peek(ignored -> foundOne.set(true)) + .mapToDouble(line -> Double.parseDouble(line.substring(line.lastIndexOf(' ') + 1))) + .sum(); + + assertThat(foundOne.get()) + .as("Metric not found. normalizedMetricName:" + normalizedMetricName) + .isTrue(); + + LOGGER.info("metricTotal() - normalizedMetricName: {}, total: {}", normalizedMetricName, total); + return total; + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsUnitAssertions.java b/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsUnitAssertions.java new file mode 100644 index 0000000000..fdf39f1e82 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/util/MetricsUnitAssertions.java @@ -0,0 +1,105 @@ +package io.stargate.sgv2.jsonapi.util; + +import static org.assertj.core.api.Assertions.assertThat; + +import io.micrometer.core.instrument.*; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import java.util.HashMap; +import java.util.Map; +import java.util.Objects; +import java.util.function.Consumer; +import org.assertj.core.api.AbstractDoubleAssert; + +/** + * Assertions for working with metrics in **Unit Tests**. + * + *

Create a single instance for each test, and then use the assertion methods to check metric + * values. + * + *

NOTE: because metrics like a {@link Counter} can only be increased, and the only way to + * reset the metric values is to destroy and re-creat. Use the {@link MetricSnapshot} created with + * {@link #createSnapshot()} to assert that a metric has changed a certain amount *since* the + * snapshot was taken. + */ +public class MetricsUnitAssertions { + + private final MeterRegistry meterRegistry; + + public MetricsUnitAssertions() { + this(new SimpleMeterRegistry()); + } + + public MetricsUnitAssertions(MeterRegistry meterRegistry) { + this.meterRegistry = Objects.requireNonNull(meterRegistry, "meterRegistry is null"); + } + + public MeterRegistry registry() { + return meterRegistry; + } + + public MetricSnapshot createSnapshot() { + + Map values = new HashMap<>(); + for (Meter meter : meterRegistry.getMeters()) { + switch (meter) { + case Counter counter -> values.put(meter.getId(), counter.count()); + case Gauge gauge -> values.put(meter.getId(), gauge.value()); + case Timer timer -> values.put(meter.getId(), (double) timer.count()); + case DistributionSummary summary -> values.put(meter.getId(), (double) summary.count()); + default -> {} + } + } + return new MetricSnapshot(values); + } + + /** Assert the value of the first metric with this name and tags is specified value */ + public void assertMetric(Meter metric, double metricValue) { + assertMetric(null, metric, metricValue); + } + + /** + * Assert the value of the first metric with this name and tags is specified value plus the value + * the metric has in the snapshot + */ + public void assertMetric(MetricSnapshot snapshot, Meter metric, double metricValue) { + + var valueAndSnapshot = snapshot == null ? metricValue : snapshot.value(metric) + metricValue; + assertMetric(metric, (a) -> a.isEqualTo(valueAndSnapshot)); + } + + public void assertMetric(Meter metric, Consumer> assertConsumer) { + + var id = metric.getId(); + var registeredMeter = registry().find(id.getName()).tags(id.getTags()).meter(); + assertThat(registeredMeter) + .as("assertMetricEqual()- meter is registered. id:" + id) + .isNotNull(); + + AbstractDoubleAssert asserts = + switch (registeredMeter) { + case Counter c -> assertThat(c.count()); + case Gauge g -> assertThat(g.value()); + case Timer t -> assertThat((double) t.count()); + default -> + throw new IllegalArgumentException( + "Unknown meter type. id:%s, class:%s".formatted(id, registeredMeter.getClass())); + }; + + var assertsWithDesc = asserts.as("assertMetricEqual()- metric id:" + id); + assertConsumer.accept(assertsWithDesc); + } + + public record MetricSnapshot(Map values) { + + public double value(Meter meter) { + return value(meter.getId()); + } + + public double value(Meter.Id meterId) { + if (values.containsKey(meterId)) { + return values.get(meterId); + } + throw new IllegalArgumentException("Unknown meter id:" + meterId); + } + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/util/MockClock.java b/src/test/java/io/stargate/sgv2/jsonapi/util/MockClock.java new file mode 100644 index 0000000000..a08e4baa0b --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/util/MockClock.java @@ -0,0 +1,62 @@ +package io.stargate.sgv2.jsonapi.util; + +import java.time.*; +import java.util.concurrent.atomic.AtomicReference; + +/** Implementation of the Java Clock that can be used to control time for time dependant tests. */ +public class MockClock extends Clock { + private final Instant startedAt; + private final AtomicReference now; + private final ZoneId zone; + + public MockClock() { + this(Instant.now(), ZoneId.systemDefault()); + } + + public MockClock(MockClock other) { + this(other.startedAt, other.zone); + } + + private MockClock(Instant now, ZoneId zone) { + this.now = new AtomicReference<>(now); + this.startedAt = now; + this.zone = zone; + } + + public Instant startedAt() { + return startedAt; + } + + public MockClock nextSecond() { + return addSeconds(1); + } + + public MockClock addSeconds(int seconds) { + return advance(Duration.ofSeconds(seconds)); + } + + public MockClock advance(Duration amount) { + now.updateAndGet(current -> current.plus(amount)); + return this; + } + + public MockClock setInstant(Instant instant) { + now.set(instant); + return this; + } + + @Override + public ZoneId getZone() { + return zone; + } + + @Override + public Clock withZone(ZoneId zone) { + return new MockClock(now.get(), zone); + } + + @Override + public Instant instant() { + return now.get(); + } +} diff --git a/src/test/java/io/stargate/sgv2/jsonapi/util/SmallRyeConfigTestUtil.java b/src/test/java/io/stargate/sgv2/jsonapi/util/SmallRyeConfigTestUtil.java new file mode 100644 index 0000000000..5a1e8478d8 --- /dev/null +++ b/src/test/java/io/stargate/sgv2/jsonapi/util/SmallRyeConfigTestUtil.java @@ -0,0 +1,163 @@ +package io.stargate.sgv2.jsonapi.util; + +import io.smallrye.config.ConfigMapping; +import io.smallrye.config.WithName; +import io.smallrye.config.WithParentName; +import io.smallrye.config.common.utils.StringUtil; +import java.io.Serializable; +import java.lang.invoke.SerializedLambda; +import java.lang.reflect.Method; +import java.util.Map; +import java.util.Objects; +import java.util.function.Function; + +/** + * Utils for working with SmallRye config classes in tests, mostly so we can use method references + * that the compiler can detect if they are invalid rather than string names for metrics. + * + *

See {@link #propertyName(ConfigMethodRef)} and {@link #addPropertyTo(Map, ConfigMethodRef, + * String)} + */ +public final class SmallRyeConfigTestUtil { + + /** + * Functional interface to represent a method on a SmallRye config interface. + * + *

{@link Serializable} is required, the java compiler only emits the synthetic + * writeReplace() function for a lambda whose target type is serializable. + * + *

Used with {@link #propertyName(ConfigMethodRef)} , the T type param is the instance that + * would be passed if the Function was evaluated. This is why it's a Function not a Supplier even + * though the Config function takes no params. + * + *

+   *      SmallRyeConfigUtil.propertyName(MyConfigInterface::host);
+   *  
+ * + * @param Type of the object that would be this if the function was invoked. + * @param Type of the return from the function + */ + @FunctionalInterface + public interface ConfigMethodRef extends Function, Serializable {} + + /** + * Gets the string name for this config mapping method, so it can be used in tests without using + * string consts. + * + *

You will probably want to use {@link #addPropertyTo(Map, ConfigMethodRef, String)} + * + *

Example, given this config: + * + *

{@code
+   * @ConfigMapping(prefix = "stargate.jsonapi.billing")
+   * public interface BillingConfig {
+   *     @WithDefault("serverless")
+   *     String product();
+   *  }
+   *
+   * }
+ * + * Invoked using: + * + *
{@code
+   * SmallRyeConfigUtil.propertyName(BillingConfig::product);
+   *
+   * }
+ * + * Will return the string: + * + *
{@code
+   * stargate.jsonapi.billing.product
+   *
+   * }
+ */ + public static String propertyName(ConfigMethodRef methodRef) { + + var configMethod = configMethod(methodRef); + // e.g. get the ConfigMapping instance from: + // @ConfigMapping(prefix = "stargate.jsonapi.billing") + // public interface BillingConfig { + var configMappingAnnotation = + configMethod.getDeclaringClass().getAnnotation(ConfigMapping.class); + + // pulls the "stargate.jsonapi.billing" from above example + var propertyNameBuilder = new StringBuilder(configMappingAnnotation.prefix()); + + if (!configMethod.isAnnotationPresent(WithParentName.class)) { + if (!propertyNameBuilder.isEmpty()) { + propertyNameBuilder.append('.'); + } + propertyNameBuilder.append( + propertyNameSegment(configMethod, configMappingAnnotation.namingStrategy())); + } + return propertyNameBuilder.toString(); + } + + /** + * Helper method to add the property name and value to the map, when you need to build a map of + * config for overriding in a test. + * + *

Example usage: + * + *

{@code
+   * Map props = new HashMap<>();
+   * addPropertyTo(props, BillingS3UploadConfig::enabled, true);
+   * addPropertyTo(props, BillingS3UploadConfig::region, REGION);
+   * addPropertyTo(props, BillingS3UploadConfig::bucket, BUCKET);
+   *
+   * }
+ */ + public static void addPropertyTo( + Map props, ConfigMethodRef methodRef, String value) { + props.put(propertyName(methodRef), value); + } + + public static void addPropertyTo( + Map props, ConfigMethodRef methodRef, int value) { + addPropertyTo(props, methodRef, Integer.toString(value)); + } + + public static void addPropertyTo( + Map props, ConfigMethodRef methodRef, boolean value) { + addPropertyTo(props, methodRef, Boolean.toString(value)); + } + + private static String propertyNameSegment( + Method configMethod, ConfigMapping.NamingStrategy namingStrategy) { + + // check if it is using a different name in config than the name of the method + WithName withName = configMethod.getAnnotation(WithName.class); + if (withName != null) { + return withName.value(); + } + + return switch (namingStrategy) { + case VERBATIM -> configMethod.getName(); + // skewer() is the same function SmallRye uses internally to derive the segment. + case SNAKE_CASE -> StringUtil.skewer(configMethod.getName()).replace('-', '_'); + case KEBAB_CASE -> StringUtil.skewer(configMethod.getName()); + }; + } + + /** Gets the standard {@link Method} that the Function object is pointing to. */ + private static Method configMethod(ConfigMethodRef methodRef) { + + Objects.requireNonNull(methodRef, "methodRef must not be null"); + + try { + // writeReplace() is generated by javac on the lambda class, private and undeclared + // in any source code; it returns the SerializedLambda holding the referenced + // method's owner and name. + Method writeReplace = methodRef.getClass().getDeclaredMethod("writeReplace"); + writeReplace.setAccessible(true); + SerializedLambda serializedLambda = (SerializedLambda) writeReplace.invoke(methodRef); + // getImplClass() returns the class-file form with slashes, e.g. "com/example/Server", + // so convert it to the binary name "com.example.Server" that Class.forName expects. + + Class configInterface = Class.forName(serializedLambda.getImplClass().replace('/', '.')); + return configInterface.getMethod(serializedLambda.getImplMethodName()); + } catch (ReflectiveOperationException e) { + throw new IllegalStateException(e); + } + } +}