diff --git a/dotCMS/src/enterprise/java/com/dotcms/enterprise/priv/ESSearchAPIImpl.java b/dotCMS/src/enterprise/java/com/dotcms/enterprise/priv/ESSearchAPIImpl.java index a35195ef2d07..51184e072f1c 100644 --- a/dotCMS/src/enterprise/java/com/dotcms/enterprise/priv/ESSearchAPIImpl.java +++ b/dotCMS/src/enterprise/java/com/dotcms/enterprise/priv/ESSearchAPIImpl.java @@ -9,6 +9,8 @@ package com.dotcms.enterprise.priv; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.content.elasticsearch.business.ESContentFactoryImpl; import com.dotcms.content.elasticsearch.business.ESSearchResults; import com.dotcms.content.elasticsearch.business.IndiciesInfo; @@ -204,6 +206,7 @@ public SearchResponse esSearchRelated(final Contentlet contentlet, * @throws DotDataException * An error occurred when retrieving the data. */ + @RequestCost(Price.ES_QUERY) private SearchResponse esSearchRaw(JSONObject jsonObject, boolean live, User user, boolean respectFrontendRoles, int limit, int offset, String sortBy) throws DotSecurityException, DotDataException { diff --git a/dotCMS/src/main/java/com/dotcms/business/interceptor/RequestCostHandler.java b/dotCMS/src/main/java/com/dotcms/business/interceptor/RequestCostHandler.java index 04a8a4a3b25c..4fa51da1803e 100644 --- a/dotCMS/src/main/java/com/dotcms/business/interceptor/RequestCostHandler.java +++ b/dotCMS/src/main/java/com/dotcms/business/interceptor/RequestCostHandler.java @@ -32,4 +32,40 @@ public static void incrementCost(final Price price, final Method method, "Error in RequestCostHandler.incrementCost(): " + t.getMessage(), t); } } + + /** + * Increments the request cost by {@code price * times} from a call site that charges + * directly rather than through the {@code @RequestCost} annotation. + *

+ * Use this rather than calling {@code APILocator.getRequestCostAPI().incrementCost(..)} + * inline. The annotation path is protected — {@code RequestCostAdvice.enter} is declared + * {@code @Advice.OnMethodEnter(suppress = Throwable.class)} — so a failure in the cost API + * can never break the method being metered. A direct call has no such protection, and + * these charge points sit on page rendering and content loading: metering must never be + * able to take down serving. + * + * @param price the unit price + * @param clazz calling class + * @param method calling method + * @param args arguments, for the HTML accounting report + * @param times how many units of work were done + */ + public static void incrementCost(final Price price, final Class clazz, final String method, + final Object[] args, final int times) { + try { + APILocator.getRequestCostAPI().incrementCost(price, clazz, method, args, times); + } catch (Throwable t) { + Logger.warnAndDebug(RequestCostHandler.class, + "Error in RequestCostHandler.incrementCost(): " + t.getMessage(), t); + } + } + + /** + * Convenience overload charging a single unit. See + * {@link #incrementCost(Price, Class, String, Object[], int)}. + */ + public static void incrementCost(final Price price, final Class clazz, final String method, + final Object[] args) { + incrementCost(price, clazz, method, args, 1); + } } \ No newline at end of file diff --git a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ContentletIndexAPIImpl.java b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ContentletIndexAPIImpl.java index 71b311b6e70e..8adbd693e363 100644 --- a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ContentletIndexAPIImpl.java +++ b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ContentletIndexAPIImpl.java @@ -1,5 +1,7 @@ package com.dotcms.content.elasticsearch.business; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import static com.dotcms.content.index.IndexConfigHelper.haltMigration; import static com.dotcms.content.index.IndexConfigHelper.isMigrationComplete; import static com.dotcms.content.index.IndexConfigHelper.isMigrationNotStarted; @@ -2321,6 +2323,7 @@ public void stopFullReindexation() throws DotDataException { } } + @RequestCost(Price.CONTENT_INDEX) @Override public void addContentToIndex(final List contentToIndex) { diff --git a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentFactoryImpl.java b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentFactoryImpl.java index 3208210f690f..8b3a7a286d9a 100644 --- a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentFactoryImpl.java +++ b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentFactoryImpl.java @@ -42,6 +42,9 @@ import com.dotcms.variant.model.Variant; import com.dotmarketing.beans.Host; import com.dotmarketing.beans.Identifier; +import com.dotcms.business.interceptor.RequestCostHandler; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotmarketing.business.APILocator; import com.dotmarketing.business.CacheLocator; import com.dotmarketing.business.DotStateException; @@ -115,7 +118,6 @@ import java.util.Optional; import java.util.Set; import java.util.stream.Collectors; -import org.apache.commons.collections.CollectionUtils; import org.apache.commons.lang.StringUtils; /** @@ -755,6 +757,11 @@ public Optional findInDb(final String inode) { * @param ignoreStoryBlock if it is true then the StoryBlock are not hydrated * @return */ + // The cache-miss surcharge for the single-contentlet path. Reaching this method IS the + // miss - find() has already charged the CONTENT_FROM_CACHE base fee, so a warm find + // costs 1 and a cold one costs 11. Annotations are not inherited, so the @RequestCost on + // ContentletFactory's findInDb default does nothing here; this needs its own. + @RequestCost(Price.CONTENT_FROM_DB) public Optional findInDb(final String inode, final boolean ignoreStoryBlock) { try { if (inode != null) { @@ -1274,17 +1281,35 @@ public Contentlet findContentletForLanguage(long languageId, Identifier identifi @Override public List findContentlets(final List inodes) throws DotDataException { + // Single pass: the cache lookup already knows which inodes missed, so collect them here + // rather than re-deriving the difference afterwards. A hit only counts when the cached + // inode matches the requested one: the cache stores the CACHE_404_CONTENTLET sentinel + // under the requested key after a failed single-item lookup, and treating it as a hit + // would silently drop that inode from the result instead of falling through to the DB + // (the old CollectionUtils.subtract over conMap's keys had the same inode-equality + // semantics, since the sentinel's inode never matches a requested inode). final HashMap conMap = new HashMap<>(); - for (String i : inodes) { + final List missingCons = new ArrayList<>(); + for (final String i : inodes) { final Contentlet contentlet = contentletCache.get(i); - if (contentlet != null && InodeUtils.isSet(contentlet.getInode())) { - conMap.put(contentlet.getInode(), processCachedContentlet(contentlet)); + if (contentlet != null && i.equals(contentlet.getInode())) { + conMap.put(i, processCachedContentlet(contentlet)); + } else { + missingCons.add(i); } } - if (conMap.size() != inodes.size()) { - final List missingCons = new ArrayList<>( - CollectionUtils.subtract(inodes, conMap.keySet())); + // This is the bulk loader behind every search result (GraphQL, /api/content, + // /api/es/search, page render) and it bypasses ESContentletAPIImpl.find(), so nothing + // else meters it. Base fee per contentlet asked for; the cache misses pay a surcharge + // below. Note the surcharge is per missed ROW, not per SQL statement - the 200-row + // batching is our implementation detail and is deliberately not priced. + RequestCostHandler.incrementCost(Price.CONTENT_FROM_CACHE, + ESContentFactoryImpl.class, "findContentlets", new Object[]{}, inodes.size()); + + if (!missingCons.isEmpty()) { + RequestCostHandler.incrementCost(Price.CONTENT_FROM_DB, + ESContentFactoryImpl.class, "findContentlets", new Object[]{}, missingCons.size()); final String contentletBase = "select contentlet.*, contentlet_1_.owner from contentlet join inode contentlet_1_ " diff --git a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentletAPIImpl.java b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentletAPIImpl.java index 3efef9b2b695..470b52bf34ca 100644 --- a/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentletAPIImpl.java +++ b/dotCMS/src/main/java/com/dotcms/content/elasticsearch/business/ESContentletAPIImpl.java @@ -432,6 +432,8 @@ public Contentlet find(final String inode, final User user, final boolean respec * @throws DotDataException * @throws DotSecurityException */ + // Base fee for asking for one contentlet. If the factory misses cache and falls through + // to findInDb, that adds the CONTENT_FROM_DB surcharge - so warm is 1, cold is 11. @RequestCost(Price.CONTENT_FROM_CACHE) @CloseDBIfOpened @Override @@ -575,6 +577,13 @@ private Folder createFolder(final String folderPath, final Contentlet contentlet } @WrapInTransaction + // Deliberately NOT a terminal, and the stacking is intended: move() calls + // indexAPI.addContentToIndex(..) below, which reaches the annotated + // addContentToIndex(List) and adds CONTENT_INDEX on top of this CONTENT_MOVE. A move + // really does reindex, so it really should cost both. This is not the "annotating two + // methods in one chain double-charges" trap - that is about one operation being counted + // twice, this is two distinct operations each counted once. Do not remove either. + @RequestCost(Price.CONTENT_MOVE) @Override public Contentlet move(final Contentlet contentlet, final User incomingUser, final Host host, final Folder folder, @@ -5718,6 +5727,7 @@ private boolean isWorkflowInProgress(final Contentlet contentlet) { return contentlet.isWorkflowInProgress(); } + @RequestCost(Price.CONTENT_CHECKIN) private Contentlet internalCheckin(Contentlet contentlet, ContentletRelationships contentRelationships, List categories, final User incomingUser, @@ -7100,6 +7110,7 @@ public List checkout(String luceneQuery, User user, boolean respectF } @WrapInTransaction + @RequestCost(Price.CONTENT_CHECKOUT) @Override public Contentlet checkout(final String contentletInode, final User user, final boolean respectFrontendRoles) @@ -9464,6 +9475,7 @@ public Contentlet copyContentlet(final Contentlet sourceContentlet, final Host h } @WrapInTransaction + @RequestCost(Price.CONTENT_COPY) @Override @SuppressWarnings("unchecked") public Contentlet copyContentlet(final Contentlet sourceContentlet, diff --git a/dotCMS/src/main/java/com/dotcms/cost/LeakyTokenBucketImpl.java b/dotCMS/src/main/java/com/dotcms/cost/LeakyTokenBucketImpl.java index d30ee3d00f2e..f5cb63657f30 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/LeakyTokenBucketImpl.java +++ b/dotCMS/src/main/java/com/dotcms/cost/LeakyTokenBucketImpl.java @@ -66,8 +66,8 @@ public class LeakyTokenBucketImpl implements LeakyTokenBucket { LeakyTokenBucketImpl() { this( Config.getBooleanProperty("RATE_LIMIT_ENABLED", false), - Config.getLongProperty("RATE_LIMIT_REFILL_PER_SECOND", 500), - Config.getLongProperty("RATE_LIMIT_MAX_BUCKET_SIZE", 10000) + Config.getLongProperty("RATE_LIMIT_REFILL_PER_SECOND", 5000), + Config.getLongProperty("RATE_LIMIT_MAX_BUCKET_SIZE", 100000) ); } diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApi.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApi.java index 7849d05f520b..794d14560246 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApi.java +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApi.java @@ -92,6 +92,20 @@ public static Accounting fromString(String text) { */ void incrementCost(Price price, @NotNull Class clazz, @NotNull String method, @NotNull Object[] args); + /** + * Increments the cost for the current request by {@code price * times}. Used where the work + * scales with the size of a result set (e.g. loading N contentlets) and charging once would + * make a 1-row and a 1000-row response cost the same. + * + * @param price the unit price + * @param clazz calling class + * @param method calling method + * @param args arguments, for the HTML accounting report + * @param times how many units of work were done; values <= 0 are a no-op + */ + void incrementCost(Price price, @NotNull Class clazz, @NotNull String method, + @NotNull Object[] args, int times); + /** * Returns the current cost for the current request. * diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java index 5401e5951c89..3783c8c0ae51 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostApiImpl.java @@ -41,6 +41,13 @@ public class RequestCostApiImpl implements RequestCostApi { final LongAdder requestCostForWindow = new LongAdder(); private final LongAdder requestCountTotal = new LongAdder(); private final LongAdder requestCostTotal = new LongAdder(); + // Cost incurred with no HttpServletRequest on the thread: site-search reindexing, + // scheduled publishing, remote/push publishing, content indexing, embedding generation. + // This is real, billable work - it just has no request to attach to. Before these + // counters existed incrementCost returned early and the cost vanished from the totals + // entirely, so none of it reached the collector. + private final LongAdder jobCostForWindow = new LongAdder(); + private final LongAdder jobCostTotal = new LongAdder(); private final Optional enableForTests; //log an accounting every X seconds private int requestCostTimeWindowSeconds; @@ -62,11 +69,15 @@ public RequestCostApiImpl(Boolean enable) { @PostConstruct public void init() { - this.requestCostTimeWindowSeconds = Config.getIntProperty("REQUEST_COST_TIME_WINDOW_SECONDS", 60); + this.requestCostTimeWindowSeconds = Config.getIntProperty("REQUEST_COST_TIME_WINDOW_SECONDS", 300); // 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. + // Default of 10 keeps reported tokens in the range they were before the Price table + // was re-based on resource-time: internally 1 unit is now an in-memory cache read and + // one DB round trip is 10, so dividing by 10 makes a reported token ~= one DB query, + // which is roughly what a token meant under the old table. this.requestCostDenominator = Math.max(1.0d, - Config.getFloatProperty("REQUEST_COST_DENOMINATOR", 1.0f)); + Config.getFloatProperty("REQUEST_COST_DENOMINATOR", 10.0f)); this.scheduler = Executors.newSingleThreadScheduledExecutor( r -> { @@ -97,35 +108,57 @@ private void logRequestCost() { // 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(); + // Token totals are rounded to whole numbers. They were always integral while the + // denominator was 1, and a collector that has been parsing them as ints would break + // on a fractional value. The per-request averages stay fractional — they always were. + final double requestCostForDuration = Math.round( + this.requestCostForWindow.sumThenReset() / getRequestCostDenominator()); + final double jobCostForDuration = Math.round( + this.jobCostForWindow.sumThenReset() / getRequestCostDenominator()); + + // windowTokens stays request-only, exactly as it has always been. Background work + // is reported alongside it in windowJobTokens rather than folded in, so every + // field keeps a single meaning and windowTokens / windowRequests still agrees with + // windowAvgTokensPerRequest. Total cluster consumption is the sum of the two, and + // the collector is where that sum belongs. + final double totalCostForDuration = requestCostForDuration; + final double costPerRequestForDuration = totalRequestsForDuration == 0 ? 0 - : totalCostForDuration / totalRequestsForDuration; + : requestCostForDuration / totalRequestsForDuration; final long totalRequestsTotal = requestCountTotal.longValue(); - final double totalCostTotal = requestCostTotal.longValue() / getRequestCostDenominator(); + final double requestCostTotalValue = Math.round( + requestCostTotal.longValue() / getRequestCostDenominator()); + final double jobCostTotalValue = Math.round( + jobCostTotal.longValue() / getRequestCostDenominator()); + final double totalCostTotal = requestCostTotalValue; final double costPerRequestTotal = totalRequestsTotal == 0 ? 0 - : totalCostTotal / totalRequestsTotal; + : requestCostTotalValue / 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; + // An idle window is one with no requests AND no background work - a node doing + // nothing but reindexing is not idle and should still log. + final boolean idleWindow = totalRequestsForDuration == 0 && jobCostForDuration == 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", + "Last %ds: Reqs: %d, Tokens: %.2f, Avg Tokens: %.2f, Job Tokens: %.2f | Totals: Reqs: %d, Tokens: %.2f, Avg Tokens: %.2f, Job Tokens: %.2f", requestCostTimeWindowSeconds, totalRequestsForDuration, totalCostForDuration, costPerRequestForDuration, + jobCostForDuration, totalRequestsTotal, totalCostTotal, - costPerRequestTotal)); + costPerRequestTotal, + jobCostTotalValue)); } if (publisher.isEnabled()) { @@ -141,7 +174,9 @@ private void logRequestCost() { costPerRequestForDuration, totalRequestsTotal, totalCostTotal, - costPerRequestTotal)); + costPerRequestTotal, + jobCostForDuration, + jobCostTotalValue)); } } catch (Exception e) { Logger.warnAndDebug(this.getClass(), "Error logging request tokens:" + e.getMessage(), e); @@ -246,26 +281,50 @@ public void incrementCost(Price price, Method method, Object[] args) { @Override public void incrementCost(Price price, Class clazz, String method, Object[] args) { + incrementCost(price, clazz, method, args, 1); + } + + + @Override + public void incrementCost(Price price, Class clazz, String method, Object[] args, + final int times) { + if (times <= 0) { + return; + } + final int cost = price.price * times; HttpServletRequest request = HttpServletRequestThreadLocal.INSTANCE.getRequest(); if (request == null) { + // Background work - reindex, scheduled publish, push publish, embedding + // generation. It has no request to attach to, but it is still the customer's + // work and still consumes the cluster, so it is counted here rather than + // discarded. Deliberately NOT drained from the rate-limit bucket: a reindex + // must never be able to throttle live traffic into 429s. + jobCostForWindow.add(cost); + jobCostTotal.add(cost); + Logger.debug(RequestCostApiImpl.class, + () -> "REQUESTCOST job cost:" + cost + " , thread:" + Thread.currentThread().getName() + + " , method:" + clazz.getSimpleName() + "." + method); return; } Accounting accounting = resolveAccounting(request); if (accounting == Accounting.HTML) { - Map load = createAccountingEntry(price, clazz, method, args, accounting); + Map load = createAccountingEntry(cost, clazz, method, args, accounting); getAccountList(request).add(load); } - String logMessage = - "<--- REQUESTCOST price:" + price.price + " , method:" + clazz.getSimpleName() + "." + method; // log requests if a fuller accounting is enabled // Note: Cannot use lambdas with inline=true due to synthetic method access issues if (accounting.ordinal() > Accounting.HEADER.ordinal()) { - Logger.info(RequestCostAdvice.class, logMessage); + Logger.info(RequestCostAdvice.class, ()->{ + return "<--- REQUESTCOST price:" + cost + " , method:" + clazz.getSimpleName() + "." + method; + }); } else { - Logger.debug(RequestCostAdvice.class, logMessage); + Logger.debug(RequestCostAdvice.class, ()-> { + return "<--- REQUESTCOST price:" + cost + " , method:" + clazz.getSimpleName() + "." + method; + + }); } int currentCost = getRequestCost(request); if (currentCost == 0) { @@ -273,16 +332,16 @@ public void incrementCost(Price price, Class clazz, String method, Object[] args this.requestCountTotal.increment(); } - request.setAttribute(REQUEST_COST_RUNNING_TOTAL_ATTRIBUTE, currentCost + price.price); - requestCostForWindow.add(price.price); - requestCostTotal.add(price.price); - bucket.drainFromBucket(price.price); + request.setAttribute(REQUEST_COST_RUNNING_TOTAL_ATTRIBUTE, currentCost + cost); + requestCostForWindow.add(cost); + requestCostTotal.add(cost); + bucket.drainFromBucket(cost); } - private Map createAccountingEntry(Price price, Class clazz, String method, + private Map createAccountingEntry(int cost, Class clazz, String method, Object[] args, Accounting accounting) { - return Map.of(COST, price.price, METHOD, method, CLASS, clazz.getCanonicalName(), ARGS, args); + return Map.of(COST, cost, METHOD, method, CLASS, clazz.getCanonicalName(), ARGS, args); } @@ -336,8 +395,19 @@ public void addCostHeader(HttpServletRequest request, HttpServletResponse respon } Integer currentCost = getRequestCost(request); - response.setHeader(REQUEST_COST_HEADER_NAME, - String.format("%.2f", currentCost.doubleValue() / requestCostDenominator)); + // Rounded, but still formatted "%.2f": the header has always looked like "23.00" and + // has always been a whole number. Keeping both the format and the integrality means + // nothing downstream has to change when the internal Price scale moves. + // + // Floored at 1 when the request cost anything at all. Without this, any request under + // half the denominator rounds to "0.00" - at the default of 10 that is every request + // reading a single warm contentlet - and a request that did real work would report as + // free. Only a genuinely zero-cost request reports 0.00. Window and lifetime totals + // are unaffected: they sum raw units and divide once, so no resolution is lost there. + final long reported = currentCost > 0 + ? Math.max(1L, Math.round(currentCost.doubleValue() / requestCostDenominator)) + : 0L; + response.setHeader(REQUEST_COST_HEADER_NAME, String.format("%.2f", (double) reported)); } diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java b/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java index deec0addee02..a1055e49f4ac 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestCostSnapshot.java @@ -23,6 +23,22 @@ public final class RequestCostSnapshot { public final long lifetimeRequests; public final double lifetimeTokens; public final double lifetimeAvgTokensPerRequest; + /** + * Tokens consumed by work that ran outside any HTTP request — site-search reindexing, + * scheduled publishing, remote/push publishing, content indexing, embedding generation. + *

+ * Reported separately from {@code windowTokens} / {@code lifetimeTokens}, + * which remain request-only. Total cluster consumption is the sum of the two. Keeping them + * apart means every field has one meaning: {@code windowTokens} still divides by + * {@code windowRequests} to give {@code windowAvgTokensPerRequest}, which it would not if + * background work were folded in. + *

+ * Before these fields existed this cost was not merely unattributed, it was discarded — + * {@code incrementCost} returned early when no request was on the thread, so reindexing and + * scheduled publishing reached the collector as zero. + */ + public final double windowJobTokens; + public final double lifetimeJobTokens; public RequestCostSnapshot( final String clusterId, @@ -34,7 +50,9 @@ public RequestCostSnapshot( final double windowAvgTokensPerRequest, final long lifetimeRequests, final double lifetimeTokens, - final double lifetimeAvgTokensPerRequest) { + final double lifetimeAvgTokensPerRequest, + final double windowJobTokens, + final double lifetimeJobTokens) { this.clusterId = clusterId; this.serverId = serverId; this.timestamp = timestamp; @@ -45,5 +63,7 @@ public RequestCostSnapshot( this.lifetimeRequests = lifetimeRequests; this.lifetimeTokens = lifetimeTokens; this.lifetimeAvgTokensPerRequest = lifetimeAvgTokensPerRequest; + this.windowJobTokens = windowJobTokens; + this.lifetimeJobTokens = lifetimeJobTokens; } } diff --git a/dotCMS/src/main/java/com/dotcms/cost/RequestPrices.java b/dotCMS/src/main/java/com/dotcms/cost/RequestPrices.java index a64d59dcc8a4..1a00dbe1e3d5 100644 --- a/dotCMS/src/main/java/com/dotcms/cost/RequestPrices.java +++ b/dotCMS/src/main/java/com/dotcms/cost/RequestPrices.java @@ -21,35 +21,117 @@ public enum Price { TEN_THOUSAND(10000), - // PRICED ITEMS - DB_QUERY(1), + /* + * PRICED ITEMS + * + * A price is an order-of-magnitude estimate of the *resource-time* an operation + * consumes — CPU, heap, or a request thread parked on a socket. Reading from an + * in-memory cache is microseconds and is the unit; a remote HTTP call parks the + * thread for hundreds of milliseconds and is priced ~250x that. What matters is + * the ratio between tiers, not the absolute numbers. + * + * 1 in-memory cache read + * 2 per-row hydrate / small alloc + * 5 render a template fragment + * 10 parse/compile CPU-bound, or one DB round trip + * 25 one ES round trip, or a multi-query write + * 50 heavy CPU + heap (image, Tika), or a write transaction + * 100 one remote HTTP round trip + * + * Rule of thumb when adding one: what does this hold a thread (or a core, or a + * chunk of heap) for? Price that, not how important the operation feels. + * + * On why a DB query is only 10x a cache read when it is ~1000x the latency: what + * is being metered is capacity consumed *on this node*, not wall time. A query + * parks the thread and burns the cycles on Postgres, so it costs this JVM far less + * than its latency suggests. The Velocity-tenant profiles bear that out - template + * rendering dominates those requests, not the DB frames. If a node ever runs out + * of request threads before it runs out of CPU, that reasoning inverts and the DB + * and HTTP tiers should go back up. + */ + + // --- tier 1: memory reads. Deliberately near-free; these must not dominate a + // response just because it returned a lot of rows. COSTING_INIT(1), - CONTENT_FROM_CACHE(1), - CONTENT_FROM_DB(3), - CONTENT_GET_RELATED(1), - CONTENT_GET_REFERENCES(2), - CONTENT_MOVE(2), - CONTENT_COPY(2), - CONTENT_DELETE(2), - CONTENT_CHECKOUT(1), - CONTENT_CHECKIN(5), - WORKFLOW_ACTION_RUN(1), - BLOCK_EDITOR_HYDRATION(1), FILE_METADATA_FROM_CACHE(1), - FILE_METADATA_FROM_DB(2), - FILE_METADATA_GENERATE(3), - HTTP_FETCH(4), - VELOCITY_BUILD_CONTEXT(1), - VELOCITY_MERGE(3), - VELOCITY_PARSE(5), - LOGIN_USERNAME_PASS(3), - XML_FETCH_AND_PARSE(5), - XSLT_PARSE(3), - XSLT_FETCH_AND_PARSE(6), - IMAGE_FILTER_TRANSFORM(2), ES_CACHE(1), - ES_QUERY(3), - ES_COUNT(3); + + // --- tier 2: per-item work in memory (allocate, transform, hydrate one object). + VELOCITY_BUILD_CONTEXT(2), + BLOCK_EDITOR_HYDRATION(2), + + /* + * Content is priced per contentlet, in two parts: + * + * CONTENT_FROM_CACHE base fee, charged for every contentlet asked for + * CONTENT_FROM_DB surcharge, added only when we had to read it from Postgres + * + * So one contentlet costs 1 warm and 11 cold; a thousand cost 1,000 warm and 11,000 + * cold. The 10x gap is the point: caching is something customers control - through + * cacheable containers and pages, cache TTLs, and how they shape their queries - so + * it should visibly pay off in their bill. + * + * What is NOT priced is how we service a miss: batch size, query plan, how many SQL + * statements it took. That is our implementation detail and a customer cannot + * optimise against it, which is why there is no generic DB_QUERY price. The line is + * between "did this need the database" (theirs) and "how did we ask the database" + * (ours). + */ + CONTENT_FROM_CACHE(1), + + // --- tier 5-10: CPU-bound work, no I/O. + VELOCITY_MERGE(5), + VELOCITY_PARSE(10), + XSLT_PARSE(10), + // Parsing and validating an incoming GraphQL document, before a single field is + // fetched. This is the only charge that scales with the size of the *query* rather + // than the size of the result, so a deeply nested document is not free. + GRAPHQL_QUERY(10), + + // --- tier 10: one round trip to Postgres. Deliberately only 10x a cache read - + // see the note above on capacity vs latency. + // + // There is intentionally no generic DB_QUERY here. Charging per SQL statement would + // make a customer's cost depend on batch sizes and query plans they cannot see or + // change. Whether the database was needed at all is theirs to influence and IS + // priced; how many statements it took to satisfy is ours and is not. + // + // Surcharge added to CONTENT_FROM_CACHE when a contentlet had to be read from + // Postgres. Charged in ESContentFactoryImpl.findContentlets (per missed row) and on + // both findInDb variants (single-contentlet path). + CONTENT_FROM_DB(10), + FILE_METADATA_FROM_DB(10), + CONTENT_GET_REFERENCES(10), + LOGIN_USERNAME_PASS(10), + CONTENT_CHECKOUT(10), + WORKFLOW_ACTION_RUN(10), + // Recurses through ContentHelper.addRelationshipsToJSON, one DB query per level; + // a single ?depth= bump multiplies the work, so it is priced as the query it is. + CONTENT_GET_RELATED(10), + // Folder-tree walk, DB-blocked and recursive through NavResultHydrated.getChildren. + NAV_BUILD(10), + + // --- tier 25: one round trip to Elasticsearch, or a multi-query write. + ES_QUERY(25), + ES_COUNT(25), + // Blocking ES write on the request thread after every checkin. + CONTENT_INDEX(25), + CONTENT_MOVE(25), + CONTENT_COPY(25), + + // --- tier 50: heavy CPU and heap, or a write transaction spanning many queries. + // Decoding, resizing and re-encoding an image, or running Tika over a binary, + // burns a core and a large buffer for a long time - it is not a "2". + IMAGE_FILTER_TRANSFORM(50), + FILE_METADATA_GENERATE(50), + CONTENT_CHECKIN(50), + CONTENT_DELETE(50), + + // --- tier 100: outbound HTTP. The thread is parked for the whole remote + // round-trip, which is unbounded and outside our control. + HTTP_FETCH(100), + XML_FETCH_AND_PARSE(100), + XSLT_FETCH_AND_PARSE(100); final public int price; diff --git a/dotCMS/src/main/java/com/dotcms/graphql/DotGraphQLHttpServlet.java b/dotCMS/src/main/java/com/dotcms/graphql/DotGraphQLHttpServlet.java index b199368be8fd..baae5c772ed7 100644 --- a/dotCMS/src/main/java/com/dotcms/graphql/DotGraphQLHttpServlet.java +++ b/dotCMS/src/main/java/com/dotcms/graphql/DotGraphQLHttpServlet.java @@ -1,5 +1,7 @@ package com.dotcms.graphql; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.rest.api.CorsFilter; import com.dotmarketing.util.Config; import com.dotmarketing.util.Logger; @@ -74,6 +76,7 @@ protected void doOptions(final HttpServletRequest request, final HttpServletResp * @param request * @param response */ + @RequestCost(Price.GRAPHQL_QUERY) protected void handleRequest(HttpServletRequest request, HttpServletResponse response) { corsHeaders.get().forEach(response::setHeader); try { diff --git a/dotCMS/src/main/java/com/dotcms/http/CircuitBreakerUrl.java b/dotCMS/src/main/java/com/dotcms/http/CircuitBreakerUrl.java index ad8c415a0f3f..90f8515b7958 100644 --- a/dotCMS/src/main/java/com/dotcms/http/CircuitBreakerUrl.java +++ b/dotCMS/src/main/java/com/dotcms/http/CircuitBreakerUrl.java @@ -75,7 +75,7 @@ public class CircuitBreakerUrl { private static final Lazy circuitBreakerMaxConnTotal = Lazy.of(() -> Config.getIntProperty("CIRCUIT_BREAKER_MAX_CONN_TOTAL", 100)); private static final Lazy allowAccessToPrivateSubnets = - Lazy.of(() -> Config.getBooleanProperty("ALLOW_ACCESS_TO_PRIVATE_SUBNETS", false)); + Lazy.of(() -> Config.getBooleanProperty("ALLOW_ACCESS_TO_PRIVATE_SUBNETS", false)); private static final CircuitBreakerConnectionControl circuitBreakerConnectionControl = new CircuitBreakerConnectionControl(circuitBreakerMaxConnTotal.get()); diff --git a/dotCMS/src/main/java/com/dotcms/prerender/PreRenderSEOWebAPIImpl.java b/dotCMS/src/main/java/com/dotcms/prerender/PreRenderSEOWebAPIImpl.java index a5d7aebd56ce..4ba38a6c33da 100644 --- a/dotCMS/src/main/java/com/dotcms/prerender/PreRenderSEOWebAPIImpl.java +++ b/dotCMS/src/main/java/com/dotcms/prerender/PreRenderSEOWebAPIImpl.java @@ -1,5 +1,7 @@ package com.dotcms.prerender; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.concurrent.ConditionalSubmitter; import com.dotcms.concurrent.DotConcurrentFactory; import com.dotcms.security.apps.AppSecrets; @@ -256,6 +258,7 @@ private PreRenderEventHandler getEventHandler(final AppConfig appConfig) { return null; } + @RequestCost(Price.HTTP_FETCH) private boolean proxyPrerenderedPageResponse(final HttpServletRequest request, final HttpServletResponse response, final PreRenderEventHandler preRenderEventHandler, final PrerenderConfig prerenderConfig) { diff --git a/dotCMS/src/main/java/com/dotcms/rendering/velocity/directive/DotDirective.java b/dotCMS/src/main/java/com/dotcms/rendering/velocity/directive/DotDirective.java index 9391cceb27ad..df7a04311449 100644 --- a/dotCMS/src/main/java/com/dotcms/rendering/velocity/directive/DotDirective.java +++ b/dotCMS/src/main/java/com/dotcms/rendering/velocity/directive/DotDirective.java @@ -1,5 +1,8 @@ package com.dotcms.rendering.velocity.directive; +import com.dotcms.business.interceptor.RequestCostHandler; +import com.dotcms.cost.RequestPrices.Price; +import com.dotmarketing.business.APILocator; import java.io.IOException; import java.io.StringWriter; import java.io.Writer; @@ -117,6 +120,12 @@ final public boolean render(InternalContextAdapter context, Writer writer, Node } Template t = loadTemplate(context, templatePath); + // Charged here, past the getFromCache() short-circuit above, so a directive served from + // cache stays cheap. Without this every #dotParse/#parseContainer on a page is free and + // a 30-container page costs the same as a 1-container page. + RequestCostHandler.incrementCost(Price.VELOCITY_MERGE, DotDirective.class, + "render", new Object[]{templatePath}); + final Writer innerWriter = new StringWriter(); final boolean result = this.renderTemplate(context, innerWriter, t, templatePath); this.afterRender(innerWriter.toString(), arguments, context); diff --git a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityEditMode.java b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityEditMode.java index 2f59ece0ecb1..c2e85f8169d4 100644 --- a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityEditMode.java +++ b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityEditMode.java @@ -1,5 +1,7 @@ package com.dotcms.rendering.velocity.servlet; +import com.dotcms.business.interceptor.RequestCostHandler; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.rendering.velocity.events.PreviewEditParseErrorException; import com.dotcms.rendering.velocity.services.PageRenderUtil; import com.dotcms.rendering.velocity.util.VelocityUtil; @@ -62,6 +64,11 @@ public void serve(final OutputStream out) throws DotDataException, IOException, try(final Writer outStr = new BufferedWriter(new OutputStreamWriter(out))){ + // Charged at the merge itself, not on serve(): serve() also does permission + // checks and context building, and would bill a merge that never happened. + // Nested #dotParse / #parseContainer charge separately in DotDirective.render. + RequestCostHandler.incrementCost(Price.VELOCITY_MERGE, + VelocityEditMode.class, "serve", new Object[]{}); this.getTemplate(htmlPage, mode).merge(context, outStr); } catch (PreviewEditParseErrorException e) { this.processException(user, htmlPage.getName(), e); diff --git a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityLiveMode.java b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityLiveMode.java index c3d0a7bec477..54ea180384db 100644 --- a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityLiveMode.java +++ b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityLiveMode.java @@ -1,5 +1,7 @@ package com.dotcms.rendering.velocity.servlet; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import static com.dotmarketing.filters.Constants.VANITY_URL_OBJECT; import com.dotcms.api.web.HttpServletRequestThreadLocal; @@ -265,6 +267,11 @@ PageCacheParameters buildCacheParameters(final long langId, final IHTMLPage html * @param out * @param htmlPage */ + // The page's own template merge. The three call sites above are mutually exclusive + // branches, so this charges exactly once per render - and notably NOT at all when the + // page is served from the page cache, which never reaches here. Nested #dotParse / + // #parseContainer directives charge separately in DotDirective.render. + @RequestCost(Price.VELOCITY_MERGE) private void writePage(final Writer out, final IHTMLPage htmlPage) { final Context context = VelocityUtil.getInstance().getContext(request, response); this.getTemplate(htmlPage, mode).merge(context, out); diff --git a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityPreviewMode.java b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityPreviewMode.java index ab31cced2273..af9a6e567d49 100644 --- a/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityPreviewMode.java +++ b/dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityPreviewMode.java @@ -1,5 +1,7 @@ package com.dotcms.rendering.velocity.servlet; +import com.dotcms.business.interceptor.RequestCostHandler; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.rendering.velocity.events.PreviewEditParseErrorException; import com.dotcms.rendering.velocity.services.PageRenderUtil; import com.dotcms.rendering.velocity.util.VelocityUtil; @@ -69,6 +71,11 @@ public void serve(final OutputStream out) throws DotDataException, IOException, request.setAttribute("velocityContext", context); try(final Writer outStr = new BufferedWriter(new OutputStreamWriter(out))){ + // Charged at the merge itself, not on serve(): serve() also does permission + // checks and context building, and would bill a merge that never happened. + // Nested #dotParse / #parseContainer charge separately in DotDirective.render. + RequestCostHandler.incrementCost(Price.VELOCITY_MERGE, + VelocityPreviewMode.class, "serve", new Object[]{}); this.getTemplate(htmlPage, mode).merge(context, outStr); } catch (PreviewEditParseErrorException e) { this.processException(user, htmlPage.getName(), e); diff --git a/dotCMS/src/main/java/com/dotcms/rendering/velocity/viewtools/navigation/NavTool.java b/dotCMS/src/main/java/com/dotcms/rendering/velocity/viewtools/navigation/NavTool.java index 59d0b1d2fbff..ecd895463561 100644 --- a/dotCMS/src/main/java/com/dotcms/rendering/velocity/viewtools/navigation/NavTool.java +++ b/dotCMS/src/main/java/com/dotcms/rendering/velocity/viewtools/navigation/NavTool.java @@ -1,6 +1,8 @@ package com.dotcms.rendering.velocity.viewtools.navigation; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.rest.api.v1.browsertree.BrowserTreeHelper; import com.dotmarketing.beans.Host; import com.dotmarketing.beans.Identifier; @@ -86,6 +88,7 @@ protected void setItemLinkValues(NavResult nav,Link itemLink, List ch children.add(nav); } + @RequestCost(Price.NAV_BUILD) protected NavResultHydrated getNav(final Host host, String path, final long languageId, final User systemUserParam) throws DotDataException, DotSecurityException { diff --git a/dotCMS/src/main/java/com/dotcms/rest/api/v1/vtl/VTLResource.java b/dotCMS/src/main/java/com/dotcms/rest/api/v1/vtl/VTLResource.java index 02d1ab9d8eae..71dc33c83089 100644 --- a/dotCMS/src/main/java/com/dotcms/rest/api/v1/vtl/VTLResource.java +++ b/dotCMS/src/main/java/com/dotcms/rest/api/v1/vtl/VTLResource.java @@ -1,5 +1,7 @@ package com.dotcms.rest.api.v1.vtl; +import com.dotcms.cost.RequestCost; +import com.dotcms.cost.RequestPrices.Price; import com.dotcms.api.vtl.model.DotJSON; import com.dotcms.cache.DotJSONCache; import com.dotcms.cache.DotJSONCacheFactory; @@ -538,6 +540,7 @@ private Response processRequest(final HttpServletRequest request, final HttpServ } } + @RequestCost(Price.VELOCITY_MERGE) private Response evalVelocity(final HttpServletRequest request, final HttpServletResponse response, final Reader velocityReader, final Map contextParams, final User user, final DotJSONCache cache) diff --git a/dotCMS/src/main/java/com/dotmarketing/portlets/contentlet/business/ContentletFactory.java b/dotCMS/src/main/java/com/dotmarketing/portlets/contentlet/business/ContentletFactory.java index a1df0f0059d3..1a61d9ad9d26 100644 --- a/dotCMS/src/main/java/com/dotmarketing/portlets/contentlet/business/ContentletFactory.java +++ b/dotCMS/src/main/java/com/dotmarketing/portlets/contentlet/business/ContentletFactory.java @@ -70,6 +70,11 @@ public interface ContentletFactory { * @param variant the variant ID to filter the contentlet from the database results * @return an {@code Optional} containing the contentlet if found, or an empty {@code Optional} if not found */ + // The cache-miss surcharge for the single-contentlet path - reaching this method IS the + // miss. Only fires for find(inode, variant); the other paths land on + // ESContentFactoryImpl.findInDb(String, boolean), which carries its own copy of both the + // SQL and this annotation. (The two differ: this one filters by variantId, that one + // honours ignoreStoryBlock, so neither can delegate to the other as written.) @RequestCost(Price.CONTENT_FROM_DB) default Optional findInDb(final String inode, final String variant) { try { diff --git a/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java b/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java index fde57fb008de..2c5f3ba0e4d8 100644 --- a/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java +++ b/dotCMS/src/test/java/com/dotcms/cost/RequestCostPublisherTest.java @@ -31,7 +31,7 @@ public void clearConfig() { private RequestCostSnapshot anySnapshot() { return new RequestCostSnapshot( "c", "e", "2026-05-19T00:00:00Z", - 60, 0L, 0d, 0d, 0L, 0d, 0d); + 60, 0L, 0d, 0d, 0L, 0d, 0d, 0d, 0d); } @Test diff --git a/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java b/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java index 873e60e6440a..68904feab62d 100644 --- a/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java +++ b/dotCMS/src/test/java/com/dotcms/cost/RequestCostSnapshotTest.java @@ -28,7 +28,9 @@ private RequestCostSnapshot sample() { 4.6d, 999_999L, 12_345_678.25d, - 12.35d); + 12.35d, + 42.5d, + 86_400.75d); } @Test @@ -47,6 +49,8 @@ public void test_serialization_includesAllExpectedFields() throws Exception { assertTrue("missing lifetimeRequests", json.has("lifetimeRequests")); assertTrue("missing lifetimeTokens", json.has("lifetimeTokens")); assertTrue("missing lifetimeAvgTokensPerRequest", json.has("lifetimeAvgTokensPerRequest")); + assertTrue("missing windowJobTokens", json.has("windowJobTokens")); + assertTrue("missing lifetimeJobTokens", json.has("lifetimeJobTokens")); } @Test @@ -65,15 +69,17 @@ public void test_serialization_preservesValues() throws Exception { 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); + assertEquals(42.5d, json.get("windowJobTokens").asDouble(), 0.0001d); + assertEquals(86_400.75d, json.get("lifetimeJobTokens").asDouble(), 0.0001d); } @Test - public void test_serialization_emitsExactlyTenFields() throws Exception { + public void test_serialization_emitsExactlyTwelveFields() 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()); + assertEquals("unexpected fields on the wire", 12, json.size()); } } diff --git a/dotcms-integration/src/test/java/com/dotcms/cost/RequestCostReportTest.java b/dotcms-integration/src/test/java/com/dotcms/cost/RequestCostReportTest.java index ff57b36e32e3..3611a7c11538 100644 --- a/dotcms-integration/src/test/java/com/dotcms/cost/RequestCostReportTest.java +++ b/dotcms-integration/src/test/java/com/dotcms/cost/RequestCostReportTest.java @@ -151,7 +151,11 @@ public void test_writeAccounting_shouldCalculateTotalCorrectly() { requestCostApi.incrementCost(Price.TWENTY, RequestCostReportTest.class, "method2", new Object[]{}); requestCostApi.incrementCost(Price.THIRTY, RequestCostReportTest.class, "method3", new Object[]{}); - int expectedTotal = requestCostApi.getRequestCost(request); + // The report renders the total divided by the denominator of the singleton API it + // uses internally. Our locally constructed requestCostApi never runs @PostConstruct, + // so its denominator would stay at the field default and not match the report's. + double expectedTotal = requestCostApi.getRequestCost(request) + / APILocator.getRequestCostAPI().getRequestCostDenominator(); // When String html = report.writeAccounting(request);