From 183e3b0daddbfb7b71b2bccad4faca39d47cf00b Mon Sep 17 00:00:00 2001 From: ethanstjohn Date: Fri, 2 Jun 2023 13:14:01 -0500 Subject: [PATCH 1/4] setup IAM timing log --- app/apollo/resolvers/cluster.js | 2 ++ 1 file changed, 2 insertions(+) diff --git a/app/apollo/resolvers/cluster.js b/app/apollo/resolvers/cluster.js index 230c23824..15296b5b0 100644 --- a/app/apollo/resolvers/cluster.js +++ b/app/apollo/resolvers/cluster.js @@ -562,6 +562,8 @@ const clusterResolvers = { try { logger.info({ req_id, user, org_id, registration }, `${queryName} validating`); + context.IAM_PERF = true; + await validAuth(me, org_id, ACTIONS.REGISTER, TYPES.CLUSTER, queryName, context); logger.info({ req_id, user, org_id, registration }, `${queryName} validating - authorized`); From 293b87dab6b1a74e21dc7b0a733a720e4a5bb5b2 Mon Sep 17 00:00:00 2001 From: ethanstjohn Date: Fri, 2 Jun 2023 14:29:42 -0500 Subject: [PATCH 2/4] log IAM call --- app/apollo/resolvers/cluster.js | 2 +- app/apollo/resolvers/common.js | 4 ++++ 2 files changed, 5 insertions(+), 1 deletion(-) diff --git a/app/apollo/resolvers/cluster.js b/app/apollo/resolvers/cluster.js index 15296b5b0..f62965c9c 100644 --- a/app/apollo/resolvers/cluster.js +++ b/app/apollo/resolvers/cluster.js @@ -562,8 +562,8 @@ const clusterResolvers = { try { logger.info({ req_id, user, org_id, registration }, `${queryName} validating`); + //step where IAM is authorized context.IAM_PERF = true; - await validAuth(me, org_id, ACTIONS.REGISTER, TYPES.CLUSTER, queryName, context); logger.info({ req_id, user, org_id, registration }, `${queryName} validating - authorized`); diff --git a/app/apollo/resolvers/common.js b/app/apollo/resolvers/common.js index 3d3bd3679..a5ed3c8ca 100644 --- a/app/apollo/resolvers/common.js +++ b/app/apollo/resolvers/common.js @@ -165,7 +165,11 @@ const validAuth = async (me, org_id, action, type, queryName, context, attrs = n // razeedash users (x-api-key) if(me && me.type == 'userToken'){ + //likely IAM location + const startTime = Date.now(); const result = await models.User.userTokenIsAuthorized(me, org_id, action, type, context); + const endTime = Date.now(); + if( context.IAM_PERF ) logger.info( {req_id, org_id, me, iam_time: endTime - startTime }, 'IAM api call completed' ); if(!result){ throw new RazeeForbiddenError( context.req.t('You are not allowed to {{action}} on {{type}} under organization {{org_id}} for the query {{queryName}}.', {'action':action, 'type':type, 'org_id':org_id, 'queryName':queryName, interpolation: { escapeValue: false }} From 9134ee9890b4a8577c2aa945c6b34c3fa00943b6 Mon Sep 17 00:00:00 2001 From: Ethan St John <42824212+ethanstjohn@users.noreply.github.com> Date: Mon, 28 Aug 2023 11:45:58 -0500 Subject: [PATCH 3/4] log how long it takes to validate registerCluster in IAM --- app/apollo/resolvers/common.js | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/app/apollo/resolvers/common.js b/app/apollo/resolvers/common.js index a5ed3c8ca..20a3199fc 100644 --- a/app/apollo/resolvers/common.js +++ b/app/apollo/resolvers/common.js @@ -165,11 +165,7 @@ const validAuth = async (me, org_id, action, type, queryName, context, attrs = n // razeedash users (x-api-key) if(me && me.type == 'userToken'){ - //likely IAM location - const startTime = Date.now(); const result = await models.User.userTokenIsAuthorized(me, org_id, action, type, context); - const endTime = Date.now(); - if( context.IAM_PERF ) logger.info( {req_id, org_id, me, iam_time: endTime - startTime }, 'IAM api call completed' ); if(!result){ throw new RazeeForbiddenError( context.req.t('You are not allowed to {{action}} on {{type}} under organization {{org_id}} for the query {{queryName}}.', {'action':action, 'type':type, 'org_id':org_id, 'queryName':queryName, interpolation: { escapeValue: false }} @@ -178,6 +174,9 @@ const validAuth = async (me, org_id, action, type, queryName, context, attrs = n } return; } + + // Debug: Find how long registerCluster() IAM validation takes + const startTime = Date.now(); if (me === null || !(await models.User.isAuthorized(me, org_id, action, type, attrs, context))) { logger.error({req_id, me: whoIs(me), org_id, action, type}, `ForbiddenError - ${queryName}`); if (type === TYPES.RESOURCE){ @@ -186,6 +185,8 @@ const validAuth = async (me, org_id, action, type, queryName, context, attrs = n throw new RazeeForbiddenError(context.req.t('You are not allowed to {{action}} on {{type}} under organization {{org_id}} for the query {{queryName}}.', {'action':action, 'type':type, 'org_id':org_id, 'queryName':queryName, interpolation: { escapeValue: false }}), context); } + const endTime = Date.now(); + if( context.IAM_PERF ) logger.info( {req_id, org_id, me, iam_time: endTime - startTime }, 'IAM api call completed' ); } }; From d5add9bb4ed963db2f9bac636129a6392a6d5aba Mon Sep 17 00:00:00 2001 From: Ethan St John <42824212+ethanstjohn@users.noreply.github.com> Date: Mon, 28 Aug 2023 11:47:13 -0500 Subject: [PATCH 4/4] Update common.js --- app/apollo/resolvers/common.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/app/apollo/resolvers/common.js b/app/apollo/resolvers/common.js index 20a3199fc..f034dd838 100644 --- a/app/apollo/resolvers/common.js +++ b/app/apollo/resolvers/common.js @@ -185,9 +185,9 @@ const validAuth = async (me, org_id, action, type, queryName, context, attrs = n throw new RazeeForbiddenError(context.req.t('You are not allowed to {{action}} on {{type}} under organization {{org_id}} for the query {{queryName}}.', {'action':action, 'type':type, 'org_id':org_id, 'queryName':queryName, interpolation: { escapeValue: false }}), context); } + } const endTime = Date.now(); if( context.IAM_PERF ) logger.info( {req_id, org_id, me, iam_time: endTime - startTime }, 'IAM api call completed' ); - } }; // a helper function to render clusterInfo for a list of resources