Allow deleting orgkeys when remote versions are present (#1352)

* Allow deleting orgkeys when remote versions are present

* Ensure remote versions are excluded from versions using encryption

* audit allowlist lodash.set

* linting

* replace bunyan/express-bunyan-logger with pino/pino-http to avoid vulnerabilities

* linting

* testfix

app/apollo/index.js

@@ -73,27 +73,26 @@ const createDefaultApp = () => {
   return app;
 };
 
-const buildCommonApolloContext = async ({ models, req, res, connection }) => {
+const buildCommonApolloContext = async ({ models, req, res, connection, req_id }) => {
   if (connection) { // Operation is a Subscription
     const logger = connection.context.logger;
-    const req_id = connection.context.logger.fields.req_id;
     const req = connection.context.upgradeReq;
     const apiKey = connection.context.orgKey;
     const userToken = connection.context.userToken;
     const orgId = connection.context.orgId;
     const context = await initModule.buildApolloContext({ models, req, res, connection, logger });
     return { apiKey, req, req_id, userToken, recoveryHintsMap, orgId, ...context };
   } else if (req) { // Operation is a Query/Mutation
-    const logger = req.log; // request context logger created by express-bunyan-logger
+    const logger = req.log;
     const context = await initModule.buildApolloContext({ models, req, res, connection, logger });
     if (context.me && context.me.orgKey) {
       const org = await models.Organization.findOne( { $or: [ { orgKeys: context.me.orgKey }, { 'orgKeys2.key': context.me.orgKey } ] } );
-      logger.fields.org_id = org._id;
+      req.log = req.log.child({org_id: org._id});
     }
     if (context.me && context.me.org_id) {
-      logger.fields.org_id = context.me.org_id;
+      req.log = req.log.child({org_id: context.me.org_id});
     }
-    return { req, req_id: logger.fields.req_id, recoveryHintsMap, ...context }; // req_id = req.id
+    return { req, req_id, recoveryHintsMap, ...context };
   }
 };
 
@@ -199,7 +198,8 @@ const createApolloServer = (schema) => {
         models,
         req,
         res,
-        connection
+        connection,
+        req_id: uuid()
       });
     },
   });
@@ -238,7 +238,7 @@ const createSubscriptionServer = (httpServer, apolloServer, schema) => {
         }
         // add original upgrade request to the context
         const subscriptionContext = { me, upgradeReq: webSocket.upgradeReq, logger, orgKey, orgId };
