Merge remote-tracking branch 'origin/issue/183_debug_logging_options'

into develop

dsf-bpe/dsf-bpe-server/pom.xml

@@ -42,6 +42,10 @@
 			<groupId>dev.dsf</groupId>
 			<artifactId>dsf-common-documentation</artifactId>
 		</dependency>
+		<dependency>
+			<groupId>dev.dsf</groupId>
+			<artifactId>dsf-common-db</artifactId>
+		</dependency>
 		<dependency>
 			<groupId>dev.dsf</groupId>
 			<artifactId>dsf-common-status</artifactId>

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/BpeJerseyApplication.java

@@ -1,13 +1,19 @@
 package dev.dsf.bpe;
 
+import java.util.logging.Level;
+
+import org.glassfish.jersey.logging.LoggingFeature;
+import org.glassfish.jersey.logging.LoggingFeature.Verbosity;
 import org.glassfish.jersey.server.ResourceConfig;
 import org.glassfish.jersey.server.filter.RolesAllowedDynamicFeature;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.springframework.web.context.WebApplicationContext;
 import org.springframework.web.context.support.WebApplicationContextUtils;
 
+import dev.dsf.bpe.spring.config.PropertiesConfig;
 import dev.dsf.common.auth.filter.AuthenticationFilter;
+import dev.dsf.common.auth.logging.CurrentUserLogger;
 import jakarta.inject.Inject;
 import jakarta.servlet.ServletContext;
 import jakarta.ws.rs.ApplicationPath;
@@ -41,5 +47,16 @@ public BpeJerseyApplication(ServletContext servletContext)
 
 		register(AuthenticationFilter.class);
 		register(RolesAllowedDynamicFeature.class);
+
+		if (context.getBean(PropertiesConfig.class).getDebugLogMessageCurrentUser())
+			register(CurrentUserLogger.class);
+
+		if (context.getBean(PropertiesConfig.class).getDebugLogMessageWebserviceRequest())
+		{
+			java.util.logging.Logger l = java.util.logging.Logger.getLogger(BpeJerseyApplication.class.getName());
+			l.setLevel(Level.FINE);
+			LoggingFeature loggingFeature = new LoggingFeature(l, Verbosity.HEADERS_ONLY);
+			register(loggingFeature);
+		}
 	}
 }

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/dao/AbstractDaoJdbc.java

@@ -2,14 +2,15 @@
 
 import java.util.Objects;
 
