#174: Add User Action Logging

packages/data-model/docs/schema.dbml

@@ -92,7 +92,6 @@ table submissions {
   dictionary_id integer [not null]
   errors jsonb
   organization varchar [not null]
-  published_at timestamp
   status submission_status [not null]
   created_at timestamp [default: `now()`]
   created_by varchar

packages/data-provider/index.ts

@@ -20,6 +20,9 @@ export {
 } from './src/middleware/auth.js';
 export { errorHandler } from './src/middleware/errorHandler.js';
 
+// middleware
+export { actionLoggerMiddleware } from './src/middleware/actionLogger.js';
+
 // routes
 export { default as dictionaryRouters } from './src/routers/dictionaryRouter.js';
 export { default as migrationRouter } from './src/routers/migrationRouter.js';

packages/data-provider/src/config/config.ts

@@ -32,6 +32,7 @@ export type SubmissionServiceConfig = {
 export type LoggerConfig = {
 	level?: string;
 	file?: boolean;
+	routerLoggerEnabled?: boolean;
 };
 
 export type IdServiceConfig = {
@@ -72,6 +73,7 @@ export interface BaseDependencies {
 	features?: FeaturesConfig;
 	idService: IdServiceConfig;
 	logger: Logger;
+	routerLoggerEnabled: boolean;
 	onFinishCommit?: (resultOnCommit: ResultOnCommit) => Promise<void>;
 	schemaService: SchemaServiceConfig;
 	submissionService: SubmissionServiceConfig;

packages/data-provider/src/controllers/auditController.ts

@@ -8,8 +8,7 @@ import { AuditPaginatedResponse } from '../utils/types.js';
 
 const controller = (dependencies: BaseDependencies) => {
 	const auditService = auditSvc(dependencies);
-	const { logger } = dependencies;
-	const LOG_MODULE = 'AUDIT_CONTROLLER';
+
 	return {
 		byCategoryIdAndOrganization: validateRequest(auditByCatAndOrgRequestSchema, async (req, res, next) => {
 			try {
@@ -23,8 +22,6 @@ const controller = (dependencies: BaseDependencies) => {
 				// optional query parameters
 				const { entityName, eventType, startDate, endDate, systemId } = req.query;
 
-				logger.info(LOG_MODULE, 'Request Audit', `categoryId '${categoryId}' organization '${organization}'`);
-
 				const auditRecords = await auditService.byCategoryIdAndOrganization(categoryId, {
 					entityName,
 					eventType,

packages/data-provider/src/controllers/categoryController.ts

@@ -15,8 +15,6 @@ const controller = (dependencies: BaseDependencies) => {
 			try {
 				const categoryId = Number(req.params.categoryId);
 
-				logger.info(LOG_MODULE, 'Request Get Category Details', `categoryId '${categoryId}'`);
-
 				const details = await categoryService.getDetails(categoryId);
 
 				if (!details) {

packages/data-provider/src/controllers/dictionaryController.ts

@@ -7,8 +7,7 @@ import { BaseDependencies } from '../config/config.js';
 import dictionarySvc from '../services/dictionaryService.js';
 import { NotFound } from '../utils/errors.js';
 import { validateRequest } from '../utils/requestValidation.js';
-import { dictionaryRegisterRequestSchema } from '../utils/schemas.js';
-import { downloadDataFileTemplatesSchema } from '../utils/schemas.js';
+import { dictionaryRegisterRequestSchema, downloadDataFileTemplatesSchema } from '../utils/schemas.js';
 import { RegisterDictionaryResult } from '../utils/types.js';
 
 const controller = (dependencies: BaseDependencies) => {
@@ -25,11 +24,6 @@ const controller = (dependencies: BaseDependencies) => {
 				const forceRegistration = req.query.force?.toLowerCase() === 'true';
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					`Register Dictionary Request categoryName '${categoryName}' name '${dictionaryName}' version '${dictionaryVersion}'`,
-				);
-
 				const { dictionary, category, migrationId } = await dictionaryService.register({
 					categoryName,
 					dictionaryName,

packages/data-provider/src/controllers/submissionController.ts

@@ -42,17 +42,13 @@ const controller = ({
 }) => {
 	const submissionService = createSubmissionService(baseDependencies);
 	const dataService = createSubmittedDataService(baseDependencies);
-	const { logger } = baseDependencies;
-	const LOG_MODULE = 'SUBMISSION_CONTROLLER';
 	return {
 		commit: validateRequest(submissionCommitRequestSchema, async (req, res, next) => {
 			try {
 				const categoryId = Number(req.params.categoryId);
 				const submissionId = Number(req.params.submissionId);
 				const user = req.user;
 
-				logger.info(LOG_MODULE, `Request Commit Active Submission '${submissionId}' on category '${categoryId}'`);
-
 				const submission = await submissionService.getSubmissionById(submissionId);
 				if (!submission) {
 					throw new BadRequest(`Submission '${submissionId}' not found`);
@@ -77,8 +73,6 @@ const controller = ({
 				const user = req.user;
 				const force = req.query.force?.toLowerCase() === 'true';
 
-				logger.info(LOG_MODULE, `Request Delete Active Submission '${submissionId}'`);
-
 				const submission = await submissionService.getSubmissionById(submissionId);
 				if (!submission) {
 					throw new BadRequest(`Submission '${submissionId}' not found`);
@@ -116,11 +110,6 @@ const controller = ({
 				const index = req.query.index ? parseInt(req.query.index) : null;
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					`Request Delete '${entityName ? entityName : 'all'}' records on '{${actionType}}' Active Submission '${submissionId}'`,
-				);
-
 				const submission = await submissionService.getSubmissionById(submissionId);
 				if (!submission) {
 					throw new BadRequest(`Submission '${submissionId}' not found`);
@@ -157,8 +146,6 @@ const controller = ({
 				const systemId = req.params.systemId;
 				const user = req.user;
 
-				logger.info(LOG_MODULE, `Request Delete Submitted Data systemId '${systemId}' on categoryId '${categoryId}'`);
-
 				// get SubmittedData by SystemId
 				const foundRecordToDelete = await dataService.getSubmittedDataBySystemId(categoryId, systemId, {
 					view: 'flat',
@@ -192,8 +179,6 @@ const controller = ({
 				const payload = req.body;
 				const user = req.user;
 
-				logger.info(LOG_MODULE, `Request Edit Submitted Data`);
-
 				if (!payload || payload.length == 0) {
 					throw new BadRequest(
 						'The "payload" parameter is missing or empty. Please include the records in the request for processing.',
@@ -231,14 +216,6 @@ const controller = ({
 					const pageSize = parseInt(String(req.query.pageSize)) || DEFAULT_PAGE_SIZE;
 					const username = req.query.username;
 
-					logger.info(
-						LOG_MODULE,
-						`Request Submission categoryId '${categoryId}'`,
-						`pagination params: page '${page}' pageSize '${pageSize}'`,
-						`onlyActive '${onlyActive}'`,
-						`organization '${organization}'`,
-					);
-
 					const submissionsResult = await submissionService.getSubmissionsByCategory(
 						categoryId,
 						{ page, pageSize },
@@ -265,8 +242,6 @@ const controller = ({
 			try {
 				const submissionId = Number(req.params.submissionId);
 
-				logger.info(LOG_MODULE, `Request Active Submission submissionId '${submissionId}'`);
-
 				const submission = await submissionService.getSubmissionById(submissionId);
 
 				if (isEmpty(submission)) {
@@ -289,8 +264,6 @@ const controller = ({
 				const page = parseInt(String(req.query.page)) || DEFAULT_PAGE;
 				const pageSize = parseInt(String(req.query.pageSize)) || DEFAULT_PAGE_SIZE;
 
-				logger.info(LOG_MODULE, `Request Submission Details by ID '${submissionId}'`);
-
 				const submission = await submissionService.getSubmissionDetailsById({
 					submissionId,
 					paginationOptions: { page, pageSize },
@@ -311,11 +284,6 @@ const controller = ({
 				const categoryId = Number(req.params.categoryId);
 				const organization = req.params.organization;
 
-				logger.info(
-					LOG_MODULE,
-					`Request Active Submission categoryId '${categoryId}' and organization '${organization}'`,
-				);
-
 				// Get username from auth
 				const username = req.user?.username || '';
 
@@ -344,13 +312,6 @@ const controller = ({
 
 				// TODO: Validate file-entity map in body: no duplicate filenames, and that entities exist in schemaNames
 
-				logger.info(
-					LOG_MODULE,
-					`Submission Request: categoryId '${categoryId}'`,
-					` organization '${organization}'`,
-					` entityName '${entityName}'`,
-				);
-
 				// TODO: parse body payload
 
 				if (!payload || !Array.isArray(payload) || payload.length == 0) {
@@ -392,14 +353,6 @@ const controller = ({
 				// Get username from auth
 				const username = req.user?.username || '';
 
-				logger.info(
-					LOG_MODULE,
-					`Upload Submission Request: categoryId '${categoryId}'`,
-					` organization '${organization}'`,
-					` files '${files?.map((f) => f.originalname)}'`,
-					` fileEntityMap ${JSON.stringify(fileEntityMap)}`,
-				);
-
 				if (!shouldBypassAuth(req, authConfig) && !hasUserWriteAccess(organization, req.user)) {
 					throw new Forbidden(`User is not authorized to submit data to '${organization}'`);
 				}

packages/data-provider/src/controllers/submittedDataController.ts

@@ -42,13 +42,6 @@ const controller = ({
 				const view = convertToViewType(req.query.view) || defaultView;
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					`Request Submitted Data on categoryId '${categoryId}'`,
-					`pagination params: page '${page}' pageSize '${pageSize}'`,
-					`view '${view}'`,
-				);
-
 				const organizations = getUserReadableOrganizations(user);
 
 				const submittedDataResult = await service.getSubmittedDataByCategory(
@@ -89,13 +82,6 @@ const controller = ({
 				const view = convertToViewType(String(req.query.view)) || defaultView;
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					`Request Submitted Data on categoryId '${categoryId}' and organization '${organization}'`,
-					`pagination params: page '${page}' pageSize '${pageSize}'`,
-					`view '${view}'`,
-				);
-
 				if (!shouldBypassAuth(req, authConfig) && !hasUserReadAccess(organization, user)) {
 					throw new Forbidden(`User is not authorized to read submitted data for organization '${organization}'`);
 				}
@@ -142,15 +128,6 @@ const controller = ({
 				const pageSize = parseInt(String(req.query.pageSize)) || DEFAULT_PAGE_SIZE;
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					'Request Query Submitted Data',
-					`categoryId '${categoryId}'`,
-					`organization '${organization}'`,
-					`sqon '${JSON.stringify(sqon)}'`,
-					`pagination params: page '${page}' pageSize '${pageSize}'`,
-				);
-
 				if (!shouldBypassAuth(req, authConfig) && !hasUserReadAccess(organization, user)) {
 					throw new Forbidden(`User is not authorized to read submitted data for organization '${organization}'`);
 				}
@@ -191,14 +168,6 @@ const controller = ({
 				const view = convertToViewType(String(req.query.view)) || defaultView;
 				const user = req.user;
 
-				logger.info(
-					LOG_MODULE,
-					'Request Submitted Data',
-					`categoryId '${categoryId}'`,
-					`systemId '${systemId}'`,
-					`params: view '${view}'`,
-				);
-
 				const submittedDataResult = await service.getSubmittedDataBySystemId(categoryId, systemId, {
 					view,
 				});

packages/data-provider/src/controllers/validationController.ts

@@ -12,8 +12,6 @@ const controller = ({
 	baseDependencies: BaseDependencies;
 	validatorConfig: ValidatorConfig;
 }) => {
-	const { logger } = baseDependencies;
-	const LOG_MODULE = 'VALIDATION_CONTROLLER';
 	const validationSvc = validationService(baseDependencies);
 
 	return {
@@ -22,15 +20,6 @@ const controller = ({
 				const { categoryId, entityName } = req.params;
 				const { organization, value } = req.query;
 
-				logger.info(
-					LOG_MODULE,
-					'Validation Request',
-					`categoryId '${categoryId}'`,
-					`entityName '${entityName}'`,
-					`organization '${organization}'`,
-					`value '${value}'`,
-				);
-
 				// check if validator is enabled for this category, and entity name
 				const validatorEntry = findValidatorEntry({ validatorConfig, categoryId, entityName });
 

packages/data-provider/src/core/provider.ts

@@ -55,6 +55,7 @@ const provider = (configData: AppConfig, options?: ProviderOptions) => {
 		features: configData.features,
 		idService: configData.idService,
 		logger: getLogger(configData.logger),
+		routerLoggerEnabled: configData.logger.routerLoggerEnabled ?? true,
 		schemaService: configData.schemaService,
 		submissionService: configData.submissionService,
 		onFinishCommit: configData.onFinishCommit,

packages/data-provider/src/middleware/actionLogger.ts

@@ -0,0 +1,40 @@
+import type { NextFunction, Response } from 'express';
+
+import type { Logger } from '../config/logger.js';
+import { ActionResult, extractActionMetadata, formatActionLog } from '../utils/actionLoggerUtils.js';
+import type { RequestWithUser } from './auth.js';
+
+export type ActionLoggerConfig = {
+	enabled: boolean;
+};
+
+/**
+ * Action Logger Middleware
+ */
+export const actionLoggerMiddleware = (config: ActionLoggerConfig, logger: Logger) => {
+	return (req: RequestWithUser, res: Response, next: NextFunction) => {
+		// Skip logging if disabled
+		if (!config.enabled) {
+			return next();
+		}
+
+		/**
+		 * Log the action after response is sent
+		 */
+		res.on('finish', () => {
+			const metadata = extractActionMetadata(req);
+			// Extract metadata now that route has been matched and params are populated
+			const statusResult = res.statusCode >= 200 && res.statusCode < 400 ? ActionResult.ALLOWED : ActionResult.DENIED;
+
+			const logMessage = formatActionLog(metadata, statusResult, res.statusCode, res.locals.user);
+
+			if (statusResult === 'DENIED') {
+				logger.warn(logMessage);
+			} else {
+				logger.info(logMessage);
+			}
+		});
+
+		next();
+	};
+};

packages/data-provider/src/middleware/auth.ts

@@ -65,6 +65,8 @@ export const authMiddleware = (authConfig: AuthConfig) => {
 			const authResult =
 				typeof authConfig.customAuthHandler === 'function' ? await authConfig.customAuthHandler(req) : {};
 
+			// Define locals to access the user result in lyric actionLoggerMiddleware
+			res.locals.user = authResult.user;
 			if (authResult.errorCode) {
 				return res.status(authResult.errorCode).json({ message: authResult.errorMessage });
 			}

packages/data-provider/src/middleware/errorHandler.ts

@@ -52,5 +52,17 @@ export const errorHandler = (err: Error, req: Request, res: Response, _next: Nex
 			status = 500;
 	}
 
-	return res.status(status).send({ error: err.name, message: customizableMsg, details: details });
+	// Get request context from res.locals (set by validateRequest middleware)
+	const requestContext = res.locals.requestContext;
+	if (requestContext) {
+		req.params = requestContext.params || req.params;
+		req.query = requestContext.query || req.query;
+		req.body = requestContext.body || req.body;
+	}
+
+	return res.status(status).send({
+		error: err.name,
+		message: customizableMsg,
+		details: details,
+	});
 };

packages/data-provider/src/routers/auditRouter.ts

@@ -2,6 +2,7 @@ import { json, Router, urlencoded } from 'express';
 
 import { BaseDependencies } from '../config/config.js';
 import auditController from '../controllers/auditController.js';
+import { actionLoggerMiddleware } from '../middleware/actionLogger.js';
 import { type AuthConfig, authMiddleware } from '../middleware/auth.js';
 
 const router = ({
@@ -15,6 +16,7 @@ const router = ({
 	router.use(urlencoded({ extended: false }));
 	router.use(json());
 
+	router.use(actionLoggerMiddleware({ enabled: baseDependencies.routerLoggerEnabled }, baseDependencies.logger));
 	router.use(authMiddleware(authConfig));
 
 	router.get(