Add more logs for UnableToPlanException

fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java

@@ -383,16 +383,65 @@ public QueryPlanResult planGraph(@Nonnull final Supplier<Reference> referenceSup
                                     Debugger.getDebuggerMaybe()
                                             .flatMap(Debugger::getStatsMaps).orElse(null))
                             .build());
+        } catch (UnableToPlanException e) {
+            if (logger.isErrorEnabled()) {
+                final var logBuilder = KeyValueLogMessage.build("Unable to plan query",
+                        "recordMetadata", metaData.toProto().toString(),
+                        "parameterValues", evaluationContext.getBindings().toString(),
+                        "indexStates", recordStoreState.getIndexStates().toString(),
+                        "dataStoreInfo", recordStoreState.getStoreHeader().toString(),
+                        "taskCount", taskCount,
+                        "maxQueueSize", maxQueueSize,
+                        "plannerConfiguration", configuration.toString());
+
+                // Add match candidates info if present
+                if (e.getMatchCandidatesInfo() != null) {
+                    logBuilder.addKeyAndValue("matchCandidatesInfo", e.getMatchCandidatesInfo());
+                }
+
+                logger.error(logBuilder.toString(), e);
+            }
+            throw e;
         } finally {
             Debugger.withDebugger(Debugger::onDone);
         }
     }
 
+    /**
+     * Builds a detailed string representation of match candidates for diagnostic purposes.
+     * This includes the candidate type, name, record types, uniqueness, and column size.
+     *
+     * @param matchCandidates the collection of match candidates to describe
+     * @return a formatted string describing all match candidates
+     */
+    @Nonnull
+    static String buildMatchCandidatesInfo(@Nonnull final Collection<? extends MatchCandidate> matchCandidates) {
+        final var matchCandidatesBuilder = new StringBuilder("Match Candidates:\n");
+        if (matchCandidates.isEmpty()) {
+            matchCandidatesBuilder.append("  (none)");
+        } else {
+            for (final var candidate : matchCandidates) {
+                matchCandidatesBuilder.append(String.format("  - Type: %s, Name: %s, RecordTypes: [%s], Unique: %s, ColumnSize: %d%n",
+                        candidate.getClass().getSimpleName(),
+                        candidate.getName(),
+                        String.join(", ", candidate.getQueriedRecordTypeNames()),
+                        candidate.isUnique(),
+                        candidate.getColumnSize()));
+            }
+        }
+        return matchCandidatesBuilder.toString();
+    }
+
     private RecordQueryPlan resultOrFail() {
         final Set<RelationalExpression> finalExpressions = currentRoot.getFinalExpressions();
         Verify.verify(finalExpressions.size() <= 1, "more than one variant present");
         if (finalExpressions.isEmpty()) {
-            throw new UnableToPlanException("Cascades planner could not plan query");
+            // Build match candidates info
+            final var matchCandidates = planContext.getMatchCandidates();
+            final var matchCandidatesInfo = buildMatchCandidatesInfo(matchCandidates);
+
+            throw new UnableToPlanException("Cascades planner could not plan query")
+                    .withMatchCandidatesInfo(matchCandidatesInfo);
         }
 
         final RelationalExpression singleRoot = Iterables.getOnlyElement(finalExpressions);

fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/UnableToPlanException.java

@@ -33,7 +33,30 @@
 public class UnableToPlanException extends RecordCoreException {
     private static final long serialVersionUID = -640771754012134420L;
 
+    @Nullable
+    private String matchCandidatesInfo;
+
     public UnableToPlanException(@Nonnull String msg, @Nullable Object ... keyValues) {
         super(msg, keyValues);
     }
+
+    /**
+     * Set match candidates information to be included when logging this exception.
+     * @param matchCandidatesInfo String representation of match candidates
+     * @return this exception for chaining
+     */
+    @Nonnull
+    public UnableToPlanException withMatchCandidatesInfo(@Nullable String matchCandidatesInfo) {
+        this.matchCandidatesInfo = matchCandidatesInfo;
+        return this;
+    }
+
+    /**
+     * Get the match candidates information associated with this exception.
+     * @return match candidates info string, or null if not set
+     */
+    @Nullable
+    public String getMatchCandidatesInfo() {
+        return matchCandidatesInfo;
+    }
 }

fdb-record-layer-core/src/test/java/com/apple/foundationdb/record/query/plan/cascades/UnableToPlanExceptionTest.java

@@ -0,0 +1,59 @@
+/*
+ * UnableToPlanExceptionTest.java
+ *
+ * This source file is part of the FoundationDB open source project
+ *
+ * Copyright 2025 Apple Inc. and the FoundationDB project authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.apple.foundationdb.record.query.plan.cascades;
+
+import org.junit.jupiter.api.Test;
+
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertNull;
+import static org.junit.jupiter.api.Assertions.assertSame;
+
+/**
+ * Tests for {@link UnableToPlanException}.
+ */
+public class UnableToPlanExceptionTest {
+    @Test
+    public void testWithMatchCandidatesInfo() {
+        final UnableToPlanException exception = new UnableToPlanException("Test message");
+        final String matchCandidatesInfo = "Match Candidates:\n  - candidate1\n  - candidate2";
+
+        final UnableToPlanException result = exception.withMatchCandidatesInfo(matchCandidatesInfo);
+
+        // Verify it returns the same instance (fluent API)
+        assertSame(exception, result);
+
+        // Verify the match candidates info was set
+        assertEquals(matchCandidatesInfo, exception.getMatchCandidatesInfo());
+    }
+
+    @Test
+    public void testWithNullValue() {
+        final UnableToPlanException exception = new UnableToPlanException("Test message");
+
+        // Set to non-null value first
+        exception.withMatchCandidatesInfo("match");
+        assertEquals("match", exception.getMatchCandidatesInfo());
+
+        // Now set to null
+        exception.withMatchCandidatesInfo(null);
+        assertNull(exception.getMatchCandidatesInfo());
+    }
+}

fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/PlanGenerator.java

@@ -33,6 +33,7 @@
 import com.apple.foundationdb.record.query.plan.cascades.CascadesPlanner;
 import com.apple.foundationdb.record.query.plan.cascades.SemanticException;
 import com.apple.foundationdb.record.query.plan.cascades.StableSelectorCostModel;
+import com.apple.foundationdb.record.query.plan.cascades.UnableToPlanException;
 import com.apple.foundationdb.record.query.plan.cascades.typing.TypeRepository;
 import com.apple.foundationdb.record.query.plan.plans.RecordQueryPlan;
 import com.apple.foundationdb.record.query.plan.serialization.DefaultPlanSerializationRegistry;
@@ -239,6 +240,25 @@
                             planContext.getConstantActionFactory(), planContext.getDbUri(), caseSensitive)
                             .generateLogicalPlan(ast.getParseTree()));
             return maybePlan.optimize(planner, planContext, currentPlanHashMode);
