Merge branch 'develop'

e-gov · May 7, 2019 · cb0c24c · cb0c24c
2 parents 4e58833 + 4b8c154
commit cb0c24c
Show file tree

Hide file tree

Showing 13 changed files with 386 additions and 168 deletions.
diff --git a/src/main/java/ee/ria/sso/Constants.java b/src/main/java/ee/ria/sso/Constants.java
@@ -26,6 +26,7 @@ public final class Constants {
 
     public static final String MDC_ATTRIBUTE_REQUEST_ID = "requestId";
     public static final String MDC_ATTRIBUTE_SESSION_ID = "sessionId";
+    public static final String MDC_ATTRIBUTE_OCSP_ID = "ocspUrl";
 
     public static final String TARA_OIDC_SESSION_SCOPES = "taraOidcSessionScopes";
     public static final String TARA_OIDC_SESSION_CLIENT_ID = "taraOidcSessionClientId";

diff --git a/src/main/java/ee/ria/sso/flow/ThymeleafSupport.java b/src/main/java/ee/ria/sso/flow/ThymeleafSupport.java
@@ -10,11 +10,11 @@
 import org.apache.http.client.utils.URIBuilder;
 import org.apereo.cas.configuration.CasConfigurationProperties;
 import org.apereo.cas.services.OidcRegisteredService;
-import org.slf4j.MDC;
 import org.springframework.web.servlet.support.ServletUriComponentsBuilder;
 import org.springframework.web.util.UriComponentsBuilder;
 import org.springframework.webflow.execution.RequestContextHolder;
 
+import javax.servlet.http.HttpServletRequest;
 import java.net.URI;
 import java.net.URISyntaxException;
 import java.util.List;
@@ -83,9 +83,9 @@ public String getInformationUrl() {
         }
     }
 
