Add support for subsystem logging.properties

The CMSEngine, ACMEEngine, and ESTEngine have been modified
to support subsystem logging.properties. If the file exists,
it can be used to configure the logging level in various
libraries (e.g. RESTEasy) to help troubleshooting.

The CA, ACME, and EST tests have been modified to create
the subsystem logging.properties then check the debug log.

https://github.com/dogtagpki/pki/wiki/Configuring-Subsystem-Debug-Log

.github/workflows/acme-basic-test.yml

@@ -348,6 +348,18 @@ jobs:
       - name: Verify ACME in PKI container
         run: docker exec pki pki acme-info
 
+      - name: Update ACME configuration
+        run: |
+          # configure RESTEasy logging
+          docker exec -i pki tee /var/lib/pki/pki-tomcat/conf/acme/logging.properties << EOF
+          org.jboss.resteasy.level = INFO
+          EOF
+
+          docker exec pki chown pkiuser:pkiuser /var/lib/pki/pki-tomcat/conf/acme/logging.properties
+
+          # restart PKI server
+          docker exec pki pki-server restart --wait
+
       - name: Set up client container
         run: |
           tests/bin/runner-init.sh \

.github/workflows/ca-basic-test.yml

@@ -315,6 +315,13 @@ jobs:
           # enable CA signed audit log
           docker exec pki pki-server ca-config-set log.instance.SignedAudit.logSigning true
 
+          # configure RESTEasy logging
+          docker exec -i pki tee /var/lib/pki/pki-tomcat/conf/ca/logging.properties << EOF
+          org.jboss.resteasy.level = INFO
+          EOF
+
+          docker exec pki chown pkiuser:pkiuser /var/lib/pki/pki-tomcat/conf/ca/logging.properties
+
           # restart PKI server
           docker exec pki pki-server restart --wait
 

base/acme/src/main/java/org/dogtagpki/acme/server/ACMEEngine.java

@@ -27,6 +27,7 @@
 import java.util.Set;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.function.Consumer;
+import java.util.logging.Logger;
 
 import javax.ws.rs.WebApplicationException;
 import javax.ws.rs.core.Response;
@@ -192,7 +193,29 @@ public URL getBaseURL() {
         return config.getBaseURL();
     }
 
