From 91497e4a1e3937964856535702d23394d1e33065 Mon Sep 17 00:00:00 2001 From: Havoc Pennington Date: Fri, 4 Jul 2014 14:34:02 -0400 Subject: [PATCH] Add config.trace=substitutions mode Dumps a bunch of verbose output about how substitutions are being resolved. --- .../config/impl/ConfigConcatenation.java | 12 +++++++ .../config/impl/ConfigDelayedMerge.java | 29 +++++++++++++++-- .../com/typesafe/config/impl/ConfigImpl.java | 25 +++++++++++++++ .../typesafe/config/impl/ConfigReference.java | 3 ++ .../com/typesafe/config/impl/MemoKey.java | 5 +++ .../typesafe/config/impl/ResolveContext.java | 32 ++++++++++++++++++- .../typesafe/config/impl/ResolveReplacer.java | 2 ++ .../typesafe/config/impl/ResolveSource.java | 28 +++++++++++++++- 8 files changed, 132 insertions(+), 4 deletions(-) diff --git a/config/src/main/java/com/typesafe/config/impl/ConfigConcatenation.java b/config/src/main/java/com/typesafe/config/impl/ConfigConcatenation.java index e592a250..8cb15753 100644 --- a/config/src/main/java/com/typesafe/config/impl/ConfigConcatenation.java +++ b/config/src/main/java/com/typesafe/config/impl/ConfigConcatenation.java @@ -171,11 +171,23 @@ final class ConfigConcatenation extends AbstractConfigValue implements Unmergeab @Override AbstractConfigValue resolveSubstitutions(ResolveContext context) throws NotPossibleToResolve { + if (ConfigImpl.traceSubstitutionsEnabled()) { + int indent = context.depth() + 2; + ConfigImpl.trace(indent - 1, "concatenation has " + pieces.size() + " pieces:"); + int count = 0; + for (AbstractConfigValue v : pieces) { + ConfigImpl.trace(indent, count + ": " + v); + count += 1; + } + } + List resolved = new ArrayList(pieces.size()); for (AbstractConfigValue p : pieces) { // to concat into a string we have to do a full resolve, // so unrestrict the context AbstractConfigValue r = context.unrestricted().resolve(p); + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "resolved concat piece to " + r); if (r == null) { // it was optional... omit } else { diff --git a/config/src/main/java/com/typesafe/config/impl/ConfigDelayedMerge.java b/config/src/main/java/com/typesafe/config/impl/ConfigDelayedMerge.java index 28153331..df942d5b 100644 --- a/config/src/main/java/com/typesafe/config/impl/ConfigDelayedMerge.java +++ b/config/src/main/java/com/typesafe/config/impl/ConfigDelayedMerge.java @@ -62,6 +62,16 @@ final class ConfigDelayedMerge extends AbstractConfigValue implements Unmergeabl // static method also used by ConfigDelayedMergeObject static AbstractConfigValue resolveSubstitutions(ReplaceableMergeStack replaceable, List stack, ResolveContext context) throws NotPossibleToResolve { + if (ConfigImpl.traceSubstitutionsEnabled()) { + int indent = context.depth() + 2; + ConfigImpl.trace(indent - 1, "delayed merge stack has " + stack.size() + " items:"); + int count = 0; + for (AbstractConfigValue v : stack) { + ConfigImpl.trace(indent, count + ": " + v); + count += 1; + } + } + // to resolve substitutions, we need to recursively resolve // the stack of stuff to merge, and merge the stack so // we won't be a delayed merge anymore. If restrictToChildOrNull @@ -86,6 +96,10 @@ final class ConfigDelayedMerge extends AbstractConfigValue implements Unmergeabl // ConfigDelayedMerge with a value that is only // the remainder of the stack below this one. + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth() + 1, "because item " + count + + " in this stack is unresolved, resolving it can only look at remaining " + + (stack.size() - count - 1) + " items"); context.source().replace((AbstractConfigValue) replaceable, replaceable.makeReplacer(count + 1)); replaced = true; @@ -93,6 +107,9 @@ final class ConfigDelayedMerge extends AbstractConfigValue implements Unmergeabl AbstractConfigValue resolved; try { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth() + 1, "resolving item " + count + " in merge stack of " + + stack.size()); resolved = context.resolve(v); } finally { if (replaced) @@ -100,14 +117,20 @@ final class ConfigDelayedMerge extends AbstractConfigValue implements Unmergeabl } if (resolved != null) { - if (merged == null) + if (merged == null) { merged = resolved; - else + } else { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth() + 1, "merging " + merged + " with fallback " + resolved); merged = merged.withFallback(resolved); + } } count += 1; } + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth() + 1, "stack was merged to: " + merged); + return merged; } @@ -129,6 +152,8 @@ final class ConfigDelayedMerge extends AbstractConfigValue implements Unmergeabl List subStack = stack.subList(skipping, stack.size()); if (subStack.isEmpty()) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "Nothing else in the merge stack, can't resolve"); throw new NotPossibleToResolve(context); } else { // generate a new merge stack from only the remaining items diff --git a/config/src/main/java/com/typesafe/config/impl/ConfigImpl.java b/config/src/main/java/com/typesafe/config/impl/ConfigImpl.java index 582c585c..d06b2c34 100644 --- a/config/src/main/java/com/typesafe/config/impl/ConfigImpl.java +++ b/config/src/main/java/com/typesafe/config/impl/ConfigImpl.java @@ -377,10 +377,12 @@ public class ConfigImpl { private static class DebugHolder { private static String LOADS = "loads"; + private static String SUBSTITUTIONS = "substitutions"; private static Map loadDiagnostics() { Map result = new HashMap(); result.put(LOADS, false); + result.put(SUBSTITUTIONS, false); // People do -Dconfig.trace=foo,bar to enable tracing of different things String s = System.getProperty("config.trace"); @@ -391,6 +393,8 @@ public class ConfigImpl { for (String k : keys) { if (k.equals(LOADS)) { result.put(LOADS, true); + } else if (k.equals(SUBSTITUTIONS)) { + result.put(SUBSTITUTIONS, true); } else { System.err.println("config.trace property contains unknown trace topic '" + k + "'"); @@ -403,10 +407,15 @@ public class ConfigImpl { private static final Map diagnostics = loadDiagnostics(); private static final boolean traceLoadsEnabled = diagnostics.get(LOADS); + private static final boolean traceSubstitutionsEnabled = diagnostics.get(SUBSTITUTIONS); static boolean traceLoadsEnabled() { return traceLoadsEnabled; } + + static boolean traceSubstitutionsEnabled() { + return traceSubstitutionsEnabled; + } } /** For use ONLY by library internals, DO NOT TOUCH not guaranteed ABI */ @@ -418,10 +427,26 @@ public class ConfigImpl { } } + public static boolean traceSubstitutionsEnabled() { + try { + return DebugHolder.traceSubstitutionsEnabled(); + } catch (ExceptionInInitializerError e) { + throw ConfigImplUtil.extractInitializerError(e); + } + } + public static void trace(String message) { System.err.println(message); } + public static void trace(int indentLevel, String message) { + while (indentLevel > 0) { + System.err.print(" "); + indentLevel -= 1; + } + System.err.println(message); + } + // the basic idea here is to add the "what" and have a canonical // toplevel error message. the "original" exception may however have extra // detail about what happened. call this if you have a better "what" than diff --git a/config/src/main/java/com/typesafe/config/impl/ConfigReference.java b/config/src/main/java/com/typesafe/config/impl/ConfigReference.java index 8c024daf..204a0aba 100644 --- a/config/src/main/java/com/typesafe/config/impl/ConfigReference.java +++ b/config/src/main/java/com/typesafe/config/impl/ConfigReference.java @@ -72,6 +72,9 @@ final class ConfigReference extends AbstractConfigValue implements Unmergeable { try { v = context.source().lookupSubst(context, expr, prefixLength); } catch (NotPossibleToResolve e) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), + "not possible to resolve " + expr + ", cycle involved: " + e.traceString()); if (expr.optional()) v = null; else diff --git a/config/src/main/java/com/typesafe/config/impl/MemoKey.java b/config/src/main/java/com/typesafe/config/impl/MemoKey.java index 7237234f..c9c73e14 100644 --- a/config/src/main/java/com/typesafe/config/impl/MemoKey.java +++ b/config/src/main/java/com/typesafe/config/impl/MemoKey.java @@ -36,4 +36,9 @@ final class MemoKey { return false; } } + + @Override + public final String toString() { + return "MemoKey(" + value + "," + restrictToChildOrNull + ")"; + } } diff --git a/config/src/main/java/com/typesafe/config/impl/ResolveContext.java b/config/src/main/java/com/typesafe/config/impl/ResolveContext.java index b73c064c..a6f9a469 100644 --- a/config/src/main/java/com/typesafe/config/impl/ResolveContext.java +++ b/config/src/main/java/com/typesafe/config/impl/ResolveContext.java @@ -43,6 +43,8 @@ final class ResolveContext { // in error messages if nothing else this(new ResolveSource(root), new ResolveMemos(), options, restrictToChild, new ArrayList()); + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace("ResolveContext at root " + root + " restrict to child " + restrictToChild); } ResolveSource source() { @@ -73,11 +75,15 @@ final class ResolveContext { } void trace(SubstitutionExpression expr) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "pushing expression " + expr); expressionTrace.add(expr); } void untrace() { - expressionTrace.remove(expressionTrace.size() - 1); + SubstitutionExpression expr = expressionTrace.remove(expressionTrace.size() - 1); + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "popped expression " + expr); } String traceString() { @@ -92,7 +98,14 @@ final class ResolveContext { return sb.toString(); } + int depth() { + return expressionTrace.size(); + } + AbstractConfigValue resolve(AbstractConfigValue original) throws NotPossibleToResolve { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "resolving " + original); + // a fully-resolved (no restrictToChild) object can satisfy a // request for a restricted object, so always check that first. final MemoKey fullKey = new MemoKey(original, null); @@ -109,15 +122,26 @@ final class ResolveContext { } if (cached != null) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "using cached resolution " + cached + " for " + original); return cached; } else { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "not found in cache, resolving " + original); + AbstractConfigValue resolved = source.resolveCheckingReplacement(this, original); + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "resolved to " + resolved + " from " + original); + if (resolved == null || resolved.resolveStatus() == ResolveStatus.RESOLVED) { // if the resolved object is fully resolved by resolving // only the restrictToChildOrNull, then it can be cached // under fullKey since the child we were restricted to // turned out to be the only unresolved thing. + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "caching " + fullKey + " result " + resolved); + memos.put(fullKey, resolved); } else { // if we have an unresolved object then either we did a @@ -128,8 +152,14 @@ final class ResolveContext { throw new ConfigException.BugOrBroken( "restrictedKey should not be null here"); } + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "caching " + restrictedKey + " result " + resolved); + memos.put(restrictedKey, resolved); } else if (options().getAllowUnresolved()) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(depth(), "caching " + fullKey + " result " + resolved); + memos.put(fullKey, resolved); } else { throw new ConfigException.BugOrBroken( diff --git a/config/src/main/java/com/typesafe/config/impl/ResolveReplacer.java b/config/src/main/java/com/typesafe/config/impl/ResolveReplacer.java index 1a5650f0..4cb1c364 100644 --- a/config/src/main/java/com/typesafe/config/impl/ResolveReplacer.java +++ b/config/src/main/java/com/typesafe/config/impl/ResolveReplacer.java @@ -24,6 +24,8 @@ abstract class ResolveReplacer { @Override protected AbstractConfigValue makeReplacement(ResolveContext context) throws NotPossibleToResolve { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "Cycle detected, can't resolve"); throw new NotPossibleToResolve(context); } }; diff --git a/config/src/main/java/com/typesafe/config/impl/ResolveSource.java b/config/src/main/java/com/typesafe/config/impl/ResolveSource.java index 6b5d5a18..9e150bad 100644 --- a/config/src/main/java/com/typesafe/config/impl/ResolveSource.java +++ b/config/src/main/java/com/typesafe/config/impl/ResolveSource.java @@ -31,8 +31,13 @@ final class ResolveSource { AbstractConfigValue lookupSubst(ResolveContext context, SubstitutionExpression subst, int prefixLength) throws NotPossibleToResolve { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "searching for " + subst); + context.trace(subst); try { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), subst + " - looking up relative to file it occurred in"); // First we look up the full path, which means relative to the // included file if we were not a root file AbstractConfigValue result = findInObject(root, context, subst); @@ -49,19 +54,30 @@ final class ResolveSource { context.trace(unprefixed); if (prefixLength > 0) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), unprefixed + " - looking up relative to parent file"); result = findInObject(root, context, unprefixed); } if (result == null && context.options().getUseSystemEnvironment()) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), unprefixed + " - looking up in system environment"); result = findInObject(ConfigImpl.envVariablesAsConfigObject(), context, unprefixed); } } if (result != null) { + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "recursively resolving " + result + + " which was the resolution of " + subst); + result = context.resolve(result); } + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "resolved to " + result); + return result; } finally { context.untrace(); @@ -87,7 +103,12 @@ final class ResolveSource { if (replacer == null) { return value; } else { - return replacer.replace(context); + AbstractConfigValue replacement = replacer.replace(context); + if (ConfigImpl.traceSubstitutionsEnabled() && value != replacement) { + ConfigImpl.trace(" when looking up substitutions " + context.traceString() + " replaced " + value + + " with " + replacement); + } + return replacement; } } @@ -103,10 +124,15 @@ final class ResolveSource { if (replacement != original) { // start over, checking if replacement was memoized + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "for resolution, replaced " + original + " with " + replacement); return context.resolve(replacement); } else { AbstractConfigValue resolved; + if (ConfigImpl.traceSubstitutionsEnabled()) + ConfigImpl.trace(context.depth(), "resolving " + original + " with trace '" + context.traceString() + + "'"); resolved = original.resolveSubstitutions(context); return resolved;