-import org.apache.commons.dbcp2.BasicDataSource;
+import javax.sql.DataSource;
+
 import org.springframework.beans.factory.InitializingBean;
 
 public abstract class AbstractDaoJdbc implements InitializingBean
 {
-	protected final BasicDataSource dataSource;
+	protected final DataSource dataSource;
 
-	public AbstractDaoJdbc(BasicDataSource dataSource)
+	public AbstractDaoJdbc(DataSource dataSource)
 	{
 		this.dataSource = dataSource;
 	}

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/dao/LastEventTimeDaoJdbc.java

@@ -10,18 +10,15 @@
 import java.util.Objects;
 import java.util.Optional;
 
-import org.apache.commons.dbcp2.BasicDataSource;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
+import javax.sql.DataSource;
+
 import org.springframework.beans.factory.InitializingBean;
 
 public class LastEventTimeDaoJdbc extends AbstractDaoJdbc implements LastEventTimeDao, InitializingBean
 {
-	private static final Logger logger = LoggerFactory.getLogger(LastEventTimeDaoJdbc.class);
-
 	private final String type;
 
-	public LastEventTimeDaoJdbc(BasicDataSource dataSource, String type)
+	public LastEventTimeDaoJdbc(DataSource dataSource, String type)
 	{
 		super(dataSource);
 
@@ -47,7 +44,6 @@ public Optional<LocalDateTime> readLastEventTime() throws SQLException
 		{
 			statement.setString(1, type);
 
-			logger.trace("Executing query '{}'", statement);
 			try (ResultSet result = statement.executeQuery())
 			{
 				if (result.next())
@@ -77,7 +73,6 @@ public LocalDateTime writeLastEventTime(LocalDateTime lastEvent) throws SQLExcep
 				statement.setString(3, type);
 				statement.setTimestamp(4, Timestamp.valueOf(lastEvent));
 
-				logger.trace("Executing query '{}'", statement);
 				statement.execute();
 			}
 		}

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/dao/ProcessPluginResourcesDaoJdbc.java

@@ -12,11 +12,10 @@
 import java.util.Objects;
 import java.util.UUID;
 
-import org.apache.commons.dbcp2.BasicDataSource;
+import javax.sql.DataSource;
+
 import org.hl7.fhir.r4.model.ResourceType;
 import org.postgresql.util.PGobject;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 
 import ca.uhn.fhir.parser.DataFormatException;
 import dev.dsf.bpe.plugin.ProcessIdAndVersion;
@@ -25,9 +24,7 @@
 
 public class ProcessPluginResourcesDaoJdbc extends AbstractDaoJdbc implements ProcessPluginResourcesDao
 {
-	private static final Logger logger = LoggerFactory.getLogger(ProcessPluginResourcesDaoJdbc.class);
-
-	public ProcessPluginResourcesDaoJdbc(BasicDataSource dataSource)
+	public ProcessPluginResourcesDaoJdbc(DataSource dataSource)
 	{
 		super(dataSource);
 	}
@@ -39,7 +36,6 @@ public Map<ProcessIdAndVersion, List<ResourceInfo>> getResources() throws SQLExc
 				PreparedStatement statement = connection.prepareStatement(
 						"SELECT process_key_and_version, resource_type, resource_id, url, version, name, identifier FROM process_plugin_resources ORDER BY process_key_and_version"))
 		{
-			logger.trace("Executing query '{}'", statement);
 			try (ResultSet result = statement.executeQuery())
 			{
 				Map<ProcessIdAndVersion, List<ResourceInfo>> resources = new HashMap<>();
@@ -117,7 +113,6 @@ public void addOrRemoveResources(Collection<? extends ProcessesResource> newReso
 							statement.setObject(6, uuidToPgObject(resourceInfo.getResourceId()));
 
 							statement.addBatch();
-							logger.trace("Executing query '{}'", statement);
 
 							statement.executeBatch();
 						}
@@ -145,7 +140,6 @@ else if (ResourceType.NamingSystem.equals(resourceType))
 							statement.setObject(4, uuidToPgObject(resourceInfo.getResourceId()));
 
 							statement.addBatch();
-							logger.trace("Executing query '{}'", statement);
 
 							statement.executeBatch();
 						}
@@ -173,7 +167,6 @@ else if (ResourceType.Task.equals(resourceType))
 							statement.setObject(4, uuidToPgObject(resourceInfo.getResourceId()));
 
 							statement.addBatch();
-							logger.trace("Executing query '{}'", statement);
 
 							statement.executeBatch();
 						}
@@ -194,7 +187,6 @@ else if (ResourceType.Task.equals(resourceType))
 					statement.setObject(1, uuidToPgObject(deletedId));
 
 					statement.addBatch();
-					logger.trace("Executing query '{}'", statement);
 				}
 
 				statement.executeBatch();
@@ -213,7 +205,6 @@ else if (ResourceType.Task.equals(resourceType))
 					statement.setString(1, process.toString());
 
 					statement.addBatch();
-					logger.trace("Executing query '{}'", statement);
 				}
 
 				statement.executeBatch();

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/dao/ProcessStateDaoJdbc.java

@@ -9,18 +9,14 @@
 import java.util.Map.Entry;
 import java.util.Objects;
 
-import org.apache.commons.dbcp2.BasicDataSource;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
+import javax.sql.DataSource;
 
 import dev.dsf.bpe.plugin.ProcessIdAndVersion;
 import dev.dsf.bpe.plugin.ProcessState;
 
 public class ProcessStateDaoJdbc extends AbstractDaoJdbc implements ProcessStateDao
 {
-	private static final Logger logger = LoggerFactory.getLogger(ProcessStateDaoJdbc.class);
-
-	public ProcessStateDaoJdbc(BasicDataSource dataSource)
+	public ProcessStateDaoJdbc(DataSource dataSource)
 	{
 		super(dataSource);
 	}
@@ -49,7 +45,6 @@ public void updateStates(Map<ProcessIdAndVersion, ProcessState> states) throws S
 					statement.addBatch();
 				}
 
-				logger.trace("Executing query '{}'", statement);
 				statement.executeBatch();
 			}
 		}

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/spring/config/DaoConfig.java

