[jira] [Created] (SOLR-15783) MDC Values can leak between request threads, trace_id currently does

["Chris M. Hostetter (Jira)" <ji...@apache.org>]

Chris M. Hostetter created SOLR-15783:
-----------------------------------------

             Summary: MDC Values can leak between request threads, trace_id currently does
                 Key: SOLR-15783
                 URL: https://issues.apache.org/jira/browse/SOLR-15783
             Project: Solr
          Issue Type: Bug
      Security Level: Public (Default Security Level. Issues are Public)
            Reporter: Chris M. Hostetter
            Assignee: Chris M. Hostetter



Currently, the only general "MDC Cleanup" code that happens from request to request is done by {{MDCLoggingContext.clear()}} and {{MDCLoggingContext.reset()}} ... but these methods (in addition to only being concerned with a static list of 5 specific MDC values) are currently designed and used in such a way that things like "trace_id" are only "reset" at the _begining_ of {{HttpSolrCall.call()}} ... which means any request specific log messages that happen before that point (like authn errors) will incorrectly refer to the trace_id of whatever request the thread _previously_ processed.

As a trivial example of this, if you apply a patch like...

{noformat}
diff --git a/solr/core/src/java/org/apache/solr/client/solrj/embedded/JettySolrRunner.java b/solr/core/src/java/org/apache/solr/client/solrj/embedded/JettySolrRunner.java
index 5f481c48e92..97c864617f4 100644
--- a/solr/core/src/java/org/apache/solr/client/solrj/embedded/JettySolrRunner.java
+++ b/solr/core/src/java/org/apache/solr/client/solrj/embedded/JettySolrRunner.java
@@ -109,7 +109,7 @@ public class JettySolrRunner {
 
   private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
 
-  private static final int THREAD_POOL_MAX_THREADS = 10000;
+  private static final int THREAD_POOL_MAX_THREADS = 10; // nocommit
   // NOTE: needs to be larger than SolrHttpClient.threadPoolSweeperMaxIdleTime
   private static final int THREAD_POOL_MAX_IDLE_TIME_MS = 260000;
 
diff --git a/solr/core/src/java/org/apache/solr/servlet/SolrDispatchFilter.java b/solr/core/src/java/org/apache/solr/servlet/SolrDispatchFilter.java
index 28167270099..fa6bb9a4eb8 100644
--- a/solr/core/src/java/org/apache/solr/servlet/SolrDispatchFilter.java
+++ b/solr/core/src/java/org/apache/solr/servlet/SolrDispatchFilter.java
@@ -484,6 +484,9 @@ public class SolrDispatchFilter extends BaseSolrFilter {
         response.sendError(429, errorMessage);
       }
 
+      log.error("nocommit: fake log message before HttpSolrCall.call() as if auth error happened: MDC_claims={} ; real_traceId={}",
+                org.slf4j.MDC.get(org.apache.solr.logging.MDCLoggingContext.TRACE_ID), span.context().toTraceId());
+      
       AtomicReference<HttpServletRequest> wrappedRequest = new AtomicReference<>();
       if (!authenticateRequest(request, response, wrappedRequest)) { // the response and status code have already been sent
         return;
{noformat}

...and then run {{./gradlew test --tests TestDistributedTracing -Ptests.verbose=true}} you can pick out any single jetty query thread and see something like...

{noformat}
  2> 4103 ERROR (qtp1310066330-70) [] o.a.s.s.SolrDispatchFilter nocommit: fake log message before HttpSolrCall.call() as if auth error happened: MDC_claims=null ; real_traceId=1
  2> 6146 ERROR (qtp1310066330-70) [n:127.0.0.1:34135_solr t:1] o.a.s.s.SolrDispatchFilter nocommit: fake log message before HttpSolrCall.call() as if auth error happened: MDC_claims=1 ; real_traceId=22
  2> 6661 ERROR (qtp1310066330-70) [n:127.0.0.1:34135_solr t:22] o.a.s.s.SolrDispatchFilter nocommit: fake log message before HttpSolrCall.call() as if auth error happened: MDC_claims=22 ; real_traceId=50
{noformat}

(Note also that during authn, the nodeId isn't populated for a 'new' thread, it's only set if it was leaked from the last request processed)




--
This message was sent by Atlassian Jira
(v8.20.1#820001)

---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@solr.apache.org
For additional commands, e-mail: issues-help@solr.apache.org