diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java index 4333d8d04ea4..5401e5951c89 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java @@ -4,11 +4,17 @@ import com.dotcms.auth.providers.jwt.services.JsonWebTokenAuthCredentialProcessorImpl; import com.dotcms.cdi.CDIUtils; import com.dotcms.cost.RequestPrices.Price; +import com.dotcms.enterprise.cluster.ClusterFactory; import com.dotmarketing.util.Config; +import com.dotmarketing.util.ConfigUtils; import com.dotmarketing.util.Logger; +import com.dotmarketing.util.UtilMethods; import com.liferay.portal.model.User; import com.liferay.portal.util.PortalUtil; +import io.vavr.control.Try; import java.lang.reflect.Method; +import java.time.Instant; +import java.time.temporal.ChronoUnit; import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -43,6 +49,7 @@ public class RequestCostApiImpl implements RequestCostApi { private double requestCostDenominator = 1.0d; private final LeakyTokenBucket bucket = CDIUtils.getBeanThrows(LeakyTokenBucket.class); + private final RequestCostPublisher publisher = CDIUtils.getBeanThrows(RequestCostPublisher.class); public RequestCostApiImpl() { enableForTests = Optional.empty(); @@ -56,7 +63,10 @@ public RequestCostApiImpl(Boolean enable) { @PostConstruct public void init() { this.requestCostTimeWindowSeconds = Config.getIntProperty("REQUEST_COST_TIME_WINDOW_SECONDS", 60); - this.requestCostDenominator = Config.getFloatProperty("REQUEST_COST_DENOMINATOR", 1.0f); + // Clamp to >= 1.0 so a misconfigured 0 doesn't produce Infinity/NaN in the snapshot — + // those serialize as JSON-invalid literals and break strict parsers on the collector side. + this.requestCostDenominator = Math.max(1.0d, + Config.getFloatProperty("REQUEST_COST_DENOMINATOR", 1.0f)); this.scheduler = Executors.newSingleThreadScheduledExecutor( r -> { @@ -71,42 +81,70 @@ public void init() { } private volatile boolean skipZeroRequests = false; + + private static String nullSafe(final String value) { + return UtilMethods.isSet(value) ? value : "unknown"; + } + private void logRequestCost() { try { if (!isAccountingEnabled()) { return; } - long totalRequestsForDuration = this.requestCountForWindow.sumThenReset(); - double totalCostForDuration = this.requestCostForWindow.sumThenReset() / getRequestCostDenominator(); - double costPerRequestForDuration = totalRequestsForDuration == 0 + // The four counter reads below are not atomic relative to each other. Increments + // landing between them are counted in the next window's snapshot but already in + // the lifetime totals — Σ(window) can briefly trail lifetime by a few requests. + // Intentional: observational telemetry, atomic snapshot would need a lock. + final long totalRequestsForDuration = this.requestCountForWindow.sumThenReset(); + final double totalCostForDuration = this.requestCostForWindow.sumThenReset() / getRequestCostDenominator(); + final double costPerRequestForDuration = totalRequestsForDuration == 0 ? 0 : totalCostForDuration / totalRequestsForDuration; - if (totalRequestsForDuration == 0 && skipZeroRequests) { - return; - } - skipZeroRequests = totalRequestsForDuration == 0; - - long totalRequestsTotal = requestCountTotal.longValue(); - double totalCostTotal = requestCostTotal.longValue() / getRequestCostDenominator(); - double costPerRequestTotal = totalRequestsTotal == 0 + final long totalRequestsTotal = requestCountTotal.longValue(); + final double totalCostTotal = requestCostTotal.longValue() / getRequestCostDenominator(); + final double costPerRequestTotal = totalRequestsTotal == 0 ? 0 : totalCostTotal / totalRequestsTotal; + // The log line is throttled on consecutive idle windows so dev consoles stay quiet. + // The publisher is NOT throttled — telemetry must emit a point every tick so an idle + // cluster and a downed cluster are distinguishable on the receiving side. + final boolean idleWindow = totalRequestsForDuration == 0; + final boolean suppressLog = idleWindow && skipZeroRequests; + skipZeroRequests = idleWindow; + + if (!suppressLog) { + Logger.info("REQUEST TOKEN MONITOR >", + String.format( + "Last %ds: Reqs: %d, Tokens: %.2f, Avg Tokens: %.2f | Totals: Reqs: %d, Tokens: %.2f, Avg Tokens: %.2f", + requestCostTimeWindowSeconds, + totalRequestsForDuration, + totalCostForDuration, + costPerRequestForDuration, + totalRequestsTotal, + totalCostTotal, + costPerRequestTotal)); + } - Logger.info("REQUEST COST MONITOR >", - String.format( - "Last %ds: Reqs: %d, Cost: %.2f, Avg Cost: %.2f | Totals: Reqs: %d, Cost: %.2f, Avg Cost: %.2f", - requestCostTimeWindowSeconds, - totalRequestsForDuration, - totalCostForDuration, - costPerRequestForDuration, - totalRequestsTotal, - totalCostTotal, - costPerRequestTotal)); + if (publisher.isEnabled()) { + publisher.publish(new RequestCostSnapshot( + // Try.getOrElse only fires on throw — also coalesce null returns since + // these lookups can transiently return null during early startup. + nullSafe(Try.of(ClusterFactory::getClusterId).getOrNull()), + nullSafe(Try.of(ConfigUtils::getServerId).getOrNull()), + Instant.now().truncatedTo(ChronoUnit.SECONDS).toString(), + requestCostTimeWindowSeconds, + totalRequestsForDuration, + totalCostForDuration, + costPerRequestForDuration, + totalRequestsTotal, + totalCostTotal, + costPerRequestTotal)); + } } catch (Exception e) { - Logger.warnAndDebug(this.getClass(), "Error logging request cost:" + e.getMessage(), e); + Logger.warnAndDebug(this.getClass(), "Error logging request tokens:" + e.getMessage(), e); } } diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostPublisher.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostPublisher.java new file mode 100644 index 000000000000..0ee3445f0960 --- /dev/null +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostPublisher.java @@ -0,0 +1,172 @@ +package com.dotcms.cost; + +import com.dotcms.concurrent.DotConcurrentFactory; +import com.dotcms.http.CircuitBreakerUrl; +import com.dotmarketing.util.Config; +import com.dotmarketing.util.Logger; +import com.dotmarketing.util.UtilMethods; +import com.fasterxml.jackson.databind.ObjectMapper; +import java.net.URI; +import java.util.HashMap; +import java.util.Map; +import java.util.concurrent.atomic.AtomicBoolean; +import javax.enterprise.context.ApplicationScoped; + +/** + * Ships {@link RequestCostSnapshot} payloads to an external REST endpoint on each tick of + * {@link RequestCostApiImpl#logRequestCost()}. + * + *

Activates implicitly when both {@code REQUEST_COST_PUSH_URL} and + * {@code REQUEST_COST_PUSH_TOKEN} are set. Failures are rate-limited warnings and the snapshot + * is dropped — this is observational telemetry, not durable accounting.

+ * + *

Config keys: + *

+ *

+ */ +@ApplicationScoped +public class RequestCostPublisher { + + private static final ObjectMapper MAPPER = new ObjectMapper(); + private static final int FAIL_LOG_INTERVAL_MS = 10 * 60 * 1000; + private final AtomicBoolean httpSchemeWarned = new AtomicBoolean(false); + + public boolean isEnabled() { + // Use the sanitized token in the gate so a whitespace-or-CRLF-only token + // doesn't activate the publisher and cause an unauthenticated POST. + return UtilMethods.isSet(getUrl()) && UtilMethods.isSet(sanitizeHeaderValue(getToken())); + } + + private String getUrl() { + return Config.getStringProperty("REQUEST_COST_PUSH_URL", null); + } + + private String getToken() { + return Config.getStringProperty("REQUEST_COST_PUSH_TOKEN", null); + } + + private long getTimeoutMs() { + return Config.getLongProperty("REQUEST_COST_PUSH_TIMEOUT_MS", 5_000L); + } + + /** + * Submits the snapshot to {@link DotConcurrentFactory}'s default submitter so the HTTP POST + * never blocks the request-cost monitor scheduler. Returns immediately. Transport errors are + * logged at most once every 10 minutes and the snapshot is dropped. + */ + public void publish(final RequestCostSnapshot snapshot) { + if (!isEnabled()) { + return; + } + DotConcurrentFactory.getInstance().getSubmitter().submit(() -> post(snapshot)); + } + + private void post(final RequestCostSnapshot snapshot) { + final String url = getUrl(); + final String token = sanitizeHeaderValue(getToken()); + // Re-check both pieces — config may have been cleared between submit and execute, and + // posting without an Authorization header is a worse failure mode than not posting at all. + if (!UtilMethods.isSet(url) || !UtilMethods.isSet(token)) { + return; + } + warnOncePlainHttp(url); + try { + // CircuitBreakerUrl sniffs the rawData and applies Content-Type automatically when + // the payload starts with '{', so we don't set it explicitly (would risk a duplicate + // header on some Apache HttpClient versions). + final Map headers = new HashMap<>(); + headers.put("Authorization", "Bearer " + token); + + final CircuitBreakerUrl call = CircuitBreakerUrl.builder() + .setMethod(CircuitBreakerUrl.Method.POST) + .setUrl(url) + .setHeaders(headers) + .setRawData(MAPPER.writeValueAsString(snapshot)) + .setTimeout(getTimeoutMs()) + .setThrowWhenError(false) + .build(); + + call.doString(); + if (!call.isProcessed()) { + Logger.warnEvery(this.getClass(), + "REQUEST_COST_PUSH_FAIL_TRANSPORT", + "Request cost push to " + sanitizeUrlForLog(url) + " did not complete (circuit open or transport error)", + FAIL_LOG_INTERVAL_MS); + return; + } + final int response = call.response(); + if (!CircuitBreakerUrl.isSuccessResponse(response)) { + Logger.warnEvery(this.getClass(), + "REQUEST_COST_PUSH_FAIL_HTTP", + "Request cost push to " + sanitizeUrlForLog(url) + " returned HTTP " + response, + FAIL_LOG_INTERVAL_MS); + } + } catch (final Exception e) { + Logger.warnEvery(this.getClass(), + "REQUEST_COST_PUSH_ERR_EXCEPTION", + "Request cost push to " + sanitizeUrlForLog(url) + " failed: " + e.getMessage(), + FAIL_LOG_INTERVAL_MS); + Logger.debug(this.getClass(), + "Request cost push to " + sanitizeUrlForLog(url) + " failed with exception", + e); + } + } + + /** + * Warns once (per process lifetime) if the configured URL uses the plain {@code http://} + * scheme — the bearer token would otherwise traverse the wire in cleartext. Stays a warning + * rather than a refusal so a misconfiguration doesn't silently drop telemetry. + */ + private void warnOncePlainHttp(final String url) { + if (httpSchemeWarned.get()) { + return; + } + try { + final String scheme = URI.create(url).getScheme(); + if (scheme != null && scheme.equalsIgnoreCase("http") + && httpSchemeWarned.compareAndSet(false, true)) { + Logger.warn(this.getClass(), + "REQUEST_COST_PUSH_URL uses plain http:// — bearer token will be sent " + + "in cleartext. Use https:// for any non-loopback destination."); + } + } catch (final Exception ignored) { + // sanitizer is best-effort + } + } + + /** + * Strips CR/LF and surrounding whitespace from a header value. A misconfigured + * {@code REQUEST_COST_PUSH_TOKEN} containing CRLF would otherwise enable HTTP header + * injection — low-risk since only operators set this, but cheap to harden. + */ + static String sanitizeHeaderValue(final String value) { + return value == null ? null : value.replace("\r", "").replace("\n", "").trim(); + } + + /** + * Strips RFC-3986 userinfo (the {@code user:pass@} segment) from a URL before logging so a + * misconfigured {@code REQUEST_COST_PUSH_URL=https://user:secret@host/...} doesn't leak the + * credential into every failure log line. + */ + static String sanitizeUrlForLog(final String url) { + if (!UtilMethods.isSet(url)) { + return url; + } + try { + final URI uri = URI.create(url); + if (uri.getUserInfo() == null) { + return url; + } + final URI safe = new URI( + uri.getScheme(), null, uri.getHost(), uri.getPort(), + uri.getPath(), uri.getQuery(), uri.getFragment()); + return safe.toString(); + } catch (final Exception ignored) { + return ""; + } + } +} diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java new file mode 100644 index 000000000000..deec0addee02 --- /dev/null +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java @@ -0,0 +1,49 @@ +package com.dotcms.cost; + +import com.fasterxml.jackson.annotation.JsonAutoDetect; +import com.fasterxml.jackson.annotation.JsonAutoDetect.Visibility; + +/** + * Immutable payload shipped to the external request-cost (a.k.a. request token) collection + * endpoint on each scheduled tick. One snapshot = one point in the time series. + */ +@JsonAutoDetect( + fieldVisibility = Visibility.PUBLIC_ONLY, + getterVisibility = Visibility.NONE, + isGetterVisibility = Visibility.NONE) +public final class RequestCostSnapshot { + + public final String clusterId; + public final String serverId; + public final String timestamp; + public final int windowSeconds; + public final long windowRequests; + public final double windowTokens; + public final double windowAvgTokensPerRequest; + public final long lifetimeRequests; + public final double lifetimeTokens; + public final double lifetimeAvgTokensPerRequest; + + public RequestCostSnapshot( + final String clusterId, + final String serverId, + final String timestamp, + final int windowSeconds, + final long windowRequests, + final double windowTokens, + final double windowAvgTokensPerRequest, + final long lifetimeRequests, + final double lifetimeTokens, + final double lifetimeAvgTokensPerRequest) { + this.clusterId = clusterId; + this.serverId = serverId; + this.timestamp = timestamp; + this.windowSeconds = windowSeconds; + this.windowRequests = windowRequests; + this.windowTokens = windowTokens; + this.windowAvgTokensPerRequest = windowAvgTokensPerRequest; + this.lifetimeRequests = lifetimeRequests; + this.lifetimeTokens = lifetimeTokens; + this.lifetimeAvgTokensPerRequest = lifetimeAvgTokensPerRequest; + } +} diff --git a/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java b/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java new file mode 100644 index 000000000000..fde57fb008de --- /dev/null +++ b/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java @@ -0,0 +1,152 @@ +package com.dotcms.cost; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; + +import com.dotcms.UnitTestBase; +import com.dotmarketing.util.Config; +import org.junit.After; +import org.junit.Test; + +/** + * Unit tests for {@link RequestCostPublisher}. Focuses on the enable gate and the + * disabled-is-a-no-op guarantee. The actual HTTP POST is covered indirectly by + * {@link RequestCostSnapshotTest} (payload shape) and would need a localhost HTTP server plus + * {@code ALLOW_ACCESS_TO_PRIVATE_SUBNETS=true} set before {@code CircuitBreakerUrl}'s static + * initializer fires — not a stable unit-test surface. + */ +public class RequestCostPublisherTest extends UnitTestBase { + + private final RequestCostPublisher publisher = new RequestCostPublisher(); + + @After + public void clearConfig() { + Config.setProperty("REQUEST_COST_PUSH_URL", null); + Config.setProperty("REQUEST_COST_PUSH_TOKEN", null); + Config.setProperty("REQUEST_COST_PUSH_TIMEOUT_MS", null); + } + + private RequestCostSnapshot anySnapshot() { + return new RequestCostSnapshot( + "c", "e", "2026-05-19T00:00:00Z", + 60, 0L, 0d, 0d, 0L, 0d, 0d); + } + + @Test + public void test_isEnabled_returnsFalse_whenUrlAndTokenAreMissing() { + // Given — clearConfig in @After ensures both are null + + // When / Then + assertFalse("publisher must default to off", publisher.isEnabled()); + } + + @Test + public void test_isEnabled_returnsFalse_whenOnlyUrlIsSet() { + // Given + Config.setProperty("REQUEST_COST_PUSH_URL", "https://example.com/cost"); + + // When / Then + assertFalse("url alone must not enable the publisher", publisher.isEnabled()); + } + + @Test + public void test_isEnabled_returnsFalse_whenOnlyTokenIsSet() { + // Given + Config.setProperty("REQUEST_COST_PUSH_TOKEN", "secret"); + + // When / Then + assertFalse("token alone must not enable the publisher", publisher.isEnabled()); + } + + @Test + public void test_isEnabled_returnsTrue_whenUrlAndTokenAreBothSet() { + // Given + Config.setProperty("REQUEST_COST_PUSH_URL", "https://example.com/cost"); + Config.setProperty("REQUEST_COST_PUSH_TOKEN", "secret"); + + // When / Then + assertTrue("publisher must activate when both keys are present", publisher.isEnabled()); + } + + /** + * Regression: a token that is only CRLF / whitespace must NOT activate the publisher. + * If the gate used the raw token, isSet would return true, the publisher would activate, + * and {@code post()}'s sanitizer would strip the token to empty — resulting in an + * unauthenticated POST to the collector. Worse than staying disabled. + */ + @Test + public void test_isEnabled_returnsFalse_whenTokenIsOnlyWhitespaceOrCrlf() { + // Given + Config.setProperty("REQUEST_COST_PUSH_URL", "https://example.com/cost"); + Config.setProperty("REQUEST_COST_PUSH_TOKEN", " \r\n "); + + // When / Then + assertFalse("whitespace/CRLF-only token must not activate the publisher", + publisher.isEnabled()); + } + + @Test + public void test_publish_whenDisabled_isANoOp() { + // Given — both keys absent + + // When / Then — must not throw, must not submit anything to the executor + publisher.publish(anySnapshot()); + } + + /** + * Verifies that {@link Config#setProperty(String, Object) Config.setProperty(key, null)} + * actually unsets the property — i.e. the enable gate sees null, not the literal string + * {@code "null"}. If this ever regresses, {@link UtilMethods#isSet(Object)} would return true + * for {@code "null"} and the gate would silently flip on. + */ + @Test + public void test_clearConfig_actuallyRemovesProperties() { + // Given — both keys set then cleared + Config.setProperty("REQUEST_COST_PUSH_URL", "https://example.com/cost"); + Config.setProperty("REQUEST_COST_PUSH_TOKEN", "secret"); + Config.setProperty("REQUEST_COST_PUSH_URL", null); + Config.setProperty("REQUEST_COST_PUSH_TOKEN", null); + + // When + final String url = Config.getStringProperty("REQUEST_COST_PUSH_URL", null); + final String token = Config.getStringProperty("REQUEST_COST_PUSH_TOKEN", null); + + // Then — must be null, not the literal string "null" + assertNull("URL must be unset, not stringified", url); + assertNull("token must be unset, not stringified", token); + assertFalse("publisher must observe the cleared state", publisher.isEnabled()); + } + + @Test + public void test_sanitizeUrlForLog_stripsUserinfo() { + // Given / When + final String sanitized = RequestCostPublisher.sanitizeUrlForLog( + "https://user:secret@host.example.com/cost?x=1"); + + // Then — no credentials leak into log lines + assertEquals("https://host.example.com/cost?x=1", sanitized); + } + + @Test + public void test_sanitizeUrlForLog_passesPlainUrlThrough() { + // Given / When + final String sanitized = RequestCostPublisher.sanitizeUrlForLog( + "https://host.example.com/cost"); + + // Then + assertEquals("https://host.example.com/cost", sanitized); + } + + @Test + public void test_sanitizeHeaderValue_stripsCrlfAndTrims() { + // CRLF in a header value would otherwise enable HTTP header injection + assertEquals("legit-token", RequestCostPublisher.sanitizeHeaderValue("legit-token")); + assertEquals("legit-token", RequestCostPublisher.sanitizeHeaderValue(" legit-token ")); + assertEquals("evilXInjected: value", + RequestCostPublisher.sanitizeHeaderValue("evil\r\nXInjected: value")); + assertEquals("token", RequestCostPublisher.sanitizeHeaderValue("token\n")); + assertNull(RequestCostPublisher.sanitizeHeaderValue(null)); + } +} diff --git a/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java b/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java new file mode 100644 index 000000000000..873e60e6440a --- /dev/null +++ b/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java @@ -0,0 +1,79 @@ +package com.dotcms.cost; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertTrue; + +import com.dotcms.UnitTestBase; +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import org.junit.Test; + +/** + * Unit tests for {@link RequestCostSnapshot}. The snapshot is the on-the-wire payload, so the + * Jackson field-visibility config is the bug surface most likely to break silently — these tests + * lock the JSON shape down. + */ +public class RequestCostSnapshotTest extends UnitTestBase { + + private static final ObjectMapper MAPPER = new ObjectMapper(); + + private RequestCostSnapshot sample() { + return new RequestCostSnapshot( + "cluster-1", + "server-7", + "2026-05-19T18:48:00Z", + 60, + 1234L, + 5678.5d, + 4.6d, + 999_999L, + 12_345_678.25d, + 12.35d); + } + + @Test + public void test_serialization_includesAllExpectedFields() throws Exception { + // When + final JsonNode json = MAPPER.readTree(MAPPER.writeValueAsString(sample())); + + // Then + assertTrue("missing clusterId", json.has("clusterId")); + assertTrue("missing serverId", json.has("serverId")); + assertTrue("missing timestamp", json.has("timestamp")); + assertTrue("missing windowSeconds", json.has("windowSeconds")); + assertTrue("missing windowRequests", json.has("windowRequests")); + assertTrue("missing windowTokens", json.has("windowTokens")); + assertTrue("missing windowAvgTokensPerRequest", json.has("windowAvgTokensPerRequest")); + assertTrue("missing lifetimeRequests", json.has("lifetimeRequests")); + assertTrue("missing lifetimeTokens", json.has("lifetimeTokens")); + assertTrue("missing lifetimeAvgTokensPerRequest", json.has("lifetimeAvgTokensPerRequest")); + } + + @Test + public void test_serialization_preservesValues() throws Exception { + // When + final JsonNode json = MAPPER.readTree(MAPPER.writeValueAsString(sample())); + + // Then + assertEquals("cluster-1", json.get("clusterId").asText()); + assertEquals("server-7", json.get("serverId").asText()); + assertEquals("2026-05-19T18:48:00Z", json.get("timestamp").asText()); + assertEquals(60, json.get("windowSeconds").asInt()); + assertEquals(1234L, json.get("windowRequests").asLong()); + assertEquals(5678.5d, json.get("windowTokens").asDouble(), 0.0001d); + assertEquals(4.6d, json.get("windowAvgTokensPerRequest").asDouble(), 0.0001d); + assertEquals(999_999L, json.get("lifetimeRequests").asLong()); + assertEquals(12_345_678.25d, json.get("lifetimeTokens").asDouble(), 0.0001d); + assertEquals(12.35d, json.get("lifetimeAvgTokensPerRequest").asDouble(), 0.0001d); + } + + @Test + public void test_serialization_emitsExactlyTenFields() throws Exception { + // When + final JsonNode json = MAPPER.readTree(MAPPER.writeValueAsString(sample())); + + // Then — guard against accidental leakage of internal fields if someone adds private + // helpers later without updating the @JsonAutoDetect visibility + assertEquals("unexpected fields on the wire", 10, json.size()); + } +}