SOLR-18324: Fix NPE/RTimer assertion when a V2 request fails before a SolrQueryRequest is attached

changelog/unreleased/SOLR-18324-jersey-null-request-npe.yml

@@ -0,0 +1,7 @@
+title: Fixed a race condition where V2 (JAX-RS) API requests that fail before a SolrQueryRequest is attached to the request context could throw a NullPointerException while building the error response, which could cascade into an internal request-metrics-timer assertion failure under Solr's security manager / assertions-enabled test builds.
+type: fixed
+authors:
+  - name: Eric Pugh
+links:
+  - name: SOLR-18324
+    url: https://issues.apache.org/jira/browse/SOLR-18324

solr/core/src/java/org/apache/solr/handler/RequestHandlerBase.java

@@ -321,9 +321,12 @@ public static void processErrorMetricsOnException(Exception e, HandlerMetrics me
    * <p>If a tragic exception occurred in the index writer, this method also gives up leadership of
    * the shard, and replaces the index writer with a new one to attempt to get out of a transient
    * failure (e.g. disk failure).
+   *
+   * <p>{@code req} may be null, e.g. when called from Jersey's {@code CatchAllExceptionMapper} for
+   * a request that failed before a {@link SolrQueryRequest} was attached to the request context.
    */
   public static Exception processReceivedException(SolrQueryRequest req, Exception e) {
-    SolrCore core = req.getCore();
+    SolrCore core = req == null ? null : req.getCore();
     if (core != null) {
       CoreContainer coreContainer = req.getCoreContainer();
       assert coreContainer != null;

solr/core/src/java/org/apache/solr/jersey/CatchAllExceptionMapper.java

@@ -117,8 +117,10 @@ public static Response buildExceptionResponse(
             shouldHideStackTrace(solrQueryRequest, containerRequestContext));
     response.responseHeader.status = response.error.code;
     final String mediaType =
-        V2ApiUtils.getMediaTypeFromWtParam(
-            solrQueryRequest.getParams(), MediaType.APPLICATION_JSON);
+        solrQueryRequest == null
+            ? MediaType.APPLICATION_JSON
+            : V2ApiUtils.getMediaTypeFromWtParam(
+                solrQueryRequest.getParams(), MediaType.APPLICATION_JSON);
     return Response.status(response.error.code).type(mediaType).entity(response).build();
   }
 

solr/core/src/java/org/apache/solr/jersey/PostRequestDecorationFilter.java

@@ -55,6 +55,10 @@ public void filter(
     }
     final SolrQueryRequest solrQueryRequest =
         (SolrQueryRequest) requestContext.getProperty(SOLR_QUERY_REQUEST);
+    if (solrQueryRequest == null) {
+      log.debug("Skipping QTime assignment because no SolrQueryRequest was attached");
+      return;
+    }
     if (!responseContext.hasEntity()
         || !SolrJerseyResponse.class.isInstance(responseContext.getEntity())) {
       log.debug("Skipping QTime assignment because response was not a SolrJerseyResponse");

solr/core/src/java/org/apache/solr/jersey/PostRequestLoggingFilter.java

@@ -85,7 +85,9 @@ public void filter(
     final SolrQueryRequest solrQueryRequest =
         (SolrQueryRequest) requestContext.getProperty(SOLR_QUERY_REQUEST);
     final var solrConfig =
-        (solrQueryRequest.getCore() != null) ? solrQueryRequest.getCore().getSolrConfig() : null;
+        (solrQueryRequest != null && solrQueryRequest.getCore() != null)
+            ? solrQueryRequest.getCore().getSolrConfig()
+            : null;
 
     final Logger requestLogger = (solrConfig != null) ? coreRequestLogger : nonCoreRequestLogger;
     final String templatedPath =

solr/core/src/java/org/apache/solr/jersey/RequestMetricHandling.java

@@ -121,8 +121,13 @@ public void filter(
       } else {
         log.debug("Skipping partialResults check because entity was not SolrJerseyResponse");
       }
+      // Jersey can re-invoke response filters a second time when an exception occurs while
+      // building the first response (e.g. via CatchAllExceptionMapper), so guard against
+      // double-stopping the same timer.
       final var timer = (AttributedLongTimer.MetricTimer) requestContext.getProperty(TIMER);
+      if (timer == null) return;
       timer.stop();
+      requestContext.setProperty(TIMER, null);
     }
   }
 }

solr/core/src/test/org/apache/solr/handler/RequestHandlerBaseTest.java

@@ -160,6 +160,27 @@ public CoreContainer getCoreContainer() {
     assertEquals(SolrException.ErrorCode.SERVER_ERROR.code, normalizedSolrException.code());
   }
 
+  @Test
+  public void testNullRequestDoesNotThrowAndIsNotModified() {
+    // req can be null when this is called from Jersey's CatchAllExceptionMapper for a request
+    // that failed before a SolrQueryRequest was attached to the request context.
+    final Exception e = new RuntimeException("Some generic, non-SolrException");
+
+    final Exception normalized = RequestHandlerBase.processReceivedException(null, e);
+
+    assertSame(e, normalized);
+  }
+
+  @Test
+  public void testNullRequestWithSyntaxErrorIsStillWrappedIn400SolrException() {
+    final Exception e = new SyntaxError("Some syntax error");
+
+    final Exception normalized = RequestHandlerBase.processReceivedException(null, e);
+
+    assertEquals(SolrException.class, normalized.getClass());
+    assertEquals(SolrException.ErrorCode.BAD_REQUEST.code, ((SolrException) normalized).code());
+  }
+
   @Test
   public void testIsInternalShardRequest() {
     final SolrQueryRequest solrQueryRequest =

solr/core/src/test/org/apache/solr/jersey/PostRequestDecorationFilterTest.java

@@ -0,0 +1,93 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You 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 org.apache.solr.jersey;
+
+import static org.apache.solr.jersey.RequestContextKeys.NOT_FOUND_FLAG;
+import static org.apache.solr.jersey.RequestContextKeys.SOLR_QUERY_REQUEST;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.never;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
+
+import jakarta.ws.rs.container.ContainerRequestContext;
+import jakarta.ws.rs.container.ContainerResponseContext;
+import java.util.Set;
+import org.apache.solr.SolrTestCaseJ4;
+import org.apache.solr.client.api.model.SolrJerseyResponse;
+import org.apache.solr.request.SolrQueryRequest;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+/** Unit tests for {@link PostRequestDecorationFilter} */
+public class PostRequestDecorationFilterTest extends SolrTestCaseJ4 {
+
+  @BeforeClass
+  public static void ensureWorkingMockito() {
+    assumeWorkingMockito();
+  }
+
+  @Test
+  public void testFilterDoesNotThrowWhenNoSolrQueryRequestAttached() throws Exception {
+    // solrQueryRequest can be null when the request failed before Jersey attached one to the
+    // request context (e.g. via CatchAllExceptionMapper); filter() must not NPE in that case.
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of());
+    when(mockRequestContext.getProperty(SOLR_QUERY_REQUEST)).thenReturn(null);
+
+    final var response = new SolrJerseyResponse();
+    when(mockResponseContext.hasEntity()).thenReturn(true);
+    when(mockResponseContext.getEntity()).thenReturn(response);
+
+    new PostRequestDecorationFilter().filter(mockRequestContext, mockResponseContext);
+
+    assertEquals(0, response.responseHeader.qTime);
+  }
+
+  @Test
+  public void testFilterSetsQTimeWhenSolrQueryRequestPresent() throws Exception {
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    final var mockSolrQueryRequest = mock(SolrQueryRequest.class);
+    final var timer = new org.apache.solr.util.RTimerTree();
+
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of());
+    when(mockRequestContext.getProperty(SOLR_QUERY_REQUEST)).thenReturn(mockSolrQueryRequest);
+    when(mockSolrQueryRequest.getRequestTimer()).thenReturn(timer);
+
+    final var response = new SolrJerseyResponse();
+    when(mockResponseContext.hasEntity()).thenReturn(true);
+    when(mockResponseContext.getEntity()).thenReturn(response);
+
+    new PostRequestDecorationFilter().filter(mockRequestContext, mockResponseContext);
+
+    assertTrue(response.responseHeader.qTime >= 0);
+  }
+
+  @Test
+  public void testFilterSkipsEntirelyForNotFoundRequests() throws Exception {
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of(NOT_FOUND_FLAG));
+
+    new PostRequestDecorationFilter().filter(mockRequestContext, mockResponseContext);
+
+    verify(mockResponseContext, never()).hasEntity();
+  }
+}