+        } catch (UnableToPlanException e) {
+            // Log plan cache information when planning fails
+            cache.ifPresent(relationalPlanCache -> logPlanCacheOnFailure(relationalPlanCache, logger));
+
+            // Log connection options information when planning fails
+            if (logger.isErrorEnabled()) {
+                final var optionsBuilder = new StringBuilder("Connection Options:\n");
+                for (final var entry : options.entries()) {
+                    final var key = entry.getKey();
+                    final var value = entry.getValue();
+                    optionsBuilder.append(String.format("  %s = %s%n",
+                            key,
+                            value != null ? value.toString() : "null"));
+                }
+                logger.error(KeyValueLogMessage.of("Connection options when unable to plan",
+                        "connectionOptions", optionsBuilder.toString()));
+            }
+
+            throw e;
         } catch (MetaDataException mde) {
             // we need a better way for translating error codes between record layer and Relational SQL error codes
             throw new RelationalException(mde.getMessage(), ErrorCode.SYNTAX_OR_ACCESS_VIOLATION, mde).toUncheckedWrappedException();
@@ -371,6 +391,44 @@
         return options;
     }
 
+    /**
+     * Logs the plan cache state when unable to plan a query.
+     * This method collects tertiary cache statistics and logs them for debugging purposes.
+     *
+     * @param cache The optional plan cache
+     * @param logger The logger instance
+     */
+    static void logPlanCacheOnFailure(@Nonnull final RelationalPlanCache cache,
+                                      @Nonnull final Logger logger) {
+        if (logger.isErrorEnabled()) {
+            final var cacheStats = cache.getStats();
+            final var allPrimaryKeys = cacheStats.getAllKeys();
+            final var cacheInfoBuilder = new StringBuilder("Plan Cache Tertiary Layer:\n");
+
+            for (final var primaryKey : allPrimaryKeys) {
+                final var secondaryKeys = cacheStats.getAllSecondaryKeys(primaryKey);
+                for (final var secondaryKey : secondaryKeys) {
+                    final var tertiaryMappings = cacheStats.getAllTertiaryMappings(primaryKey, secondaryKey);
+                    if (!tertiaryMappings.isEmpty()) {
+                        cacheInfoBuilder.append(String.format("  [%s][%s]: %d entries%n", primaryKey, secondaryKey, tertiaryMappings.size()));
+                        for (final var entry : tertiaryMappings.entrySet()) {
+                            cacheInfoBuilder.append(String.format("    - %s%n", entry.getKey().toString()));
+                        }
+                    }
+                }
+            }
+
+            cacheInfoBuilder.append(String.format("Cache Stats: size=%d, hits=%d, misses=%d",
+                    cacheStats.numEntries(), cacheStats.numHits(), cacheStats.numMisses()));
+
+            logger.error(KeyValueLogMessage.of("Plan cache state when unable to plan",
+                    "planCacheTertiaryLayer", cacheInfoBuilder.toString(),
+                    "planCachePrimarySize", cacheStats.numEntries(),
+                    "planCachePrimaryHits", cacheStats.numHits(),
+                    "planCachePrimaryMisses", cacheStats.numMisses()));
+        }
+    }
+
     /**
      * Determines whether the query should be looked up and, if not found, cached in the plan cache. Currently, we take
      * this decision is taken statically, in the future we should combine with other combine it with environmental

fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/cache/MultiStageCache.java

@@ -21,6 +21,7 @@
 package com.apple.foundationdb.relational.recordlayer.query.cache;
 
 import com.apple.foundationdb.annotation.API;
+import com.apple.foundationdb.record.logging.KeyValueLogMessage;
 import com.apple.foundationdb.record.util.pair.NonnullPair;
 import com.apple.foundationdb.relational.api.exceptions.ErrorCode;
 import com.apple.foundationdb.relational.api.metrics.RelationalMetric;
@@ -30,6 +31,8 @@
 import com.github.benmanes.caffeine.cache.RemovalListener;
 import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Ticker;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import javax.annotation.Nonnull;
 import javax.annotation.Nullable;
@@ -92,6 +95,9 @@
 @API(API.Status.EXPERIMENTAL)
 public class MultiStageCache<K, S, T, V> extends AbstractCache<K, S, T, V> {
 
+    @Nonnull
+    private static final Logger logger = LoggerFactory.getLogger(MultiStageCache.class);
+
     @Nonnull
     private final Cache<K, Cache<S, Cache<T, V>>> mainCache;
 
@@ -167,7 +173,14 @@ public V reduce(@Nonnull final K key,
             final var secondaryCacheBuilder = Caffeine.newBuilder()
                     .maximumSize(secondarySize)
                     .recordStats()
-                    .removalListener((RemovalListener<S, Cache<T, V>>) (k, v, i) -> {
+                    .removalListener((RemovalListener<S, Cache<T, V>>) (k, v, cause) -> {
+                        if (logger.isDebugEnabled()) {
+                            logger.debug(KeyValueLogMessage.of("Plan cache secondary entry evicted",
+                                    "primaryKey", key,
+                                    "secondaryKey", k,
+                                    "cause", cause.toString(),
+                                    "remainingEntries", v != null ? v.estimatedSize() : 0));
+                        }
                         final var value = mainCache.getIfPresent(key);
                         if (value != null && value.asMap().isEmpty()) {
                             mainCache.invalidate(key); // best effort
@@ -190,7 +203,15 @@ public V reduce(@Nonnull final K key,
             final var tertiaryCacheBuilder = Caffeine.newBuilder()
                     .maximumSize(tertiarySize)
                     .recordStats()
-                    .removalListener((RemovalListener<T, V>) (k, v, i) -> {
+                    .removalListener((RemovalListener<T, V>) (k, v, cause) -> {
+                        if (logger.isDebugEnabled()) {
+                            logger.debug(KeyValueLogMessage.of("Plan cache tertiary entry evicted",
+                                    "primaryKey", key,
+                                    "secondaryKey", secondaryKey,
+                                    "tertiaryKey", k,
+                                    "cause", cause.toString(),
+                                    "valueType", v != null ? v.getClass().getSimpleName() : "null"));
+                        }
                         final var value = secondaryCache.getIfPresent(secondaryKey);
                         if (value != null && value.asMap().isEmpty()) {
                             secondaryCache.invalidate(secondaryKey); // best effort