SOLR-13835 HttpSolrCall produces incorrect extra AuditEvent on AuthorizationResponse.PROMPT (#946)

solr/CHANGES.txt

@@ -329,6 +329,8 @@ Bug Fixes
 * SOLR-13834: ZkController#getSolrCloudManager() created a new instance of ZkStateReader, thereby causing mismatch in the
   visibility of the cluster state and, as a result, undesired race conditions (Clay Goddard via Ishan Chattopadhyaya)
 
+* SOLR-13835: HttpSolrCall produces incorrect extra AuditEvent on AuthorizationResponse.PROMPT (janhoy, hossman)
+
 Other Changes
 ----------------------
 

solr/core/src/java/org/apache/solr/security/AuditEvent.java

@@ -31,6 +31,7 @@ import java.util.stream.Collectors;
 
 import org.apache.solr.common.SolrException;
 import org.apache.solr.common.cloud.ZkStateReader;
+import org.apache.solr.servlet.SolrRequestParsers;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
@@ -129,12 +130,15 @@ public class AuditEvent {
     this.solrPort = httpRequest.getLocalPort();
     this.solrIp = httpRequest.getLocalAddr();
     this.clientIp = httpRequest.getRemoteAddr();
-    this.resource = httpRequest.getContextPath();
+    this.resource = httpRequest.getPathInfo();
     this.httpMethod = httpRequest.getMethod();
     this.httpQueryString = httpRequest.getQueryString();
     this.headers = getHeadersFromRequest(httpRequest);
     this.requestUrl = httpRequest.getRequestURL();
     this.nodeName = MDC.get(ZkStateReader.NODE_NAME_PROP);
+    SolrRequestParsers.parseQueryString(httpQueryString).forEach(sp -> {
+      this.solrParams.put(sp.getKey(), Arrays.asList(sp.getValue()));
+    });
 
     setRequestType(findRequestType());
 
@@ -459,14 +463,14 @@ public class AuditEvent {
   }
   
   private static final List<String> ADMIN_PATH_REGEXES = Arrays.asList(
-      "^/solr/admin/.*",
+      "^/admin/.*",
-      "^/api/(c|collections)/$",
+      "^/(____v2|api)/(c|collections)$",
-      "^/api/(c|collections)/[^/]+/config$",
+      "^/(____v2|api)/(c|collections)/[^/]+/config$",
-      "^/api/(c|collections)/[^/]+/schema$",
+      "^/(____v2|api)/(c|collections)/[^/]+/schema$",
-      "^/api/(c|collections)/[^/]+/shards.*",
+      "^/(____v2|api)/(c|collections)/[^/]+/shards.*",
-      "^/api/cores.*$",
+      "^/(____v2|api)/cores.*$",
-      "^/api/node$",
+      "^/(____v2|api)/node$",
-      "^/api/cluster$");
+      "^/(____v2|api)/cluster$");
 
   private static final List<String> STREAMING_PATH_REGEXES = Collections.singletonList(".*/stream.*");
 

solr/core/src/java/org/apache/solr/servlet/HttpSolrCall.java

@@ -474,25 +474,39 @@ public class HttpSolrCall {
     AuthorizationContext context = getAuthCtx();
     log.debug("AuthorizationContext : {}", context);
     AuthorizationResponse authResponse = cores.getAuthorizationPlugin().authorize(context);
-    if (authResponse.statusCode == AuthorizationResponse.PROMPT.statusCode) {
+    int statusCode = authResponse.statusCode;
+    
+    if (statusCode == AuthorizationResponse.PROMPT.statusCode) {
       Map<String, String> headers = (Map) getReq().getAttribute(AuthenticationPlugin.class.getName());
       if (headers != null) {
         for (Map.Entry<String, String> e : headers.entrySet()) response.setHeader(e.getKey(), e.getValue());
       }
       log.debug("USER_REQUIRED "+req.getHeader("Authorization")+" "+ req.getUserPrincipal());
+      sendError(statusCode,
+          "Authentication failed, Response code: " + statusCode);
       if (shouldAudit(EventType.REJECTED)) {
         cores.getAuditLoggerPlugin().doAudit(new AuditEvent(EventType.REJECTED, req, context));
       }
+      return RETURN;
     }
-    if (!(authResponse.statusCode == HttpStatus.SC_ACCEPTED) && !(authResponse.statusCode == HttpStatus.SC_OK)) {
+    if (statusCode == AuthorizationResponse.FORBIDDEN.statusCode) {
-      log.info("USER_REQUIRED auth header {} context : {} ", req.getHeader("Authorization"), context);
+      log.debug("UNAUTHORIZED auth header {} context : {}, msg: {}", req.getHeader("Authorization"), context, authResponse.getMessage());
-      sendError(authResponse.statusCode,
+      sendError(statusCode,
-          "Unauthorized request, Response code: " + authResponse.statusCode);
+          "Unauthorized request, Response code: " + statusCode);
       if (shouldAudit(EventType.UNAUTHORIZED)) {
         cores.getAuditLoggerPlugin().doAudit(new AuditEvent(EventType.UNAUTHORIZED, req, context));
       }
       return RETURN;
     }
+    if (!(statusCode == HttpStatus.SC_ACCEPTED) && !(statusCode == HttpStatus.SC_OK)) {
+      log.warn("ERROR {} during authentication: {}", statusCode, authResponse.getMessage());
+      sendError(statusCode,
+          "ERROR during authorization, Response code: " + statusCode);
+      if (shouldAudit(EventType.ERROR)) {
+        cores.getAuditLoggerPlugin().doAudit(new AuditEvent(EventType.ERROR, req, context));
+      }
+      return RETURN;
+    }
     if (shouldAudit(EventType.AUTHORIZED)) {
       cores.getAuditLoggerPlugin().doAudit(new AuditEvent(EventType.AUTHORIZED, req, context));
     }

solr/core/src/test/org/apache/solr/security/AuditLoggerIntegrationTest.java

@@ -60,7 +60,6 @@ import static org.apache.solr.client.solrj.request.CollectionAdminRequest.getOve
 import static org.apache.solr.security.AuditEvent.EventType.COMPLETED;
 import static org.apache.solr.security.AuditEvent.EventType.ERROR;
 import static org.apache.solr.security.AuditEvent.EventType.REJECTED;
-import static org.apache.solr.security.AuditEvent.EventType.UNAUTHORIZED;
 import static org.apache.solr.security.AuditEvent.RequestType.ADMIN;
 import static org.apache.solr.security.AuditEvent.RequestType.SEARCH;
 
@@ -184,11 +183,11 @@ public class AuditLoggerIntegrationTest extends SolrCloudAuthTestCase {
       CollectionAdminRequest.Create createRequest = CollectionAdminRequest.createCollection("test", 1, 1);
       createRequest.setBasicAuthCredentials("solr", "wrongPW");
       client.request(createRequest);       
-      fail("Call should fail with 403");
+      fail("Call should fail with 401");
     } catch (SolrException ex) {
       waitForAuditEventCallbacks(1);
       CallbackReceiver receiver = testHarness.get().receiver;
-      assertAuditEvent(receiver.popEvent(), UNAUTHORIZED, "/admin/collections", ADMIN, null,403);
+      assertAuditEvent(receiver.popEvent(), REJECTED, "/admin/collections", ADMIN, null, 401);
     }
   }
 

solr/core/src/test/org/apache/solr/security/BasicAuthIntegrationTest.java

@@ -58,8 +58,9 @@ import org.apache.solr.common.params.MapSolrParams;
 import org.apache.solr.common.params.ModifiableSolrParams;
 import org.apache.solr.common.params.SolrParams;
 import org.apache.solr.common.util.NamedList;
-import org.apache.solr.common.util.Utils;
 import org.apache.solr.common.util.TimeSource;
+import org.apache.solr.common.util.Utils;
+import org.apache.solr.util.LogLevel;
 import org.apache.solr.util.SolrCLI;
 import org.apache.solr.util.TimeOut;
 import org.junit.After;
@@ -96,6 +97,7 @@ public class BasicAuthIntegrationTest extends SolrCloudAuthTestCase {
   @Test
   //commented 9-Aug-2018 @BadApple(bugUrl="https://issues.apache.org/jira/browse/SOLR-12028") // 21-May-2018
   // commented out on: 17-Feb-2019   @BadApple(bugUrl="https://issues.apache.org/jira/browse/SOLR-12028") // annotated on: 24-Dec-2018
+  @LogLevel("org.apache.solr.security=DEBUG")
   public void testBasicAuth() throws Exception {
     boolean isUseV2Api = random().nextBoolean();
     String authcPrefix = "/admin/authentication";
@@ -232,7 +234,7 @@ public class BasicAuthIntegrationTest extends SolrCloudAuthTestCase {
         HttpSolrClient.RemoteSolrException e = expectThrows(HttpSolrClient.RemoteSolrException.class, () -> {
           new UpdateRequest().deleteByQuery("*:*").process(aNewClient, COLLECTION);
         });
-        assertTrue(e.getMessage().contains("Unauthorized request"));
+        assertTrue(e.getMessage(), e.getMessage().contains("Authentication failed"));
       } finally {
         aNewClient.close();
         cluster.stopJettySolrRunner(aNewJetty);