Skip to content

Commit 86dec11

Browse files
authored
context: log severe warning if ancestry chain too long (grpc#3459)
If a context has an unreasonable number of ancestors, then chances are this is an application error. Log the stack trace to notify the user and aid in debugging.
1 parent 332c46f commit 86dec11

2 files changed

Lines changed: 62 additions & 2 deletions

File tree

‎context/src/main/java/io/grpc/Context.java‎

Lines changed: 28 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -99,6 +99,11 @@ public class Context {
9999
private static final PersistentHashArrayMappedTrie<Key<?>, Object> EMPTY_ENTRIES =
100100
new PersistentHashArrayMappedTrie<Key<?>, Object>();
101101

102+
// Long chains of contexts are suspicious and usually indicate a misuse of Context.
103+
// The threshold is arbitrarily chosen.
104+
// VisibleForTesting
105+
static final int CONTEXT_DEPTH_WARN_THRESH = 1000;
106+
102107
/**
103108
* The logical root context which is the ultimate ancestor of all contexts. This context
104109
* is not cancellable and so will not cascade cancellation or retain listeners.
@@ -181,13 +186,17 @@ public static Context current() {
181186
private CancellationListener parentListener = new ParentListener();
182187
final CancellableContext cancellableAncestor;
183188
final PersistentHashArrayMappedTrie<Key<?>, Object> keyValueEntries;
189+
// The number parents between this context and the root context.
190+
final int generation;
184191

185192
/**
186193
* Construct a context that cannot be cancelled and will not cascade cancellation from its parent.
187194
*/
188-
private Context(PersistentHashArrayMappedTrie<Key<?>, Object> keyValueEntries) {
195+
private Context(PersistentHashArrayMappedTrie<Key<?>, Object> keyValueEntries, int generation) {
189196
cancellableAncestor = null;
190197
this.keyValueEntries = keyValueEntries;
198+
this.generation = generation;
199+
validateGeneration(generation);
191200
}
192201

193202
/**
@@ -197,6 +206,8 @@ private Context(PersistentHashArrayMappedTrie<Key<?>, Object> keyValueEntries) {
197206
private Context(Context parent, PersistentHashArrayMappedTrie<Key<?>, Object> keyValueEntries) {
198207
cancellableAncestor = cancellableAncestor(parent);
199208
this.keyValueEntries = keyValueEntries;
209+
this.generation = parent == null ? 0 : parent.generation + 1;
210+
validateGeneration(generation);
200211
}
201212

202213
/**
@@ -337,7 +348,7 @@ public <V1, V2, V3, V4> Context withValues(Key<V1> k1, V1 v1, Key<V2> k2, V2 v2,
337348
* cancellation.
338349
*/
339350
public Context fork() {
340-
return new Context(keyValueEntries);
351+
return new Context(keyValueEntries, generation + 1);
341352
}
342353

343354
boolean canBeCancelled() {
@@ -993,4 +1004,19 @@ static CancellableContext cancellableAncestor(Context parent) {
9931004
// Bypass the parent and reference the ancestor directly (may be null).
9941005
return parent.cancellableAncestor;
9951006
}
1007+
1008+
/**
1009+
* If the ancestry chain length is unreasonably long, then print an error to the log and record
1010+
* the stack trace.
1011+
*/
1012+
private static void validateGeneration(int generation) {
1013+
if (generation == CONTEXT_DEPTH_WARN_THRESH) {
1014+
log.log(
1015+
Level.SEVERE,
1016+
"Context ancestry chain length is abnormally long. "
1017+
+ "This suggests an error in application code. "
1018+
+ "Length exceeded: " + CONTEXT_DEPTH_WARN_THRESH,
1019+
new Exception());
1020+
}
1021+
}
9961022
}

‎context/src/test/java/io/grpc/ContextTest.java‎

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -922,6 +922,40 @@ public void cancellableAncestorFork() {
922922
assertNull(fork.cancellableAncestor);
923923
}
924924

925+
@Test
926+
public void errorWhenAncestryLengthLong() {
927+
final AtomicReference<LogRecord> logRef = new AtomicReference<LogRecord>();
928+
Handler handler = new Handler() {
929+
@Override
930+
public void publish(LogRecord record) {
931+
logRef.set(record);
932+
}
933+
934+
@Override
935+
public void flush() {
936+
}
937+
938+
@Override
939+
public void close() throws SecurityException {
940+
}
941+
};
942+
Logger logger = Logger.getLogger(Context.class.getName());
943+
try {
944+
logger.addHandler(handler);
945+
Context ctx = Context.current();
946+
for (int i = 0; i < Context.CONTEXT_DEPTH_WARN_THRESH ; i++) {
947+
assertNull(logRef.get());
948+
ctx = ctx.fork();
949+
}
950+
ctx = ctx.fork();
951+
assertNotNull(logRef.get());
952+
assertNotNull(logRef.get().getThrown());
953+
assertEquals(Level.SEVERE, logRef.get().getLevel());
954+
} finally {
955+
logger.removeHandler(handler);
956+
}
957+
}
958+
925959
// UsedReflectively
926960
public static final class LoadMeWithStaticTestingClassLoader implements Runnable {
927961
@Override

0 commit comments

Comments
 (0)