@@ -1,5 +1,7 @@
 package dev.dsf.bpe.spring.config;
 
+import javax.sql.DataSource;
+
 import org.apache.commons.dbcp2.BasicDataSource;
 import org.postgresql.Driver;
 import org.springframework.beans.factory.annotation.Autowired;
@@ -12,6 +14,7 @@
 import dev.dsf.bpe.dao.ProcessPluginResourcesDaoJdbc;
 import dev.dsf.bpe.dao.ProcessStateDao;
 import dev.dsf.bpe.dao.ProcessStateDaoJdbc;
+import dev.dsf.common.db.DataSourceWithLogger;
 
 @Configuration
 public class DaoConfig
@@ -20,7 +23,7 @@ public class DaoConfig
 	private PropertiesConfig propertiesConfig;
 
 	@Bean
-	public BasicDataSource dataSource()
+	public DataSource dataSource()
 	{
 		BasicDataSource dataSource = new BasicDataSource();
 		dataSource.setDriverClassName(Driver.class.getName());
@@ -31,7 +34,8 @@ public BasicDataSource dataSource()
 
 		dataSource.setTestOnBorrow(true);
 		dataSource.setValidationQuery("SELECT 1");
-		return dataSource;
+
+		return new DataSourceWithLogger(propertiesConfig.getDebugLogMessageDbStatement(), dataSource);
 	}
 
 	private String toString(char[] password)

dsf-bpe/dsf-bpe-server/src/main/java/dev/dsf/bpe/spring/config/PropertiesConfig.java

@@ -253,6 +253,18 @@ public class PropertiesConfig implements InitializingBean
 	@Value("${dev.dsf.bpe.debug.log.message.variablesLocal:false}")
 	private boolean debugLogMessageVariablesLocal;
 
+	@Documentation(description = "To enable logging of webservices requests set to `true`.", recommendation = "This debug function should only be activated during development. WARNNING: Confidential information may be leaked via the debug log!")
+	@Value("${dev.dsf.bpe.debug.log.message.webserviceRequest:false}")
+	private boolean debugLogMessageWebserviceRequest;
+
+	@Documentation(description = "To enable logging of DB queries set to `true`.", recommendation = "This debug function should only be activated during development. WARNNING: Confidential information may be leaked via the debug log!")
+	@Value("${dev.dsf.bpe.debug.log.message.dbStatement:false}")
+	private boolean debugLogMessageDbStatement;
+
+	@Documentation(description = "To enable logging of the currently requesting user set to `true`.", recommendation = "This debug function should only be activated during development. WARNNING: Confidential information may be leaked via the debug log!")
+	@Value("${dev.dsf.bpe.debug.log.message.currentUser:false}")
+	private boolean debugLogMessageCurrentUser;
+
 	@Value("${dev.dsf.server.status.port}")
 	private int jettyStatusConnectorPort;
 
@@ -599,6 +611,21 @@ public boolean getDebugLogMessageVariablesLocal()
 		return debugLogMessageVariablesLocal;
 	}
 
