Merge pull request #195 from microsoft/beejones/Add-LogContext-to-Logger

upstream of transparanty kms logger
microsoft · Nov 15, 2024 · c79fceb · c79fceb
2 parents 6883aa7 + 2bb3a78
commit c79fceb
Show file tree

Hide file tree

Showing 22 changed files with 607 additions and 194 deletions.
diff --git a/.gitignore b/.gitignore
@@ -10,4 +10,5 @@ ccf-app/
 nohup.out
 aad.env
 *.log
+temp*/
 __pycache__/
diff --git a/governance/constitution/kms_actions.js b/governance/constitution/kms_actions.js
diff --git a/src/attestation/AttestationValidation.ts b/src/attestation/AttestationValidation.ts
@@ -12,24 +12,27 @@ import {
 } from "@microsoft/ccf-app/global";
 import { SnpAttestationClaims } from "./SnpAttestationClaims";
 import { keyReleasePolicyMap } from "../repositories/Maps";
-import { Logger } from "../utils/Logger";
+import { Logger, LogContext } from "../utils/Logger";
 import { KeyReleasePolicy } from "../policies/KeyReleasePolicy";
 
 // Validate the attestation by means of the key release policy
 export const validateAttestation = (
   attestation: ISnpAttestation,
 ): ServiceResult<string | IAttestationReport> => {
-  Logger.debug(`Start attestation validation`);
+  const logContext = new LogContext().appendScope("validateAttestation");
+  Logger.debug(`Start attestation validation`, logContext);
   if (!attestation) {
     return ServiceResult.Failed<string>(
       { errorMessage: "missing attestation" },
       400,
+      logContext
     );
   }
   if (!attestation.evidence && typeof attestation.evidence !== "string") {
     return ServiceResult.Failed<string>(
       { errorMessage: "missing or bad attestation.evidence" },
       400,
+      logContext
     );
   }
   if (
@@ -39,6 +42,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "missing or bad attestation.evidence" },
       400,
+      logContext
     );
   }
   if (
@@ -48,6 +52,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "missing or bad attestation.uvm_endorsements" },
       400,
+      logContext
     );
   }
   if (
@@ -57,6 +62,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "missing or bad attestation.endorsed_tcb" },
       400,
+      logContext
     );
   }
   let evidence: ArrayBuffer;
@@ -71,6 +77,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "Malformed attestation.evidence" },
       400,
+      logContext
     );
   }
   try {
@@ -81,6 +88,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "Malformed attestation.endorsements" },
       400,
+      logContext
     );
   }
   try {
@@ -91,6 +99,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: "Malformed attestation.uvm_endorsements" },
       400,
