fix: z/OSMF logging improvements (#2998)

* Improve log events for zosmf detection. --------- Signed-off-by: Petr Weinfurt <petr.weinfurt@broadcom.com> Signed-off-by: Pablo Hernán Carle <pablo.carle@broadcom.com> Signed-off-by: sj895092 <shobhackm9@gmail.com> Co-authored-by: Petr Weinfurt <petr.weinfurt@broadcom.com> Co-authored-by: Pablo Hernán Carle <pablo.carle@broadcom.com> Co-authored-by: sj895092 <shobhackm9@gmail.com>
zowe · Jul 26, 2023 · eb7b02e · eb7b02e
1 parent 3ffa275
commit eb7b02e
Show file tree

Hide file tree

Showing 14 changed files with 436 additions and 77 deletions.
diff --git a/apiml-common/src/main/java/org/zowe/apiml/product/web/HttpConfig.java b/apiml-common/src/main/java/org/zowe/apiml/product/web/HttpConfig.java
@@ -28,12 +28,17 @@
 import org.springframework.context.annotation.Primary;
 import org.springframework.http.client.HttpComponentsClientHttpRequestFactory;
 import org.springframework.web.client.RestTemplate;
-import org.zowe.apiml.security.*;
+import org.zowe.apiml.security.ApimlPoolingHttpClientConnectionManager;
+import org.zowe.apiml.security.HttpsConfig;
+import org.zowe.apiml.security.HttpsConfigError;
+import org.zowe.apiml.security.HttpsFactory;
+import org.zowe.apiml.security.SecurityUtils;
 
 import javax.annotation.PostConstruct;
 import javax.annotation.Resource;
 import javax.net.ssl.HostnameVerifier;
 import javax.net.ssl.SSLContext;
+
 import java.util.Set;
 import java.util.Timer;
 import java.util.TimerTask;
@@ -173,10 +178,10 @@ public void init() {
 
         } catch (HttpsConfigError e) {
             log.error("Invalid configuration of HTTPs: {}", e.getMessage());
-            System.exit(1); // NOSONAR
+            System.exit(1);
         } catch (Exception e) {
             log.error("Cannot construct configuration of HTTPs: {}", e.getMessage());
-            System.exit(1); // NOSONAR
+            System.exit(1);
         }
     }
 

diff --git a/certificate-analyser/README.md b/certificate-analyser/README.md
@@ -3,6 +3,7 @@
 ### Usage
 
 java -jar certificate-analyser-<version>.jar --help
+
 ```
 Usage: <main class> [-hl] [-kp[=<keyPasswd>]] [-tp[=<trustPasswd>]]
                     [-a=<keyAlias>] [-k=<keyStore>] [-kt=<keyStoreType>]
@@ -28,9 +29,10 @@ Usage: <main class> [-hl] [-kp[=<keyPasswd>]] [-tp[=<trustPasswd>]]
       -tt, --truststoretype=<trustStoreType>
                 Truststore type, default is PKCS12
 ```
+
 *NOTE*
 
-keypasswd - if you specify this parameter without a value(e.g. java -jar <file.jar> --keypasswd), you will be asked to enter the password 
+keypasswd - if you specify this parameter without a value(e.g. java -jar <file.jar> --keypasswd), you will be asked to enter the password
 
 trustpasswd - if you specify this parameter without a value(e.g. java -jar <file.jar> --trustpasswd), you will be asked to enter the password
             -  if this parameter is omitted completely, value from keypasswd will be used
@@ -39,14 +41,12 @@ truststoretype - if this parameter is omitted completely, value from keystoretyp
 
 ### Do local handshake
 
-java -jar -Djavax.net.debug=ssl:handshake:verbose certificate-analyser-<version>.jar --keystore ../../../keystore/localhost/localhost.keystore.p12 --truststore ../../../keystore/localhost/localhost.truststore.p12 --keypasswd password --keyalias localhost --local 
+java -jar -Djavax.net.debug=ssl:handshake:verbose certificate-analyser-<version>.jar --keystore ../../../keystore/localhost/localhost.keystore.p12 --truststore ../../../keystore/localhost/localhost.truststore.p12 --keypasswd password --keyalias localhost --local
 
 ### Keyring
 
 If you are using SAF keyrings, you need to provide an additional parameter in command line `-Djava.protocol.handler.pkgs=com.ibm.crypto.provider`.
 