-    public String getCurrentRequestIdentifier() {
+    public String getCurrentRequestIdentifier(HttpServletRequest request) {
         try {
-            return MDC.get(Constants.MDC_ATTRIBUTE_REQUEST_ID);
+            return (String)request.getAttribute(Constants.MDC_ATTRIBUTE_REQUEST_ID);
         } catch (Exception e) {
             log.error("Failed to retrieve current request identifier!", e);
             return null;

diff --git a/src/main/java/ee/ria/sso/logging/IncidentLoggingMDCServletFilter.java b/src/main/java/ee/ria/sso/logging/IncidentLoggingMDCServletFilter.java
@@ -4,6 +4,7 @@
 import lombok.AllArgsConstructor;
 import lombok.Getter;
 import lombok.NonNull;
+import lombok.extern.slf4j.Slf4j;
 import org.apache.commons.codec.digest.DigestUtils;
 import org.apache.commons.lang3.RandomStringUtils;
 import org.apache.commons.lang3.StringUtils;
@@ -16,12 +17,14 @@
 import java.io.Serializable;
 import java.util.Base64;
 
+@Slf4j
 public class IncidentLoggingMDCServletFilter implements Filter {
 
     private static final char[] REQUEST_ID_CHARACTER_SET = "ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789".toCharArray();
 
     @Override
     public void init(FilterConfig filterConfig) throws ServletException {
+        log.debug("Filter init called for: {}", IncidentLoggingMDCServletFilter.class.getName());
     }
 
     @Override
@@ -40,6 +43,7 @@ public void doFilter(ServletRequest servletRequest, ServletResponse servletRespo
 
     @Override
     public void destroy() {
+        log.debug("Filter destroy called for {}", IncidentLoggingMDCServletFilter.class.getName());
     }
 
     private static void addContextAttribute(final String attributeName, final Object value) {
@@ -49,7 +53,14 @@ private static void addContextAttribute(final String attributeName, final Object
     }
 
     private static String generateUniqueRequestId(HttpServletRequest request) {
-        return RandomStringUtils.random(16, REQUEST_ID_CHARACTER_SET);
+        String requestId = (String)request.getAttribute(Constants.MDC_ATTRIBUTE_REQUEST_ID);
+        if (requestId == null) {
+            requestId = RandomStringUtils.random(16, REQUEST_ID_CHARACTER_SET);
+            request.setAttribute(Constants.MDC_ATTRIBUTE_REQUEST_ID, requestId);
+            return requestId;
+        } else {
+            return requestId; // requestId must not be regenerated in case of internally forwarded requests
+        }
     }
 
     private static String getRequestSessionId(HttpServletRequest request) {
@@ -59,7 +70,7 @@ private static String getRequestSessionId(HttpServletRequest request) {
 
     private static TaraSessionIdentifier getSessionIdentifier(HttpSession session) {
         Object attribute = session.getAttribute(TaraSessionIdentifier.TARA_SESSION_IDENTIFIER_KEY);
-        if (attribute != null && attribute instanceof TaraSessionIdentifier)
+        if (attribute instanceof TaraSessionIdentifier)
             return (TaraSessionIdentifier) attribute;
 
         String sessionId = getBase64(DigestUtils.sha256(session.getId()));

diff --git a/src/main/java/ee/ria/sso/service/idcard/IDCardAuthenticationService.java b/src/main/java/ee/ria/sso/service/idcard/IDCardAuthenticationService.java
@@ -10,21 +10,26 @@
 import ee.ria.sso.service.ExternalServiceHasFailedException;
 import ee.ria.sso.service.UserAuthenticationFailedException;
 import ee.ria.sso.statistics.StatisticsHandler;
+import ee.ria.sso.statistics.StatisticsOperation;
+import ee.ria.sso.statistics.StatisticsRecord;
 import ee.ria.sso.utils.EstonianIdCodeUtil;
 import ee.ria.sso.utils.X509Utils;
 import lombok.extern.slf4j.Slf4j;
 import org.apereo.cas.web.flow.CasWebflowConstants;
 import org.apereo.inspektr.audit.annotation.Audit;
+import org.slf4j.MDC;
 import org.springframework.webflow.core.collection.SharedAttributeMap;
 import org.springframework.webflow.execution.Event;
 import org.springframework.webflow.execution.RequestContext;
 
 import java.security.cert.CertificateExpiredException;
 import java.security.cert.CertificateNotYetValidException;
 import java.security.cert.X509Certificate;
+import java.time.LocalDateTime;
 import java.util.List;
 import java.util.Map;
 
+import static ee.ria.sso.Constants.MDC_ATTRIBUTE_OCSP_ID;
 import static ee.ria.sso.statistics.StatisticsOperation.START_AUTH;
 import static ee.ria.sso.statistics.StatisticsOperation.SUCCESSFUL_AUTH;
 
@@ -66,12 +71,19 @@ public Event loginByIDCard(RequestContext context) {
             TaraCredential credential = createUserCredential(certificate, context);
             context.getFlowExecutionContext().getActiveSession().getScope().put(CasWebflowConstants.VAR_ID_CREDENTIAL, credential);
 
-            logEvent(context, AuthenticationType.IDCard, SUCCESSFUL_AUTH);
+            logEvent(StatisticsRecord.builder()
+                    .time(LocalDateTime.now())
+                    .clientId(getServiceClientId(context))
+                    .method(AuthenticationType.IDCard)
+                    .operation(SUCCESSFUL_AUTH)
+                    .ocsp(getOcspUrlFromMDC())
+                    .build()
+            );
 
             return new Event(this, CasWebflowConstants.TRANSITION_ID_SUCCESS);
 
         } catch (Exception e) {
-            logEvent(context, e, AuthenticationType.IDCard);
+            logFailureEvent(context, e);
             throw e;
         } finally {
             sessionMap.remove(Constants.CERTIFICATE_SESSION_ATTRIBUTE);
@@ -136,4 +148,21 @@ private boolean isEmailRequested(RequestContext context) {
         List<TaraScope > scopes = context.getExternalContext().getSessionMap().get(Constants.TARA_OIDC_SESSION_SCOPES, List.class, null);
         return scopes != null && scopes.contains(TaraScope.EMAIL);
     }
+
+    private String getOcspUrlFromMDC() {
+        String ocspUrl = MDC.get(MDC_ATTRIBUTE_OCSP_ID);
+        return ocspUrl != null ? ocspUrl : "N/A";
+    }
+
+    private void logFailureEvent(RequestContext context, Exception e) {
+        logEvent(StatisticsRecord.builder()
+                .time(LocalDateTime.now())
+                .clientId(getServiceClientId(context))
+                .method(AuthenticationType.IDCard)
+                .operation(StatisticsOperation.ERROR)
+                .ocsp(getOcspUrlFromMDC())
+                .error(e.getMessage())
+                .build()
+        );
+    }
 }
diff --git a/src/main/java/ee/ria/sso/service/idcard/OCSPServiceNotAvailableException.java b/src/main/java/ee/ria/sso/service/idcard/OCSPServiceNotAvailableException.java
@@ -2,11 +2,11 @@
 
 public class OCSPServiceNotAvailableException extends RuntimeException {
 
-    public OCSPServiceNotAvailableException(Exception exception) {
-        super(exception);
-    }
-
     public OCSPServiceNotAvailableException(String message) {
         super(message);
     }
+
+    public OCSPServiceNotAvailableException(String message, Exception e) {
+        super(message,e);
+    }
 }
diff --git a/src/main/java/ee/ria/sso/service/idcard/OCSPValidator.java b/src/main/java/ee/ria/sso/service/idcard/OCSPValidator.java
@@ -1,6 +1,6 @@
 package ee.ria.sso.service.idcard;
 
-import ee.ria.sso.config.idcard.IDCardConfigurationProvider;
+import ee.ria.sso.config.idcard.IDCardConfigurationProvider.Ocsp;
 import ee.ria.sso.utils.X509Utils;
 import lombok.RequiredArgsConstructor;
 import lombok.extern.slf4j.Slf4j;
@@ -20,6 +20,7 @@
 import org.bouncycastle.operator.OperatorCreationException;
 import org.bouncycastle.operator.jcajce.JcaContentVerifierProviderBuilder;
 import org.bouncycastle.operator.jcajce.JcaDigestCalculatorProviderBuilder;
+import org.slf4j.MDC;
 import org.springframework.util.Assert;
 
 import java.io.*;
@@ -30,6 +31,8 @@
 import java.time.Instant;
 import java.util.*;
 
+import static ee.ria.sso.Constants.MDC_ATTRIBUTE_OCSP_ID;
+
 @Slf4j
 @RequiredArgsConstructor
 public class OCSPValidator {
@@ -45,18 +48,19 @@ public void checkCert(X509Certificate userCert) {
         Assert.notNull(userCert, "User certificate cannot be null!");
         log.info("OCSP certificate validation. Serialnumber=<{}>, SubjectDN=<{}>, issuerDN=<{}>",
                 userCert.getSerialNumber(), userCert.getSubjectDN().getName(), userCert.getIssuerDN().getName());
-        List<IDCardConfigurationProvider.Ocsp> ocspConfiguration = ocspConfigurationResolver.resolve(userCert);
+        List<Ocsp> ocspConfiguration = ocspConfigurationResolver.resolve(userCert);
         Assert.isTrue(CollectionUtils.isNotEmpty(ocspConfiguration), "At least one OCSP configuration must be present");
 
         int count = 0;
         int maxTries = ocspConfiguration.size();
         while (true) {
+            Ocsp ocspConf = ocspConfiguration.get(count);
             try {
                 if (count > 0) {
-                    log.info("Retrying OCSP request with {}. Configuration: {}", ocspConfiguration.get(count).getUrl(), ocspConfiguration.get(count));
+                    log.info("Retrying OCSP request with {}. Configuration: {}", ocspConf.getUrl(), ocspConf);
                 }
 
-                checkCert(userCert, ocspConfiguration.get(count));
+                checkCert(userCert, ocspConf);
                 return;
             } catch (OCSPServiceNotAvailableException e) {
                 log.error("OCSP request has failed...");
@@ -67,15 +71,15 @@ public void checkCert(X509Certificate userCert) {
         }
     }
 
-    protected void checkCert(X509Certificate userCert, IDCardConfigurationProvider.Ocsp ocspConf) {
+    protected void checkCert(X509Certificate userCert, Ocsp ocspConf) {
         X509Certificate issuerCert = findIssuerCertificate(userCert);
         validateCertSignedBy(userCert, issuerCert);
 
         try {
             OCSPReq request = buildOCSPReq(userCert, issuerCert, ocspConf);
             OCSPResp response = sendOCSPReq(request, ocspConf);
 
-            BasicOCSPResp ocspResponse = getResponse(response);
+            BasicOCSPResp ocspResponse = getResponse(response, ocspConf);
             validateResponseNonce(request, ocspResponse, ocspConf);
             validateResponseSignature(ocspResponse, issuerCert, ocspConf);
 
@@ -84,20 +88,21 @@ protected void checkCert(X509Certificate userCert, IDCardConfigurationProvider.O
             validateCertStatus(singleResponse);
         } catch (OCSPValidationException | OCSPServiceNotAvailableException e) {
             throw e;
-        } catch (SocketTimeoutException | ConnectException | UnknownHostException e) {
-            throw new OCSPServiceNotAvailableException(e);
+        } catch (SocketTimeoutException | SocketException | UnknownHostException e) {
+            throw new OCSPServiceNotAvailableException("OCSP not available: " + ocspConf.getUrl(), e);
         } catch (Exception e) {
             throw new IllegalStateException("OCSP validation failed: " + e.getMessage(), e);
         }
     }
 
-    private BasicOCSPResp getResponse(OCSPResp response)
+    private BasicOCSPResp getResponse(OCSPResp response, Ocsp ocspConf)
             throws IOException, OCSPException {
         log.info("OCSP response received: {}", Base64.getEncoder().encodeToString(response.getEncoded()));
         BasicOCSPResp basicOCSPResponse = (BasicOCSPResp) response.getResponseObject();
         Assert.notNull(basicOCSPResponse, "Invalid OCSP response! OCSP response object bytes could not be read!");
         Assert.notNull(basicOCSPResponse.getCerts(), "Invalid OCSP response! OCSP response is missing mandatory element - the signing certificate");
         Assert.isTrue(basicOCSPResponse.getCerts().length >= 1, "Invalid OCSP response! Expecting at least one OCSP responder certificate");
+        MDC.put(MDC_ATTRIBUTE_OCSP_ID, ocspConf.getUrl());
         return basicOCSPResponse;
     }
 
@@ -113,7 +118,7 @@ private void validateCertStatus(SingleResp singleResponse) {
         }
     }
 
-    private OCSPReq buildOCSPReq(X509Certificate userCert, X509Certificate issuerCert, IDCardConfigurationProvider.Ocsp conf)
+    private OCSPReq buildOCSPReq(X509Certificate userCert, X509Certificate issuerCert, Ocsp conf)
             throws OCSPException, IOException, CertificateEncodingException, OperatorCreationException {
         OCSPReqBuilder builder = new OCSPReqBuilder();
 
@@ -129,7 +134,7 @@ private OCSPReq buildOCSPReq(X509Certificate userCert, X509Certificate issuerCer
         return builder.build();
     }
 
-    private OCSPResp sendOCSPReq(OCSPReq request, IDCardConfigurationProvider.Ocsp conf) throws IOException {
+    private OCSPResp sendOCSPReq(OCSPReq request, Ocsp conf) throws IOException {
         byte[] bytes = request.getEncoded();
 
         HttpURLConnection connection = (HttpURLConnection) new URL(conf.getUrl()).openConnection();
@@ -175,7 +180,7 @@ private CertificateID generateCertificateIdForRequest(X509Certificate userCert,
             throws OperatorCreationException, CertificateEncodingException, OCSPException {
         BigInteger userCertSerialNumber = userCert.getSerialNumber();
         return new CertificateID(
-                new JcaDigestCalculatorProviderBuilder().build().get(CertificateID.HASH_SHA1),
+                new JcaDigestCalculatorProviderBuilder().build().get(CertificateID.HASH_SHA1), // NB! SK OCSP supports only SHA-1 for CertificateID
                 new JcaX509CertificateHolder(issuerCert),
                 userCertSerialNumber
         );
@@ -186,7 +191,7 @@ private DEROctetString generateDerOctetStringForNonce(UUID uuid) throws IOExcept
         return new DEROctetString(new DEROctetString(uuidBytes));
     }
 
-    private void validateResponseNonce(OCSPReq request, BasicOCSPResp response, IDCardConfigurationProvider.Ocsp ocspConf) {
+    private void validateResponseNonce(OCSPReq request, BasicOCSPResp response, Ocsp ocspConf) {
         if (!ocspConf.isNonceDisabled()) {
             Extension requestExtension = request.getExtension(OCSPObjectIdentifiers.id_pkix_ocsp_nonce);
             DEROctetString nonce = (DEROctetString)requestExtension.getExtnValue();
@@ -211,7 +216,7 @@ private void validateResponseThisUpdate(SingleResp response, long acceptedClockS
             throw new IllegalStateException("OCSP response cannot be produced in the future");
     }
 
-    private void validateResponseSignature(BasicOCSPResp response, X509Certificate userCertIssuer, IDCardConfigurationProvider.Ocsp ocspConfiguration)
+    private void validateResponseSignature(BasicOCSPResp response, X509Certificate userCertIssuer, Ocsp ocspConfiguration)
             throws OCSPException, OperatorCreationException, CertificateException, IOException {
 
         X509Certificate signingCert = getResponseSigningCert(response, userCertIssuer, ocspConfiguration);
@@ -221,7 +226,7 @@ private void validateResponseSignature(BasicOCSPResp response, X509Certificate u
         verifyResponseSignature(response, signingCert);
     }
 
-    private X509Certificate getResponseSigningCert(BasicOCSPResp response, X509Certificate userCertIssuer, IDCardConfigurationProvider.Ocsp ocspConfiguration)
+    private X509Certificate getResponseSigningCert(BasicOCSPResp response, X509Certificate userCertIssuer, Ocsp ocspConfiguration)
             throws CertificateException, IOException {
         String responderCn = getResponderCN(response);
 

diff --git a/src/main/java/ee/ria/sso/statistics/StatisticsRecord.java b/src/main/java/ee/ria/sso/statistics/StatisticsRecord.java
@@ -5,7 +5,6 @@
 import ee.ria.sso.authentication.AuthenticationType;
 import lombok.Builder;
 import lombok.Getter;
-import lombok.NonNull;
 import org.springframework.util.Assert;
 
 import java.time.LocalDateTime;
@@ -26,8 +25,9 @@ public class StatisticsRecord {
     private final String error;
     private final String bank;
     private final String country;
+    private final String ocsp;
 
-    public StatisticsRecord(LocalDateTime time, String clientId, AuthenticationType method, StatisticsOperation operation, String error, String bank, String country) {
+    public StatisticsRecord(LocalDateTime time, String clientId, AuthenticationType method, StatisticsOperation operation, String error, String bank, String country, String ocsp) {
         Assert.notNull(time, "Authentication time cannot be null!");
         Assert.notNull(clientId, "Client-ID cannot be null!");
         Assert.notNull(method, "Authentication method cannot be null!");
@@ -45,6 +45,7 @@ public StatisticsRecord(LocalDateTime time, String clientId, AuthenticationType
         this.error = error;
         this.bank = bank;
         this.country = country;
+        this.ocsp = ocsp;
     }
 
     public String getTime() {
@@ -86,6 +87,10 @@ public String toString() {
         if (this.error != null)
             sb.append(this.error);
 
+        if (this.ocsp != null) {
+            sb.append(';').append(this.getOcsp());
+        }
+
         return sb.toString();
     }
 }
diff --git a/src/main/webapp/WEB-INF/classes/log4j2.xml b/src/main/webapp/WEB-INF/classes/log4j2.xml
@@ -146,6 +146,14 @@
             <!-- Uncomment when using syslog appender -->
             <!--AppenderRef ref="taraSyslog" level="${sys:tara.log.level}" /-->
         </AsyncLogger>
+        <AsyncLogger name="org.pac4j" level="info" additivity="false" >
+            <AppenderRef ref="casConsole" level="${sys:tara.console.level}" />
+            <AppenderRef ref="errorFile" level="error" />
+            <AppenderRef ref="casFile" level="info" />
+
+            <!-- Uncomment when using syslog appender -->
+            <!--AppenderRef ref="taraSyslog" level="${sys:tara.log.level}" /-->
+        </AsyncLogger>
         <AsyncLogger name="org.apereo.cas" level="warn" additivity="false" >
             <AppenderRef ref="casConsole" level="${sys:tara.console.level}" />
             <AppenderRef ref="errorFile" level="error" />

diff --git a/src/main/webapp/WEB-INF/classes/templates/error.html b/src/main/webapp/WEB-INF/classes/templates/error.html
@@ -8,9 +8,9 @@
             <p><strong><span th:text="#{message.error.auth.title}" th:remove="tag"></span></strong></p>
             <p th:if="${TARA_ERROR_MESSAGE != null}" th:text="${TARA_ERROR_MESSAGE}"></p>
             <p th:unless="${TARA_ERROR_MESSAGE != null}" th:text="#{message.error.auth.error}"></p>
-            <p th:if="${@thymeleafSupport.getCurrentRequestIdentifier() != null}">
+            <p th:if="${@thymeleafSupport.getCurrentRequestIdentifier(#request) != null}">
                 <span th:text="#{label.error.incidentNumber}" th:remove="tag"></span>&nbsp;
-                <span th:text="${@thymeleafSupport.getCurrentRequestIdentifier()}" th:remove="tag"></span>
+                <span th:text="${@thymeleafSupport.getCurrentRequestIdentifier(#request)}" th:remove="tag"></span>
             </p>
         </div>
         <p th:if="${@thymeleafSupport.getBackUrl(session.pac4jRequestedUrl, #locale) != '#'}" class="link-back">