-    public void loadConfig(String filename) throws Exception {
+    public void loadLoggingProperties(String loggingProperties) throws Exception {
+
+        File file = new File(loggingProperties);
+        if (!file.exists()) return;
+
+        logger.info("Loading " + loggingProperties);
+        Properties properties = new Properties();
+        properties.load(new FileReader(file));
+
+        for (String key : properties.stringPropertyNames()) {
+            String value = properties.getProperty(key);
+
+            logger.info("- " + key + ": " + value);
+            if (!key.endsWith(".level")) continue;
+
+            String loggerName = key.substring(0, key.length() - 6);
+            java.util.logging.Level level = java.util.logging.Level.parse(value);
+
+            Logger.getLogger(loggerName).setLevel(level);
+        }
+    }
+
+    public void loadEngineConfig(String filename) throws Exception {
 
         File configFile = new File(filename);
 
@@ -452,7 +475,8 @@ public void start() throws Exception {
         String acmeConfDir = serverConfDir + File.separator + id;
 
         logger.info("ACME configuration directory: " + acmeConfDir);
-        loadConfig(acmeConfDir + File.separator + "engine.conf");
+        loadLoggingProperties(acmeConfDir + File.separator + "logging.properties");
+        loadEngineConfig(acmeConfDir + File.separator + "engine.conf");
 
         Boolean noncePersistent = config.getNoncesPersistent();
         this.noncesPersistent =  noncePersistent != null ? noncePersistent : false;

base/est/src/main/java/org/dogtagpki/est/ESTEngine.java

@@ -4,6 +4,7 @@
 import java.io.FileReader;
 import java.util.Map;
 import java.util.Properties;
+import java.util.logging.Logger;
 
 import org.apache.catalina.Realm;
 import org.apache.catalina.realm.RealmBase;
@@ -60,6 +61,7 @@ public void start(String contextPath) throws Throwable {
 
         logger.info("EST configuration directory: " + estConfDir);
 
+        loadLoggingProperties(estConfDir + File.separator + "logging.properties");
         initBackend(estConfDir + File.separator + "backend.conf");
         initRequestAuthorizer(estConfDir + File.separator + "authorizer.conf");
         initRealm(estConfDir + File.separator + "realm.conf");
@@ -87,6 +89,28 @@ public void stop() throws Throwable {
         logger.info("EST engine stopped");
     }
 
+    public void loadLoggingProperties(String loggingProperties) throws Exception {
+
+        File file = new File(loggingProperties);
+        if (!file.exists()) return;
+
+        logger.info("Loading " + loggingProperties);
+        Properties properties = new Properties();
+        properties.load(new FileReader(file));
+
+        for (String key : properties.stringPropertyNames()) {
+            String value = properties.getProperty(key);
+
+            logger.info("- " + key + ": " + value);
+            if (!key.endsWith(".level")) continue;
+
+            String loggerName = key.substring(0, key.length() - 6);
+            java.util.logging.Level level = java.util.logging.Level.parse(value);
+
+            Logger.getLogger(loggerName).setLevel(level);
+        }
+    }
+
     private void initBackend(String filename) throws Throwable {
         File file = new File(filename);
         if (!file.exists()) {
@@ -136,7 +160,7 @@ private void initRequestAuthorizer(String filename) throws Throwable {
     private void initRealm(String filename) throws Throwable {
         RealmConfig realmConfig = null;
         File realmConfigFile = new File(filename);
-        
+
         if (realmConfigFile.exists()) {
             logger.info("Loading EST realm config from " + realmConfigFile);
             Properties props = new Properties();

base/server/src/main/java/com/netscape/cmscore/apps/CMSEngine.java

@@ -32,8 +32,10 @@
 import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.Properties;
 import java.util.StringTokenizer;
 import java.util.Timer;
+import java.util.logging.Logger;
 
 import javax.servlet.http.HttpServlet;
 
@@ -122,8 +124,8 @@ public class CMSEngine {
 
     private static final String SERVER_XML = "server.xml";
 
-    public String id;
-    public String name;
+    public String id;   // subsystem ID (e.g. ca, kra)
+    public String name; // subsystem name (e.g. CA, KRA)
 
     public String instanceDir; /* path to instance <server-root>/cert-<instance-name> */
     private String instanceId;
@@ -418,8 +420,31 @@ public synchronized PasswordStore getPasswordStore() throws EBaseException {
     }
 
     public void initDebug() throws Exception {
+
         ConfigStore debugConfig = config.getSubStore(Debug.ID, ConfigStore.class);
         debug.init(debugConfig);
+
+        String subsystemConfDir = CMS.getInstanceDir() + File.separator + "conf" + File.separator + id;
+        String loggingProperties = subsystemConfDir + File.separator + "logging.properties";
+
+        File file = new File(loggingProperties);
+        if (!file.exists()) return;
+
+        logger.info("CMSEngine: Loading " + loggingProperties);
+        Properties properties = new Properties();
+        properties.load(new FileReader(file));
+
+        for (String key : properties.stringPropertyNames()) {
+            String value = properties.getProperty(key);
+
+            logger.info("CMSEngine: - " + key + ": " + value);
+            if (!key.endsWith(".level")) continue;
+
+            String loggerName = key.substring(0, key.length() - 6);
+            java.util.logging.Level level = java.util.logging.Level.parse(value);
+
+            Logger.getLogger(loggerName).setLevel(level);
+        }
     }
 
     public void initSubsystemListeners() throws Exception {

tests/ansible/est/tasks/main.yml

@@ -175,6 +175,14 @@
       roles=estclient
     mode: 420      # 0o644
 
+- name: Configure EST logging
+  community.docker.docker_container_copy_into:
+    container: "{{ pki_container }}"
+    container_path: /var/lib/pki/pki-tomcat/conf/est/logging.properties
+    content: |
+      org.jboss.resteasy.level = INFO
+    mode: 420      # 0o644
+
 - name: EST deploy and start
   community.docker.docker_container_exec:
     container: "{{ pki_container }}"
@@ -235,3 +243,10 @@
   failed_when: >
     ('subject=CN = client.example.com' not in enrol_subject_issuer.stdout_lines)  or
     ('issuer=O = EXAMPLE, OU = pki-tomcat, CN = CA Signing Certificate' not in enrol_subject_issuer.stdout_lines)
+
+- name: Check EST debug log
+  community.docker.docker_container_exec:
+    container: "{{ pki_container }}"
+    command: "{{ item }}"
+  loop:
+    - find /var/lib/pki/pki-tomcat/logs/est -name "debug.*" -exec cat {} \;