-### Possible issues:
+### Possible issues
 
 Keystore/truststore is owned by different user - permission error. Temporarily Change read permission to all.
-
-
diff --git a/discoverable-client/src/main/java/org/zowe/apiml/client/api/ZaasClientTestController.java b/discoverable-client/src/main/java/org/zowe/apiml/client/api/ZaasClientTestController.java
@@ -80,6 +80,4 @@ public ResponseEntity<String> forwardLogout(
 class LoginRequest {
     private String username;
     private char[] password;
-
 }
-
diff --git a/gateway-service/src/main/java/org/zowe/apiml/gateway/health/GatewayHealthIndicator.java b/gateway-service/src/main/java/org/zowe/apiml/gateway/health/GatewayHealthIndicator.java
@@ -10,7 +10,6 @@
 
 package org.zowe.apiml.gateway.health;
 
-import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.beans.factory.annotation.Value;
 import org.springframework.boot.actuate.health.AbstractHealthIndicator;
 import org.springframework.boot.actuate.health.Health;
@@ -33,7 +32,6 @@ public class GatewayHealthIndicator extends AbstractHealthIndicator {
     private final Providers loginProviders;
     private String apiCatalogServiceId;
 
-    @Autowired
     public GatewayHealthIndicator(DiscoveryClient discoveryClient,
                                   Providers providers,
                                   @Value("${apiml.catalog.serviceId:}") String apiCatalogServiceId) {

diff --git a/gateway-service/src/main/java/org/zowe/apiml/gateway/security/login/Providers.java b/gateway-service/src/main/java/org/zowe/apiml/gateway/security/login/Providers.java
@@ -16,6 +16,8 @@
 import org.springframework.security.authentication.AuthenticationServiceException;
 import org.zowe.apiml.gateway.security.config.CompoundAuthProvider;
 import org.zowe.apiml.gateway.security.service.zosmf.ZosmfService;
+import org.zowe.apiml.message.log.ApimlLogger;
+import org.zowe.apiml.product.logging.annotations.InjectApimlLogger;
 import org.zowe.apiml.security.common.config.AuthConfigurationProperties;
 import org.zowe.apiml.security.common.error.ServiceNotAccessibleException;
 
@@ -27,18 +29,34 @@ public class Providers {
     private final CompoundAuthProvider compoundAuthProvider;
     private final ZosmfService zosmfService;
 
+    @InjectApimlLogger
+    private ApimlLogger apimlLog = ApimlLogger.empty();
+
     /**
      * This method decides whether the Zosmf service is available.
      *
      * @return Availability of the ZOSMF service in the system.
      * @throws AuthenticationServiceException if the z/OSMF service id is not configured
      */
     public boolean isZosmfAvailable() {
-        boolean isZosmfRegisteredAndPropagated = !this.discoveryClient.getInstances(authConfigurationProperties.validatedZosmfServiceId()).isEmpty();
-        log.debug("zOSMF registered with the Discovery Service and propagated to Gateway: {}", isZosmfRegisteredAndPropagated);
+        String  zosmfServiceId = authConfigurationProperties.validatedZosmfServiceId();
+        boolean isZosmfRegisteredAndPropagated = !this.discoveryClient.getInstances(zosmfServiceId).isEmpty();
+        if (!isZosmfRegisteredAndPropagated) {
+            apimlLog.log("org.zowe.apiml.security.auth.zosmf.serviceId", zosmfServiceId);
+        }
+            log.debug("z/OSMF registered with the Discovery Service and propagated to Gateway: {}", isZosmfRegisteredAndPropagated);
         return isZosmfRegisteredAndPropagated;
     }
 
+    /**
+     * Provide configured z/OSMF service ID from the Gateway auth configuration.
+     *
+     * @return service ID of z/OSMF instance
+     */
+    public String getZosmfServiceId() {
+        return authConfigurationProperties.validatedZosmfServiceId();
+    }
+
     /**
      * Verify that the zOSMF is registered in the Discovery service and that we can actually reach it.
      *
@@ -48,11 +66,12 @@ public boolean isZosmfAvailableAndOnline() {
         try {
             boolean isAvailable = isZosmfAvailable();
             boolean isAccessible = zosmfService.isAccessible();
-            log.debug("zOSMF is registered and propagated to the DS: {} and is accessible based on the information: {}", isAvailable, isAccessible);
+
+            log.debug("z/OSMF is registered and propagated to the DS: {} and is accessible based on the information: {}", isAvailable, isAccessible);
 
             return isAvailable && isAccessible;
-        } catch (ServiceNotAccessibleException exception) {
-            log.debug("zOSMF isn't registered to the Gateway yet");
+        } catch (ServiceNotAccessibleException e) {
+            log.debug("z/OSMF is not registered to the Gateway yet: {}", e.getMessage());
 
             return false;
         }

diff --git a/gateway-service/src/main/java/org/zowe/apiml/gateway/security/service/JwtSecurity.java b/gateway-service/src/main/java/org/zowe/apiml/gateway/security/service/JwtSecurity.java
@@ -10,6 +10,7 @@
 
 package org.zowe.apiml.gateway.security.service;
 
+import com.google.common.annotations.VisibleForTesting;
 import com.netflix.discovery.CacheRefreshedEvent;
 import com.netflix.discovery.EurekaEvent;
 import com.netflix.discovery.EurekaEventListener;
@@ -38,10 +39,7 @@
 import java.security.interfaces.RSAPublicKey;
 import java.time.Duration;
 import java.time.temporal.ChronoUnit;
-import java.util.ArrayList;
-import java.util.LinkedList;
-import java.util.List;
-import java.util.Optional;
+import java.util.*;
 
 import static org.awaitility.Awaitility.await;
 
@@ -77,16 +75,19 @@ public class JwtSecurity {
 
     private final Providers providers;
     private final ZosmfListener zosmfListener;
+    private final String zosmfServiceId;
 
-    private final List<String> events = new ArrayList<>();
+    private final Set<String> events = Collections.synchronizedSet(new HashSet<>());
 
     @Autowired
     public JwtSecurity(Providers providers, ApimlDiscoveryClient discoveryClient) {
         this.providers = providers;
+        this.zosmfServiceId = providers.getZosmfServiceId();
         this.zosmfListener = new ZosmfListener(discoveryClient);
     }
 
-    public JwtSecurity(Providers providers, String keyAlias, String keyStore, char[] keyStorePassword, char[] keyPassword, ApimlDiscoveryClient discoveryClient) {
+    @VisibleForTesting
+    JwtSecurity(Providers providers, String keyAlias, String keyStore, char[] keyStorePassword, char[] keyPassword, ApimlDiscoveryClient discoveryClient) {
         this(providers, discoveryClient);
 
         this.keyStore = keyStore;
@@ -120,8 +121,8 @@ public void loadAppropriateJwtKeyOrFail() {
         loadJwtSecret();
         switch (used) {
             case ZOSMF:
-                log.info("zOSMF is used as the JWT producer");
-                events.add("zOSMF is recognized as authentication provider.");
+                log.info("z/OSMF instance {} is used as the JWT producer", zosmfServiceId);
+                events.add(String.format("z/OSMF instance %s is recognized as authentication provider.", zosmfServiceId));
                 validateInitializationAgainstZosmf();
                 break;
             case APIML:
@@ -130,8 +131,8 @@ public void loadAppropriateJwtKeyOrFail() {
                 validateJwtSecret();
                 break;
             case UNKNOWN:
-                log.info("zOSMF is probably used as the JWT producer but isn't available yet.");
-                events.add("Wait for zOSMF to come online before deciding who provides JWT tokens.");
+                log.info("z/OSMF instance {} is probably used as the JWT producer but isn't available yet.", zosmfServiceId);
+                events.add(String.format("Wait for z/OSMF instance %s to come online before deciding who provides JWT tokens.", zosmfServiceId));
                 validateInitializationWhenZosmfIsAvailable();
                 break;
             default:
@@ -208,11 +209,11 @@ private HttpsConfig currentConfig() {
     private void validateInitializationAgainstZosmf() {
         if (!providers.zosmfSupportsJwt()) {
             events.add("API ML is responsible for token generation.");
-            log.debug("zOSMF is UP and does not support JWT");
+            log.debug("z/OSMF instance {} is UP and does not support JWT", zosmfServiceId);
             validateJwtSecret();
         } else {
-            events.add("zOSMF is UP and supports JWT");
-            log.debug("zOSMF is UP and supports JWT");
+            events.add(String.format("z/OSMF instance %s is UP and supports JWT", zosmfServiceId));
+            log.debug("z/OSMF instance {} is UP and supports JWT", zosmfServiceId);
         }
     }
 
@@ -260,16 +261,18 @@ private void validateInitializationWhenZosmfIsAvailable() {
 
         new Thread(() -> {
             try {
-                events.add("Started waiting for zOSMF to be registered and known by the discovery service");
-                log.debug("Waiting for zOSMF to be registered and known by the Discovery Service.");
+                events.add("Started waiting for z/OSMF instance " + zosmfServiceId + " to be registered and known by the discovery service");
+                log.debug("Waiting for z/OSMF instance {} to be registered and known by the Discovery Service.", zosmfServiceId);
                 await()
                     .atMost(Duration.of(timeout, ChronoUnit.MINUTES))
                     .with()
                     .pollInterval(Durations.ONE_MINUTE)
                     .until(zosmfListener::isZosmfReady);
             } catch (ConditionTimeoutException e) {
-                apimlLog.log("org.zowe.apiml.gateway.jwtProducerConfigError", StringUtils.join(events, "\n"));
-                apimlLog.log("org.zowe.apiml.security.zosmfInstanceNotFound", "zOSMF");
+                synchronized (events) {
+                    apimlLog.log("org.zowe.apiml.gateway.jwtProducerConfigError", StringUtils.join(events, "\n"));
+                }
+                apimlLog.log("org.zowe.apiml.security.zosmfInstanceNotFound", zosmfServiceId);
                 System.exit(1);
             }
         }).start();
@@ -278,6 +281,7 @@ private void validateInitializationWhenZosmfIsAvailable() {
     /**
      * Only for unit testing
      */
+    @VisibleForTesting
     ZosmfListener getZosmfListener() {
         return zosmfListener;
     }
@@ -299,20 +303,24 @@ public void onEvent(EurekaEvent event) {
                 }
 
                 events.add("Discovery Service Cache was updated.");
-                log.debug("Trying to reach the zOSMF.");
+                log.debug("Trying to reach the z/OSMF instance " + zosmfServiceId + ".");
                 if (providers.isZosmfAvailableAndOnline()) {
-                    events.add("zOSMF is avaiable and online.");
-                    log.debug("The zOSMF was reached ");
+                    events.add("z/OSMF instance " + zosmfServiceId + " is available and online.");
+                    log.debug("The z/OSMF instance {} was reached.", zosmfServiceId);
 
                     discoveryClient.unregisterEventListener(this); // only need to see zosmf up once to validate jwt secret
                     isZosmfReady = true;
 
                     try {
                         validateInitializationAgainstZosmf();
                     } catch (HttpsConfigError e) {
-                        apimlLog.log("org.zowe.apiml.gateway.jwtProducerConfigError", StringUtils.join(events, "\n"));
+                        synchronized (events) {
+                            apimlLog.log("org.zowe.apiml.gateway.jwtProducerConfigError", StringUtils.join(events, "\n"));
+                        }
                         System.exit(1);
                     }
+                } else {
+                    events.add("z/OSMF instance " + zosmfServiceId + " is not available and online yet.");
                 }
             }
         };

diff --git a/...ice/src/main/java/org/zowe/apiml/gateway/security/service/zosmf/AbstractZosmfService.java b/...ice/src/main/java/org/zowe/apiml/gateway/security/service/zosmf/AbstractZosmfService.java
@@ -20,6 +20,7 @@
 import org.springframework.web.client.HttpClientErrorException;
 import org.springframework.web.client.ResourceAccessException;
 import org.springframework.web.client.RestClientException;
+import org.springframework.web.client.RestClientResponseException;
 import org.springframework.web.client.RestTemplate;
 import org.zowe.apiml.message.log.ApimlLogger;
 import org.zowe.apiml.product.logging.annotations.InjectApimlLogger;
@@ -28,6 +29,9 @@
 import org.zowe.apiml.security.common.login.LoginRequest;
 import org.zowe.apiml.util.EurekaUtils;
 
+import javax.net.ssl.SSLHandshakeException;
+
+import java.net.ConnectException;
 import java.nio.charset.StandardCharsets;
 import java.util.*;
 import java.util.function.Supplier;
@@ -144,15 +148,38 @@ protected String getURI(String zosmf) {
      */
     protected RuntimeException handleExceptionOnCall(String url, RuntimeException re) {
         if (re instanceof ResourceAccessException) {
+            if (re.getCause() instanceof SSLHandshakeException) {
+                log.error("SSL Misconfiguration, z/OSMF is not accessible. Please verify the following: \n" +
+                " - CN (Common Name) and z/OSMF hostname have to match.\n" +
+                " - Certificate is expired\n" +
+                " - TLS version match\n" +
+                "Further details and a stack trace will follow", re);
+            }
             apimlLog.log("org.zowe.apiml.security.serviceUnavailable", url, re.getMessage());
             return new ServiceNotAccessibleException("Could not get an access to z/OSMF service.");
         }
 
         if (re instanceof HttpClientErrorException.Unauthorized) {
+            log.warn("Request to z/OSMF requires authentication", re.getMessage());
             return new BadCredentialsException("Invalid Credentials");
         }
 
+        if (re instanceof RestClientResponseException) {
+            RestClientResponseException responseException = (RestClientResponseException) re;
+            if (log.isTraceEnabled()) {
+                log.trace("z/OSMF request {} failed with status code {}, server response: {}", url, responseException.getRawStatusCode(), responseException.getResponseBodyAsString());
+            } else {
+                log.debug("z/OSMF request {} failed with status code {}", url, responseException.getRawStatusCode());
+            }
+        }
+
+        if (re.getCause() instanceof ConnectException) {
+            log.warn("Could not connecto to z/OSMF. Please verify z/OSMF instance is up and running {}", re.getMessage());
+            return new ServiceNotAccessibleException("Could not connect to z/OSMF service.");
+        }
+
         if (re instanceof RestClientException) {
+            log.debug("z/OSMF isn't accessible. {}", re.getMessage());
             apimlLog.log("org.zowe.apiml.security.generic", re.getMessage(), url);
             return new AuthenticationServiceException("A failure occurred when authenticating.", re);
         }

diff --git a/...ervice/src/main/java/org/zowe/apiml/gateway/security/service/zosmf/ZosmfAuthResponse.java b/...ervice/src/main/java/org/zowe/apiml/gateway/security/service/zosmf/ZosmfAuthResponse.java
@@ -0,0 +1,22 @@
+/*
+ * This program and the accompanying materials are made available under the terms of the
+ * Eclipse Public License v2.0 which accompanies this distribution, and is available at
+ * https://www.eclipse.org/legal/epl-v20.html
+ *
+ * SPDX-License-Identifier: EPL-2.0
+ *
+ * Copyright Contributors to the Zowe Project.
+ */
+
+package org.zowe.apiml.gateway.security.service.zosmf;
+
+import lombok.Data;
+
+@Data
+public class ZosmfAuthResponse {
+
+    private int returnCode;
+    private int reasonCode;
+    private String message;
+
+}