+      logContext
     );
   }
   try {
@@ -104,14 +113,14 @@ export const validateAttestation = (
         endorsed_tcb,
       );
     Logger.debug(
-      `Attestation validation report: ${JSON.stringify(attestationReport)}`,
+      `Attestation validation report: ${JSON.stringify(attestationReport)}`, logContext
     );
 
     const claimsProvider = new SnpAttestationClaims(attestationReport);
     const attestationClaims = claimsProvider.getClaims();
-    Logger.debug(`Attestation claims: `, attestationClaims);
+    Logger.debug(`Attestation claims: `, logContext, attestationClaims);
     Logger.debug(
-      `Report Data: `,
+      `Report Data: `, logContext,
       attestationClaims["x-ms-sevsnpvm-reportdata"],
     );
 
@@ -121,9 +130,8 @@ export const validateAttestation = (
     Logger.debug(
       `Key release policy: ${JSON.stringify(
         keyReleasePolicy,
-      )}, keys: ${Object.keys(keyReleasePolicy)}, keys: ${
-        Object.keys(keyReleasePolicy).length
-      }`,
+      )}, keys: ${Object.keys(keyReleasePolicy)}, keys: ${Object.keys(keyReleasePolicy).length
+      }`, logContext
     );
 
     const policyValidationResult = KeyReleasePolicy.validateKeyReleasePolicy(
@@ -135,6 +143,7 @@ export const validateAttestation = (
     return ServiceResult.Failed<string>(
       { errorMessage: `Internal error: ${exception.message}` },
       500,
+      logContext
     );
   }
 };
diff --git a/src/authorization/AuthenticationService.ts b/src/authorization/AuthenticationService.ts
@@ -8,7 +8,7 @@ import { JwtValidator } from "./jwt/JwtValidator";
 import { IValidatorService } from "./IValidationService";
 import { UserCertValidator } from "./certs/UserCertValidator";
 import { MemberCertValidator } from "./certs/MemberCertValidator";
-import { Logger } from "../utils/Logger";
+import { Logger, LogContext } from "../utils/Logger";
 
 /**
  * CCF authentication policies
@@ -29,16 +29,18 @@ export class AuthenticationService implements IAuthenticationService {
     CcfAuthenticationPolicyEnum,
     IValidatorService
   >();
+  private logContext: LogContext;
 
-  constructor() {
+  constructor(logContext?: LogContext) {
+    this.logContext = (logContext?.clone() || new LogContext()).appendScope("AuthenticationService");
     this.validators.set(CcfAuthenticationPolicyEnum.Jwt, new JwtValidator());
     this.validators.set(
       CcfAuthenticationPolicyEnum.User_cert,
-      new UserCertValidator(),
+      new UserCertValidator(this.logContext),
     );
     this.validators.set(
       CcfAuthenticationPolicyEnum.Member_cert,
-      new MemberCertValidator(),
+      new MemberCertValidator(this.logContext),
     );
   }
 
@@ -53,10 +55,11 @@ export class AuthenticationService implements IAuthenticationService {
       const caller = request.caller as unknown as ccfapp.AuthnIdentityCommon;
       if (!caller) {
         // no caller policy
-        return [caller, ServiceResult.Succeeded("")];
+        return [caller, ServiceResult.Succeeded("", undefined, this.logContext)];
       }
       Logger.debug(
         `Authorization: isAuthenticated result (AuthenticationService)-> ${caller.policy},${JSON.stringify(caller)}`,
+        this.logContext
       );
       const validator = this.validators.get(
         <CcfAuthenticationPolicyEnum>caller.policy,
@@ -68,7 +71,7 @@ export class AuthenticationService implements IAuthenticationService {
           ServiceResult.Failed({
             errorMessage: `Error: invalid caller identity (AuthenticationService)-> ${caller.policy}`,
             errorType: "AuthenticationError",
-          }),
+          }, 400, this.logContext),
         ];
       }
 
@@ -79,7 +82,7 @@ export class AuthenticationService implements IAuthenticationService {
         ServiceResult.Failed({
           errorMessage: `Error: invalid caller identity (AuthenticationService)-> ${ex}`,
           errorType: "AuthenticationError",
-        }),
+        }, 400, this.logContext),
       ];
     }
   }

diff --git a/src/authorization/certs/MemberCertValidator.ts b/src/authorization/certs/MemberCertValidator.ts
@@ -6,6 +6,7 @@ import { ccf } from "@microsoft/ccf-app/global";
 import { IValidatorService } from "../IValidationService";
 import { ServiceResult } from "../../utils/ServiceResult";
 import { UserMemberAuthnIdentity } from "./UserCertValidator";
+import { LogContext } from "../../utils/Logger";
 
 /**
  * CCF member information
@@ -16,17 +17,23 @@ interface CCFMember {
 }
 
 export class MemberCertValidator implements IValidatorService {
+  private logContext: LogContext;
+
+  constructor(logContext?: LogContext) {
+    this.logContext = (logContext?.clone() || new LogContext()).appendScope("MemberCertValidator");
+  }
+
   validate(request: ccfapp.Request<any>): ServiceResult<string> {
     const memberCaller = request.caller as unknown as UserMemberAuthnIdentity;
     const identityId = memberCaller.id;
     const isValid = this.isActiveMember(identityId);
     if (isValid.success && isValid.body) {
-      return ServiceResult.Succeeded(identityId);
+      return ServiceResult.Succeeded(identityId, undefined, this.logContext);
     }
     return ServiceResult.Failed({
       errorMessage: `Error: invalid caller identity (MemberCertValidator)->${JSON.stringify(isValid)}`,
       errorType: "AuthenticationError",
-    });
+    }, 400, this.logContext);
   }
 
   /**
@@ -54,12 +61,12 @@ export class MemberCertValidator implements IValidatorService {
     if (memberInfoBuf !== undefined) {
       const memberInfo = ccf.bufToJsonCompatible(memberInfoBuf) as CCFMember;
       const isActiveMember = memberInfo && memberInfo.status === "Active";
-      return ServiceResult.Succeeded(isActiveMember && isMember);
+      return ServiceResult.Succeeded(isActiveMember && isMember, undefined, this.logContext);
     } else {
       // memberInfoBuf is undefined
       return ServiceResult.Failed({
         errorMessage: "Member information is undefined.",
-      });
+      }, 400, this.logContext);
     }
   }
 }
diff --git a/src/authorization/certs/UserCertValidator.ts b/src/authorization/certs/UserCertValidator.ts
@@ -5,6 +5,7 @@ import * as ccfapp from "@microsoft/ccf-app";
 import { ccf } from "@microsoft/ccf-app/global";
 import { IValidatorService } from "../IValidationService";
 import { ServiceResult } from "../../utils/ServiceResult";
+import { LogContext } from "../../utils/Logger";
 
 /**
  * CCF user and member authentication identity
@@ -31,17 +32,23 @@ export interface UserMemberAuthnIdentity extends ccfapp.AuthnIdentityCommon {
 }
 
 export class UserCertValidator implements IValidatorService {
+  private logContext: LogContext;
+
+  constructor(logContext?: LogContext) {
+    this.logContext = (logContext?.clone() || new LogContext()).appendScope("UserCertValidator");
+  }
+
   validate(request: ccfapp.Request<any>): ServiceResult<string> {
     const userCaller = request.caller as unknown as UserMemberAuthnIdentity;
     const identityId = userCaller.id;
     const isValid = this.isUser(identityId);
     if (isValid.success && isValid.body) {
-      return ServiceResult.Succeeded(identityId);
+      return ServiceResult.Succeeded(identityId, undefined, this.logContext);
     }
     return ServiceResult.Failed({
       errorMessage: `Error: invalid caller identity (UserCertValidator)->${JSON.stringify(isValid)}`,
       errorType: "AuthenticationError",
-    });
+    }, 400, this.logContext);
   }
 
   /**
@@ -57,6 +64,6 @@ export class UserCertValidator implements IValidatorService {
       ccfapp.arrayBuffer,
     );
     const result = usersCerts.has(ccf.strToBuf(userId));
-    return ServiceResult.Succeeded(result);
+    return ServiceResult.Succeeded(result, undefined, this.logContext);
   }
 }
diff --git a/src/authorization/jwt/DemoJwtProvider.ts b/src/authorization/jwt/DemoJwtProvider.ts
@@ -5,12 +5,13 @@ import * as ccfapp from "@microsoft/ccf-app";
 import { ServiceResult } from "../../utils/ServiceResult";
 import { IJwtIdentityProvider } from "./IJwtIdentityProvider";
 import { authorizeJwt } from "./MsJwtProvider";
-import { Logger } from "../../utils/Logger";
+import { Logger, LogContext } from "../../utils/Logger";
 
 const errorType = "AuthenticationError";
 
 export class DemoJwtProvider implements IJwtIdentityProvider {
   constructor(public name: string) {}
+  private static readonly logContext = new LogContext().appendScope("DemoJwtProvider");
 
   /**
    * Check if caller's access token is valid
@@ -25,7 +26,7 @@ export class DemoJwtProvider implements IJwtIdentityProvider {
       return ServiceResult.Failed({
         errorMessage: "The JWT has no valid iss",
         errorType,
-      });
+      }, 400, DemoJwtProvider.logContext);
     }
 
     const isAuthorized = authorizeJwt(issuer, identity);
@@ -34,7 +35,7 @@ export class DemoJwtProvider implements IJwtIdentityProvider {
     }
 
     const identityId = identity?.jwt?.payload?.sub;
-    Logger.debug(`JWT validation succeeded: ${identityId}`);
-    return ServiceResult.Succeeded(identityId);
+    Logger.debug(`JWT validation succeeded: ${identityId}`, DemoJwtProvider.logContext);
+    return ServiceResult.Succeeded(identityId, undefined, DemoJwtProvider.logContext);
   }
 }
diff --git a/src/authorization/jwt/JwtValidationPolicyMap.ts b/src/authorization/jwt/JwtValidationPolicyMap.ts
@@ -1,32 +1,33 @@
 import { ccf } from "@microsoft/ccf-app/global";
-import { Logger } from "../../utils/Logger";
+import { Logger, LogContext } from "../../utils/Logger";
 
 const validationPolicyMapName = "public:ccf.gov.policies.jwt_validation";
 
 export class JwtValidationPolicyMap {
-  public static read(issuer: string): { [key: string]: string } | undefined {
+  public static read(issuer: string, logContextIn? : LogContext): { [key: string]: string } | undefined {
+    const logContext = (logContextIn?.clone() || new LogContext()).appendScope("JwtValidationPolicyMap");
     // For testing list all issuers
     const issuersMap = ccf.kv["public:ccf.gov.jwt.issuers"];
     issuersMap.forEach((v, k) => {
       let issuer = ccf.bufToStr(k);
       let info = ccf.bufToJsonCompatible(v);
-      Logger.debug(`Issuer: ${issuer}: ${JSON.stringify(info)}`);
+      Logger.debug(`Issuer: ${issuer}: ${JSON.stringify(info)}`, logContext);
     });
 
     const keyBuf = ccf.strToBuf(issuer);
     if (!ccf.kv[validationPolicyMapName].has(keyBuf)) {
-      Logger.error(`No JWT validation Policy for issuer: ${issuer}`);
+      Logger.error(`No JWT validation Policy for issuer: ${issuer}`, logContext);
       return undefined;
     }
 
     const policyBuf = ccf.kv[validationPolicyMapName].get(keyBuf);
     if (policyBuf === undefined) {
-      Logger.error(`Policy buffer is undefined for issuer: ${issuer}`);
+      Logger.error(`Policy buffer is undefined for issuer: ${issuer}`, logContext);
       return undefined;
     }
 
     const policy = ccf.bufToStr(policyBuf);
-    Logger.info(`JWT validation: Policy: ${policy} for issuer: ${issuer}`);
+    Logger.info(`JWT validation: Policy: ${policy} for issuer: ${issuer}`, logContext);
     return JSON.parse(policy);
   }
 }