-        return await buildCommonApolloContext( { models, req: context.request, res: { this_is_a_dummy_response: true }, connection: { context: subscriptionContext } } );
+        return await buildCommonApolloContext( { models, req: context.request, res: { this_is_a_dummy_response: true }, connection: { context: subscriptionContext }, req_id } );
       },
     },
     {

app/apollo/resolvers/organization.js

@@ -330,7 +330,26 @@ const organizationResolvers = {
         Re-encryption is ASYNCHRONOUS and could fail for various reasons (pod evicted, database failure, etc), so re-encryption is triggered again when attempting to delete any OrgKey that is still used for encryption.
         */
         // Ensure not removing a potentially in-use OrgKey (for version content encryption) (cannot force)
-        const versionsUsingOrgKey = await models.DeployableVersion.find({ org_id: orgId, $or: [ { verifiedOrgKeyUuid: { $exists: false } }, { desiredOrgKeyUuid: { $exists: false } }, {verifiedOrgKeyUuid: foundOrgKey.orgKeyUuid}, {desiredOrgKeyUuid: foundOrgKey.orgKeyUuid} ] });
+        const versionsUsingOrgKey = await models.DeployableVersion.find(
+          {
+            org_id: orgId,
+            $and: [
+              // Include all versions using the orgKey or not specifying which orgKey is used (could have been created before orgKey mgmt introduced and not yet updated)
+              { $or: [
+                { verifiedOrgKeyUuid: { $exists: false } },
+                { desiredOrgKeyUuid: { $exists: false } },
+                { verifiedOrgKeyUuid: foundOrgKey.orgKeyUuid },
+                { desiredOrgKeyUuid: foundOrgKey.orgKeyUuid }
+              ] },
+              // Omit remote versions, which do not use encryption via orgkey -- the content data is stored elsewhere
+              { $or: [
+                { 'content.metadata.type': { $exists: false } },
+                { 'content.metadata.type': { $ne: 'remote' } },
+              ]}
+            ]
+          }
+        );
+
         if( versionsUsingOrgKey.length > 0 ) {
           // Forbidden
           logger.warn({ req_id, user, orgId, uuid, forceDeletion }, `${queryName} OrgKey cannot be removed because it is in use (version encryption).` );

app/apollo/utils/versionUtils.js

@@ -165,6 +165,12 @@ const updateVersionEncryption = async (context, org, version, newOrgKey) => {
   const logContext = { req_id, user: whoIs(me), orgId: org.uuid, version: version.uuid, orgKey: newOrgKey.orgKeyUuid, methodName: 'updateVersionEncryption' };
   logger.info( logContext, 'Entry' );
 
+  // If this version is 'remote' (i.e. not using encryption), return success
+  if( version.content && version.content.metadata && version.content.metadata.type == 'remote' ) {
+    logger.info( logContext, 'Version does not use encryption, continue' );
+    return( true );
+  }
+
   // Re-retrieve the Org from the DB
   try {
     org = await models.Organization.findById(org._id);

app/log.js

@@ -1,5 +1,5 @@
 /**
-* Copyright 2019 IBM Corp. All Rights Reserved.
+* Copyright 2019, 2023 IBM Corp. All Rights Reserved.
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
@@ -14,134 +14,47 @@
 * limitations under the License.
 */
 
-const bunyan = require('bunyan');
-const ebl = require('express-bunyan-logger');
+const pino = require('pino');
+const pinoHttp = require('pino-http');
 
-const responseCodeMapper = (status, err, meta) => {
-  if (meta && meta['req-headers'] && meta['req-headers']['authorization']) {
-    meta['req-headers']['authorization'] = 'Bearer [HIDDEN]';
-    meta['req-headers']['x-auth-refresh-token'] = 'Bearer [HIDDEN]';
-  }
-  if (meta && meta.method === 'OPTIONS' && status === 204) {
-    // skip OPTION request 204 response
-    return 'trace';
-  } else if (meta && meta.body && meta.body.operationName === 'IntrospectionQuery') {
-    // skip playground introspection query
-    return 'trace';
-  } else if (status === 500) {
-    return 'error';
-  } else if (status === 400 || status === 404) {
-    return 'warn';
-  } else if (status === 200 || status === 201) {
-    return 'debug';
-  } else {
-    return 'info';
-  }
-};
-
-/*
-    Request context logger
-*/
-const getExpressBunyanConfig = (route) => {
-  const result = {
-    src: false, // turn on if needed for local debugging
+const getPinoConfig = (route) => {
+  const config = {
     name: route,
-    parseUA: false,
-    excludes: ['referer', 'short-body'],
-    levelFn: responseCodeMapper,
-    obfuscate: ['req.headers.razee-org-key', 'req.headers.x-api-key', 'req.header.authorization', 'req.header.org-admin-key', 'req.body.variables.login', 'req.body.variables.password', 'req.body.variables.email', 'req.body.variables.name'],
-    streams: [{
-      level: process.env.LOG_LEVEL || 'info',
-      stream: process.stdout
-    }],
-    serializers: {
-      /*
-      The body for resource updates from managed clusters can include details of the 'Impersonated-User' in object.status.children
-      The body for resource updates from managed clusters can include errors in object.status.razee-logs.error such as:
-        "[longsequenceofcharacters]": "Unable to fetch header secret data. { name: clustersubscription-[uuid]-secret, namespace: razeedeploy, key: razee-api-org-key }: secrets \"clustersubscription-[uuid]-secret\" is forbidden: User \"IAM#not-a-real-user@ibm.com\" cannot get resource \"secrets\" in API group \"\" in the namespace \"razeedeploy\""
-      When the resource updates are published in Razeedash-api app/apollo/subscription/index.js's resourceChangedFunc function, Express logs the body, including the user name.
-      To avoid logging the user name (PII of the user being impersonated), a custom 'body' serializer function is used to *truncate* unnecessary attributes and to *redact* any `IAM#` ids in errors.
-      Specifically, any error string containing \"IAM#SOMETHING\" will have it replaced with \"[REDACTED]\".
-      The truncation also helps minimize the size of the log entries created.
-      */
-      body: ( b => {
-        try {
-          const bodyArray = ( Array.isArray(b) ) ? b : [b];
-          for( const bodyElem of bodyArray ) {
-            if( bodyElem.object ) {
-              for( const objectKey of Object.keys(bodyElem.object) ) {
-                // Truncate object except specific desired properties
-                if( ! ['kind','apiVersion','metadata','status'].includes(objectKey) ) {
-                  bodyElem.object[objectKey] = '[TRUNCATED]';
-                  continue;
-                }
-                // Truncate object.metadata except specific desired properties
-                if( objectKey === 'metadata' ) {
-                  for( const metadataKey of Object.keys(bodyElem.object[objectKey]) ) {
-                    if( ! ['name','namespace','resourceVersion','selfLink','uid','creationTimestamp'].includes(metadataKey) ) {
-                      bodyElem.object[objectKey][metadataKey] = '[TRUNCATED]';
-                      continue;
-                    }
-                  }
-                }
-                // Truncate object.status except specific desired properties
-                else if( objectKey === 'status' ) {
-                  for( const statusKey of Object.keys(bodyElem.object[objectKey]) ) {
-                    if( ! ['last-modified','razee-logs'].includes(statusKey) ) {
-                      bodyElem.object[objectKey][statusKey] = '[TRUNCATED]';
-                    }
-                    // Redact object.status.razee-logs
-                    if( statusKey === 'razee-logs' && bodyElem.object[objectKey][statusKey].error ) {
-                      const error = bodyElem.object[objectKey][statusKey].error;
-                      Object.keys(error).forEach( k => {
-                        if( typeof error[k] === 'string' || error[k] instanceof String ) {
-                          let usrStartIdx = error[k].indexOf( '"IAM#' );
-                          while( usrStartIdx >= 0 ) {
-                            const usrEndIdx = error[k].indexOf( '"', usrStartIdx + 1 );
-                            if( usrEndIdx > usrStartIdx) {
-                              error[k] = error[k].substring( 0, usrStartIdx + 1 ) + '[REDACTED]' + error[k].substring(usrEndIdx);
-                              usrStartIdx = error[k].indexOf( '"IAM#' );
-                            }
-                            else {
-                              // userEndIdx not found, can't redact any more
-                              usrStartIdx = -1;
-                            }
-                          }
-                        }
-                      } );
-                    }
-                  }
-                }
-              }
-            }
-          }
-        }
-        catch(e) {
-          // If any unexpected error is encountered while redacting, continue
-          console.error( `Log redaction error: ${e.message}` );
-        }
-        return b;
-      } )
-    }
+    level: 'info',
+    redact: ['req.headers["razee-org-key"]','req.headers["authorization"]','req.headers["x-api-key"]','req.headers["org-admin-key"]'],
+    timestamp: pino.stdTimeFunctions.isoTime,
+    destination: pino.destination(1)  //stdout
   };
-  return result;
+  return config;
 };
 
-const getBunyanConfig = (route) => {
-  const result = {
-    src: false, // turn on if needed for local debugging
-    name: route,
-    streams: [{
-      level: process.env.LOG_LEVEL || 'info',
-      stream: process.stdout
-    }]
-  };
-  return result;
+const createExpressLogger = (route) => {
+  // Note: Pino does not log body by default (see https://github.com/pinojs/pino-http?tab=readme-ov-file#logging-request-body).
+  // If it is desired, care must be taken to ensure sensitive values are not exposed, nor logs stuffed with overlarge payloads.
+  // See pino 'serializers' option, and previously used 'serializer' implementation in earlier commits of this file.
+  return pinoHttp({
+    logger: pino(getPinoConfig(route)),
+    quietReqLogger: true,
+    customAttributeKeys: {
+      reqId: 'req_id'
+    },
+    customLogLevel: function (req, res, err) {
+      if (res.statusCode >= 400 && res.statusCode < 500) {
+        return 'warn';
+      } else if (res.statusCode >= 500 || err) {
+        return 'error';
+      }
+      return 'silent';
+    }
+  });
 };
 
-const createExpressLogger = (route) => ebl(getExpressBunyanConfig(route));
-const createLogger = (route, ids) => bunyan.createLogger({ ...getBunyanConfig(route), ...ids });
+const createLogger = (route, ids) => {
+  const config = getPinoConfig(route);
+  config.base = { ...config.base, ...ids };
+  return pino(config);
+};
 
-const log = bunyan.createLogger(getBunyanConfig('razeedash-api-test')); // logger for unit-tests
+const log = pino( getPinoConfig('razeedash-api-test') );  // logger for unit-tests
 
 module.exports = { createLogger, createExpressLogger, log };

app/routes/index.js

@@ -114,8 +114,7 @@ router.use(async (req, res, next) => {
 router.use(getOrg);
 
 router.use( (req, res, next) => {
-  const log = req.log;
-  if (req.org) log.fields.org_id = req.org._id;
+  if (req.org) req.log = req.log.child({org_id: req.org._id});
   next();
 });
 

audit-ci.json

@@ -1,6 +1,14 @@
 {
   "low": true,
-  "_allowlistInfo": "none",
+  "_allowListExample": [
+    {
+      "GHSA-1234-5678-9012": {
+        "active": true,
+        "notes": "The package X has vuln Y that is ignored because Y",
+        "expiry": "2077-04-01"
+      }
+    },
+  ],
   "allowlist": [],
   "skip-dev": true
 }