solr/core/src/test/org/apache/solr/jersey/PostRequestLoggingFilterTest.java

@@ -18,21 +18,29 @@
 package org.apache.solr.jersey;
 
 import static org.apache.solr.jersey.MessageBodyReaders.CachingDelegatingMessageBodyReader.DESERIALIZED_REQUEST_BODY_KEY;
+import static org.apache.solr.jersey.RequestContextKeys.NOT_FOUND_FLAG;
+import static org.apache.solr.jersey.RequestContextKeys.SOLR_QUERY_REQUEST;
 import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.never;
+import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.when;
 
 import com.fasterxml.jackson.databind.ObjectMapper;
 import jakarta.ws.rs.container.ContainerRequestContext;
+import jakarta.ws.rs.container.ContainerResponseContext;
 import jakarta.ws.rs.core.MediaType;
 import jakarta.ws.rs.core.MultivaluedHashMap;
 import jakarta.ws.rs.core.UriInfo;
 import java.io.ByteArrayInputStream;
 import java.lang.annotation.Annotation;
+import java.net.URI;
 import java.nio.charset.StandardCharsets;
 import java.util.List;
+import java.util.Set;
 import org.apache.solr.SolrTestCaseJ4;
 import org.apache.solr.client.api.model.CreateCollectionRequestBody;
 import org.apache.solr.client.api.model.CreateReplicaRequestBody;
