From 535cbcd93a0cd91641a0641d028edf3027c93f09 Mon Sep 17 00:00:00 2001
From: Ruben Verborgh <ruben@verborgh.org>
Date: Tue, 1 Dec 2020 20:00:21 +0100
Subject: [PATCH] feat: Add LDP request logging.

---
 src/ldp/AuthenticatedLdpHandler.ts            | 26 ++++++++++++++++---
 test/unit/ldp/AuthenticatedLdpHandler.test.ts |  2 +-
 2 files changed, 23 insertions(+), 5 deletions(-)

diff --git a/src/ldp/AuthenticatedLdpHandler.ts b/src/ldp/AuthenticatedLdpHandler.ts
index cddbca4e7..c13694975 100644
--- a/src/ldp/AuthenticatedLdpHandler.ts
+++ b/src/ldp/AuthenticatedLdpHandler.ts
@@ -1,6 +1,7 @@
 import type { Credentials } from '../authentication/Credentials';
 import type { CredentialsExtractor } from '../authentication/CredentialsExtractor';
 import type { Authorizer } from '../authorization/Authorizer';
+import { getLoggerFor } from '../logging/LogUtil';
 import { HttpHandler } from '../server/HttpHandler';
 import type { HttpRequest } from '../server/HttpRequest';
 import type { HttpResponse } from '../server/HttpResponse';
@@ -52,6 +53,7 @@ export class AuthenticatedLdpHandler extends HttpHandler {
   private readonly authorizer!: Authorizer;
   private readonly operationHandler!: OperationHandler;
   private readonly responseWriter!: ResponseWriter;
+  private readonly logger = getLoggerFor(this);
 
   /**
    * Creates the handler.
@@ -110,10 +112,26 @@ export class AuthenticatedLdpHandler extends HttpHandler {
    * @returns A promise resolving to the generated Operation.
    */
   private async runHandlers(request: HttpRequest): Promise<ResponseDescription> {
-    const op: Operation = await this.requestParser.handleSafe(request);
+    this.logger.verbose(`Handling LDP request for ${request.url}`);
+
+    const operation: Operation = await this.requestParser.handleSafe(request);
+    this.logger.verbose(`Parsed ${operation.method} operation on ${operation.target.path}`);
+
     const credentials: Credentials = await this.credentialsExtractor.handleSafe(request);
-    const permissions: PermissionSet = await this.permissionsExtractor.handleSafe(op);
-    await this.authorizer.handleSafe({ credentials, identifier: op.target, permissions });
-    return this.operationHandler.handleSafe(op);
+    this.logger.verbose(`Extracted credentials: ${credentials.webID}`);
+
+    const permissions: PermissionSet = await this.permissionsExtractor.handleSafe(operation);
+    const { read, write, append } = permissions;
+    this.logger.verbose(`Required permissions are read: ${read}, write: ${write}, append: ${append}`);
+
+    try {
+      await this.authorizer.handleSafe({ credentials, identifier: operation.target, permissions });
+    } catch (error: unknown) {
+      this.logger.verbose(`Authorization failed: ${(error as any).message}`);
+      throw error;
+    }
+
+    this.logger.verbose(`Authorization succeeded, performing operation`);
+    return this.operationHandler.handleSafe(operation);
   }
 }
diff --git a/test/unit/ldp/AuthenticatedLdpHandler.test.ts b/test/unit/ldp/AuthenticatedLdpHandler.test.ts
index 690499cda..313b34343 100644
--- a/test/unit/ldp/AuthenticatedLdpHandler.test.ts
+++ b/test/unit/ldp/AuthenticatedLdpHandler.test.ts
@@ -16,7 +16,7 @@ describe('An AuthenticatedLdpHandler', (): void => {
   let responseFn: jest.Mock<Promise<void>, [any]>;
 
   beforeEach(async(): Promise<void> => {
-    const requestParser: RequestParser = new StaticAsyncHandler(true, 'parser' as any);
+    const requestParser: RequestParser = new StaticAsyncHandler(true, ({ target: 'target' }) as any);
     const credentialsExtractor: CredentialsExtractor = new StaticAsyncHandler(true, 'credentials' as any);
     const permissionsExtractor: PermissionsExtractor = new StaticAsyncHandler(true, 'permissions' as any);
     const authorizer: Authorizer = new StaticAsyncHandler(true, 'authorizer' as any);