+	public boolean getDebugLogMessageWebserviceRequest()
+	{
+		return debugLogMessageWebserviceRequest;
+	}
+
+	public boolean getDebugLogMessageDbStatement()
+	{
+		return debugLogMessageDbStatement;
+	}
+
+	public boolean getDebugLogMessageCurrentUser()
+	{
+		return debugLogMessageCurrentUser;
+	}
+
 	public int getJettyStatusConnectorPort()
 	{
 		return jettyStatusConnectorPort;

dsf-bpe/pom.xml

@@ -134,6 +134,11 @@
 				<artifactId>dsf-common-documentation</artifactId>
 				<version>${project.version}</version>
 			</dependency>
+			<dependency>
+				<groupId>dev.dsf</groupId>
+				<artifactId>dsf-common-db</artifactId>
+				<version>${project.version}</version>
+			</dependency>
 			<dependency>
 				<groupId>dev.dsf</groupId>
 				<artifactId>dsf-common-jetty</artifactId>

dsf-common/dsf-common-auth/pom.xml

@@ -27,6 +27,10 @@
 			<groupId>jakarta.ws.rs</groupId>
 			<artifactId>jakarta.ws.rs-api</artifactId>
 		</dependency>
+		<dependency>
+			<groupId>jakarta.annotation</groupId>
+			<artifactId>jakarta.annotation-api</artifactId>
+		</dependency>
 
 		<dependency>
 			<groupId>org.springframework</groupId>

dsf-common/dsf-common-auth/src/main/java/dev/dsf/common/auth/logging/CurrentUserLogger.java

@@ -0,0 +1,62 @@
+package dev.dsf.common.auth.logging;
+
+import java.io.IOException;
+import java.security.Principal;
+import java.util.stream.Collectors;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import dev.dsf.common.auth.conf.Identity;
+import dev.dsf.common.auth.conf.OrganizationIdentity;
+import dev.dsf.common.auth.conf.PractitionerIdentity;
+import jakarta.annotation.Priority;
+import jakarta.ws.rs.ConstrainedTo;
+import jakarta.ws.rs.RuntimeType;
+import jakarta.ws.rs.container.ContainerRequestContext;
+import jakarta.ws.rs.container.ContainerRequestFilter;
+import jakarta.ws.rs.container.PreMatching;
+import jakarta.ws.rs.core.SecurityContext;
+
+@ConstrainedTo(RuntimeType.SERVER)
+@PreMatching
+@Priority(Integer.MIN_VALUE)
+public class CurrentUserLogger implements ContainerRequestFilter
+{
+	private static final Logger logger = LoggerFactory.getLogger(CurrentUserLogger.class);
+
+	@Override
+	public void filter(ContainerRequestContext requestContext) throws IOException
+	{
+		Identity identity = getCurrentIdentity(requestContext.getSecurityContext());
+
+		if (identity instanceof OrganizationIdentity)
+		{
+			logger.debug("Current organization identity '{}', dsf-roles {}", identity.getName(),
+					identity.getDsfRoles());
+		}
+		else if (identity instanceof PractitionerIdentity practitioner)
+		{
+			logger.debug("Current practitioner identity '{}', dsf-roles {}, practitioner-roles {}", identity.getName(),
+					identity.getDsfRoles(), practitioner.getPractionerRoles().stream()
+							.map(c -> c.getSystem() + "|" + c.getCode()).collect(Collectors.joining(", ", "[", "]")));
+		}
+	}
+
+	private Identity getCurrentIdentity(SecurityContext context)
+	{
+		Principal principal = context.getUserPrincipal();
+		if (principal != null)
+		{
+			if (principal instanceof Identity identity)
+				return identity;
+			else
+			{
+				logger.warn("Unknown current user principal of type {}", principal.getClass().getName());
+				return null;
+			}
+		}
+		else
+			return null;
+	}
+}

dsf-common/dsf-common-auth/src/main/java/dev/dsf/common/auth/logout/LogoutService.java

@@ -1,8 +1,5 @@
 package dev.dsf.common.auth.logout;
 
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
-
 import jakarta.servlet.ServletException;
 import jakarta.servlet.http.HttpServletRequest;
 import jakarta.ws.rs.GET;
@@ -15,13 +12,9 @@ public class LogoutService
 {
 	public static final String PATH = "logout";
 
-	private static final Logger logger = LoggerFactory.getLogger(LogoutService.class);
-
 	@GET
 	public void logout(@Context UriInfo uri, @Context HttpServletRequest request) throws ServletException
 	{
-		logger.trace("GET {}", uri.getRequestUri().toString());
-
 		request.logout();
 	}
 }