+import org.apache.solr.client.api.model.SolrJerseyResponse;
 import org.glassfish.jersey.jackson.internal.jackson.jaxrs.json.JacksonJsonProvider;
 import org.junit.BeforeClass;
 import org.junit.Test;
@@ -142,6 +150,41 @@ public void testCachingJsonMessageBodyReaderDelegateReusingObjectMapper() {
     assertSame(mapper1, mapper2);
   }
 
+  @Test
+  public void testFilterDoesNotThrowWhenNoSolrQueryRequestAttached() throws Exception {
+    // solrQueryRequest can be null when the request failed before Jersey attached one to the
+    // request context (e.g. via CatchAllExceptionMapper); filter() must not NPE in that case.
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    final var mockUriInfo = mock(UriInfo.class);
+
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of());
+    when(mockRequestContext.getProperty(SOLR_QUERY_REQUEST)).thenReturn(null);
+    when(mockRequestContext.getUriInfo()).thenReturn(mockUriInfo);
+    when(mockUriInfo.getAbsolutePath())
+        .thenReturn(URI.create("http://localhost/api/collections/foo"));
+    when(mockUriInfo.getQueryParameters()).thenReturn(new MultivaluedHashMap<>());
+
+    final var response = new SolrJerseyResponse();
+    response.responseHeader.status = 500;
+    response.responseHeader.qTime = 12;
+    when(mockResponseContext.hasEntity()).thenReturn(true);
+    when(mockResponseContext.getEntity()).thenReturn(response);
+
+    new PostRequestLoggingFilter().filter(mockRequestContext, mockResponseContext);
+  }
+
+  @Test
+  public void testFilterSkipsEntirelyForNotFoundRequests() throws Exception {
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of(NOT_FOUND_FLAG));
+
+    new PostRequestLoggingFilter().filter(mockRequestContext, mockResponseContext);
+
+    verify(mockResponseContext, never()).hasEntity();
+  }
+
   @Test
   public void testRequestBodyStringIsEmptyIfNoRequestBodyFound() {
     // NOTE: no request body is set on the context.

solr/core/src/test/org/apache/solr/jersey/RequestMetricHandlingTest.java

@@ -0,0 +1,97 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You 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 org.apache.solr.jersey;
+
+import static org.apache.solr.jersey.RequestContextKeys.HANDLER_METRICS;
+import static org.apache.solr.jersey.RequestContextKeys.TIMER;
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.api.metrics.LongCounter;
+import io.opentelemetry.api.metrics.LongHistogram;
+import jakarta.ws.rs.container.ContainerRequestContext;
+import jakarta.ws.rs.container.ContainerResponseContext;
+import java.util.Set;
+import org.apache.solr.SolrTestCaseJ4;
+import org.apache.solr.handler.RequestHandlerBase;
+import org.apache.solr.metrics.SolrMetricsContext;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+/** Unit tests for {@link RequestMetricHandling} */
+public class RequestMetricHandlingTest extends SolrTestCaseJ4 {
+
+  @BeforeClass
+  public static void ensureWorkingMockito() {
+    assumeWorkingMockito();
+  }
+
+  @Test
+  public void testPostRequestMetricsFilterToleratesBeingInvokedTwice() throws Exception {
+    // Jersey can re-invoke response filters a second time when an exception occurs while
+    // building the first response (e.g. via CatchAllExceptionMapper); the second invocation must
+    // not try to stop an already-stopped timer.
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    final RequestHandlerBase.HandlerMetrics metrics = createHandlerMetrics();
+    final var timer = metrics.requestTimes.start();
+
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of());
+    when(mockRequestContext.getProperty(HANDLER_METRICS)).thenReturn(metrics);
+    when(mockRequestContext.getProperty(TIMER)).thenReturn(timer);
+
+    final var filter = new RequestMetricHandling.PostRequestMetricsFilter();
+    filter.filter(mockRequestContext, mockResponseContext);
+
+    // Simulate Jersey clearing the property after the first stop, as our fix does.
+    when(mockRequestContext.getProperty(TIMER)).thenReturn(null);
+
+    // A second invocation must not throw (would previously throw AssertionError with
+    // assertions enabled, from RTimer.stop() being called on an already-stopped timer).
+    filter.filter(mockRequestContext, mockResponseContext);
+  }
+
+  @Test
+  public void testPostRequestMetricsFilterNoOpsWithoutMetrics() throws Exception {
+    final var mockRequestContext = mock(ContainerRequestContext.class);
+    final var mockResponseContext = mock(ContainerResponseContext.class);
+    when(mockRequestContext.getPropertyNames()).thenReturn(Set.of());
+    when(mockRequestContext.getProperty(HANDLER_METRICS)).thenReturn(null);
+
+    new RequestMetricHandling.PostRequestMetricsFilter()
+        .filter(mockRequestContext, mockResponseContext);
+  }
+
+  private RequestHandlerBase.HandlerMetrics createHandlerMetrics() {
+    final SolrMetricsContext metricsContext = mock(SolrMetricsContext.class);
+    final LongCounter mockLongCounter = mock(LongCounter.class);
+    final LongHistogram mockLongHistogram = mock(LongHistogram.class);
+
+    when(metricsContext.getRegistryName()).thenReturn("solr.core");
+    when(metricsContext.longCounter(any(), any())).thenReturn(mockLongCounter);
+    when(metricsContext.longCounter(any(), any(), any())).thenReturn(mockLongCounter);
+    when(metricsContext.longHistogram(any(), any())).thenReturn(mockLongHistogram);
+    when(metricsContext.longHistogram(any(), any(), any())).thenReturn(mockLongHistogram);
+
+    return new RequestHandlerBase.HandlerMetrics(
+        metricsContext, Attributes.of(AttributeKey.stringKey("source"), "test"), false);
+  }
+}