From 2ead5a8dc142ec92a887567c0ee4e17307fa0867 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Wed, 19 Jun 2024 23:13:16 +0530 Subject: [PATCH 01/12] chore: filtered logging and log for all destinations Signed-off-by: Sai Sankeerth --- src/adapters/network.js | 128 ++++++++++++++++-- src/logger.js | 34 +++-- .../networkHandler.js | 82 +++-------- .../utils.js | 20 +-- 4 files changed, 156 insertions(+), 108 deletions(-) diff --git a/src/adapters/network.js b/src/adapters/network.js index 850ba649c8..92411deab1 100644 --- a/src/adapters/network.js +++ b/src/adapters/network.js @@ -5,9 +5,9 @@ const lodash = require('lodash'); const http = require('http'); const https = require('https'); const axios = require('axios'); -const log = require('../logger'); +const logger = require('../logger'); const stats = require('../util/stats'); -const { removeUndefinedValues } = require('../v0/util'); +const { removeUndefinedValues, isDefinedAndNotNullAndNotEmpty } = require('../v0/util'); const { processAxiosResponse } = require('./utils/networkUtils'); // Only for tests const { setResponsesForMockAxiosAdapter } = require('../../test/testHelper'); @@ -56,7 +56,7 @@ const fireOutgoingReqStats = ({ statusCode, clientResponse, }) => { - const logMetaInfo = log.getLogMetadata(metadata); + const logMetaInfo = logger.getLogMetadata(metadata); stats.timing('outgoing_request_latency', startTime, { ...logMetaInfo, feature, @@ -118,6 +118,28 @@ const enhanceRequestOptions = (options) => { return requestOptions; }; +const getResponseDetails = (clientResponse) => { + if (!clientResponse.success) { + const { response } = clientResponse; + // non 2xx status handling for axios response + if (response) { + const { data, status, headers } = response; + return { + body: data || '', + status: status || 500, + ...(isDefinedAndNotNullAndNotEmpty(headers) ? { headers } : {}), + }; + } + return {}; + } + const { data, status, headers } = clientResponse.response; + return { + body: data || '', + status: status || 500, + ...(isDefinedAndNotNullAndNotEmpty(headers) ? { headers } : {}), + }; +}; + /** * sends an http request with underlying client, expects request options * @param {*} options @@ -128,14 +150,27 @@ const httpSend = async (options, statTags = {}) => { // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - const startTime = new Date(); const { url, data, method } = requestOptions; + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: options?.data, + method: options?.method || statTags?.requestMethod, + }, + }); + const startTime = new Date(); try { const response = await axios(requestOptions); clientResponse = { success: true, response }; } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } @@ -156,6 +191,15 @@ const httpGET = async (url, options, statTags = {}) => { // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: requestOptions?.data, + method: 'get', + }, + }); const startTime = new Date(); try { const response = await axios.get(url, requestOptions); @@ -163,6 +207,10 @@ const httpGET = async (url, options, statTags = {}) => { } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } setResponsesForMockAxiosAdapter({ url, options, method: 'GET' }, clientResponse); @@ -182,6 +230,15 @@ const httpDELETE = async (url, options, statTags = {}) => { // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: requestOptions?.data, + method: 'delete', + }, + }); const startTime = new Date(); try { const response = await axios.delete(url, requestOptions); @@ -189,6 +246,10 @@ const httpDELETE = async (url, options, statTags = {}) => { } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } setResponsesForMockAxiosAdapter({ url, options, method: 'DELETE' }, clientResponse); @@ -209,6 +270,15 @@ const httpPOST = async (url, data, options, statTags = {}) => { // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: data, + method: 'post', + }, + }); const startTime = new Date(); try { const response = await axios.post(url, data, requestOptions); @@ -216,6 +286,10 @@ const httpPOST = async (url, data, options, statTags = {}) => { } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } setResponsesForMockAxiosAdapter({ url, data, options, method: 'POST' }, clientResponse); @@ -235,7 +309,15 @@ const httpPUT = async (url, data, options, statTags = {}) => { let clientResponse; // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: data, + method: 'put', + }, + }); const startTime = new Date(); try { const response = await axios.put(url, data, requestOptions); @@ -243,6 +325,10 @@ const httpPUT = async (url, data, options, statTags = {}) => { } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } setResponsesForMockAxiosAdapter({ url, data, options, method: 'PUT' }, clientResponse); @@ -262,7 +348,15 @@ const httpPATCH = async (url, data, options, statTags = {}) => { let clientResponse; // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + logger.requestLog(`${commonMsg} request`, { + metadata: statTags?.metadata, + requestDetails: { + url, + body: data, + method: 'patch', + }, + }); const startTime = new Date(); try { const response = await axios.patch(url, data, requestOptions); @@ -270,6 +364,10 @@ const httpPATCH = async (url, data, options, statTags = {}) => { } catch (err) { clientResponse = { success: false, response: err }; } finally { + logger.responseLog(`${commonMsg} response`, { + metadata: statTags?.metadata, + responseDetails: getResponseDetails(clientResponse), + }); fireHTTPStats(clientResponse, startTime, statTags); } setResponsesForMockAxiosAdapter({ url, data, options, method: 'PATCH' }, clientResponse); @@ -352,7 +450,7 @@ const prepareProxyRequest = (request) => { // TODO: break; default: - log.debug(`body format ${payloadFormat} not supported`); + logger.debug(`body format ${payloadFormat} not supported`); } // Ref: https://github.com/rudderlabs/rudder-server/blob/master/router/network.go#L164 headers['User-Agent'] = 'RudderLabs'; @@ -426,14 +524,14 @@ const proxyRequest = async (request, destType) => { headers, method, }; - log.requestLog(`[${destType.toUpperCase()}] delivering data`, { - metadata, - requestDetails: { - body: data, - url: endpoint, - method, - }, - }); + // log.requestLog(`[${destType.toUpperCase()}] delivering data`, { + // metadata, + // requestDetails: { + // body: data, + // url: endpoint, + // method, + // }, + // }); const response = await httpSend(requestOptions, { feature: 'proxy', destType, diff --git a/src/logger.js b/src/logger.js index 6daff56c67..edea85284e 100644 --- a/src/logger.js +++ b/src/logger.js @@ -3,6 +3,8 @@ const { LOGLEVELS, structuredLogger } = require('@rudderstack/integrations-lib') // LOGGER_IMPL can be `console` or `winston` const loggerImpl = process.env.LOGGER_IMPL ?? 'winston'; +const logDestIds = (process.env.LOG_DEST_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated +const logWspIds = (process.env.LOG_WSP_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated let logLevel = process.env.LOG_LEVEL ?? 'error'; @@ -71,6 +73,24 @@ const formLogArgs = (args) => { return [msg, ...otherArgs]; }; +const isMetadataMatching = (m) => { + const isDestIdConfigured = logDestIds?.find?.((envDId) => envDId && envDId === m?.destinationId); + const isWspIdConfigured = logWspIds?.find?.( + (envWspId) => envWspId && envWspId === m?.workspaceId, + ); + return Boolean(isDestIdConfigured || isWspIdConfigured); +}; + +const getMatchedMetadata = (metadata) => { + if (!Array.isArray(metadata)) { + if (isMetadataMatching(metadata)) { + return [metadata]; + } + return []; + } + return metadata.filter((m) => isMetadataMatching(m)); +}; + /** * Perform logging operation on logMethod passed * @@ -143,8 +163,9 @@ const error = (...args) => { const requestLog = (identifierMsg, { metadata, requestDetails: { url, body, method } }) => { const logger = getLogger(); - if (LOGLEVELS[logLevel] === LOGLEVELS.warn) { - const reqLogArgs = [identifierMsg, { metadata, url, body, method }]; + const filteredMetadata = getMatchedMetadata(metadata); + if (LOGLEVELS[logLevel] === LOGLEVELS.warn && filteredMetadata.length > 0) { + const reqLogArgs = [identifierMsg, { metadata: filteredMetadata, url, body, method }]; log(logger.warn, reqLogArgs); } }; @@ -154,8 +175,9 @@ const responseLog = ( { metadata, responseDetails: { response: body, status, headers } }, ) => { const logger = getLogger(); - if (LOGLEVELS[logLevel] === LOGLEVELS.warn) { - const resLogArgs = [identifierMsg, { metadata, body, status, headers }]; + const filteredMetadata = getMatchedMetadata(metadata); + if (LOGLEVELS[logLevel] === LOGLEVELS.warn && filteredMetadata.length > 0) { + const resLogArgs = [identifierMsg, { metadata: filteredMetadata, body, status, headers }]; log(logger.warn, resLogArgs); } }; @@ -166,10 +188,6 @@ module.exports = { warn, error, setLogLevel, - // levelDebug, - // levelInfo, - // levelWarn, - // levelError, responseLog, getLogMetadata, requestLog, diff --git a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js index 51bc57d176..f0486c3b93 100644 --- a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js +++ b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js @@ -27,14 +27,6 @@ const conversionCustomVariableCache = new Cache(CONVERSION_CUSTOM_VARIABLE_CACHE const createJob = async ({ endpoint, headers, payload, metadata }) => { const endPoint = `${endpoint}:create`; - logger.requestLog(`[${destType.toUpperCase()}] job creation request`, { - metadata, - requestDetails: { - url: endpoint, - body: payload, - method: 'post', - }, - }); let createJobResponse = await httpPOST( endPoint, payload, @@ -49,15 +41,7 @@ const createJob = async ({ endpoint, headers, payload, metadata }) => { }, ); createJobResponse = processAxiosResponse(createJobResponse); - const { response, status, headers: responseHeaders } = createJobResponse; - logger.responseLog(`[${destType.toUpperCase()}] create job`, { - metadata, - responseDetails: { - headers: responseHeaders, - status, - response, - }, - }); + const { response, status } = createJobResponse; if (!isHttpStatusSuccess(status)) { throw new AbortedError( `[Google Ads Offline Conversions]:: ${response?.error?.message} during google_ads_offline_store_conversions Job Creation`, @@ -71,14 +55,6 @@ const createJob = async ({ endpoint, headers, payload, metadata }) => { const addConversionToJob = async ({ endpoint, headers, jobId, payload, metadata }) => { const endPoint = `${endpoint}/${jobId}:addOperations`; - logger.requestLog(`[${destType.toUpperCase()}] add conversion to job request`, { - metadata, - requestDetails: { - url: endpoint, - body: payload, - method: 'post', - }, - }); let addConversionToJobResponse = await httpPOST( endPoint, payload, @@ -93,15 +69,7 @@ const addConversionToJob = async ({ endpoint, headers, jobId, payload, metadata }, ); addConversionToJobResponse = processAxiosResponse(addConversionToJobResponse); - const { response, status, headers: responseHeaders } = addConversionToJobResponse; - logger.responseLog(`[${destType.toUpperCase()}] add conversion to job`, { - metadata, - responseDetails: { - response, - status, - headers: responseHeaders, - }, - }); + const { response, status } = addConversionToJobResponse; if (!isHttpStatusSuccess(status)) { throw new AbortedError( `[Google Ads Offline Conversions]:: ${response?.error?.message} during google_ads_offline_store_conversions Add Conversion`, @@ -115,15 +83,7 @@ const addConversionToJob = async ({ endpoint, headers, jobId, payload, metadata const runTheJob = async ({ endpoint, headers, payload, jobId, metadata }) => { const endPoint = `${endpoint}/${jobId}:run`; - logger.requestLog(`[${destType.toUpperCase()}] run job request`, { - metadata, - requestDetails: { - body: payload, - method: 'POST', - url: endPoint, - }, - }); - const { httpResponse: executeJobResponse, processedResponse } = await handleHttpRequest( + const { httpResponse: executeJobResponse } = await handleHttpRequest( 'post', endPoint, payload, @@ -137,15 +97,6 @@ const runTheJob = async ({ endpoint, headers, payload, jobId, metadata }) => { metadata, }, ); - const { headers: responseHeaders, response, status } = processedResponse; - logger.responseLog(`[${destType.toUpperCase()}] run job`, { - metadata, - responseDetails: { - response, - status, - responseHeaders, - }, - }); return executeJobResponse; }; @@ -339,11 +290,11 @@ const ProxyRequest = async (request) => { } } const requestBody = { url: endpoint, data: body.JSON, headers, method }; - logger.requestLog(`[${destType.toUpperCase()}] offline conversion creation request`, { - metadata, - requestDetails: { url: requestBody.url, body: requestBody.data, method }, - }); - const { httpResponse, processedResponse } = await handleHttpRequest('constructor', requestBody, { + // logger.requestLog(`[${destType.toUpperCase()}] offline conversion creation request`, { + // metadata, + // requestDetails: { url: requestBody.url, body: requestBody.data, method }, + // }); + const { httpResponse } = await handleHttpRequest('constructor', requestBody, { feature: 'proxy', destType: 'gogole_adwords_offline_conversions', endpointPath: `/proxy`, @@ -351,15 +302,14 @@ const ProxyRequest = async (request) => { module: 'dataDelivery', metadata, }); - const { headers: responseHeaders, status, response } = processedResponse; - logger.responseLog(`[${destType.toUpperCase()}] deliver event to destination`, { - metadata, - responseDetails: { - response, - headers: responseHeaders, - status, - }, - }); + // logger.responseLog(`[${destType.toUpperCase()}] deliver event to destination`, { + // metadata, + // responseDetails: { + // response, + // headers: responseHeaders, + // status, + // }, + // }); return httpResponse; }; diff --git a/src/v0/destinations/google_adwords_offline_conversions/utils.js b/src/v0/destinations/google_adwords_offline_conversions/utils.js index bf1773d450..7c21371ccf 100644 --- a/src/v0/destinations/google_adwords_offline_conversions/utils.js +++ b/src/v0/destinations/google_adwords_offline_conversions/utils.js @@ -30,13 +30,11 @@ const { CLICK_CONVERSION, trackCallConversionsMapping, consentConfigMap, - destType, } = require('./config'); const { processAxiosResponse } = require('../../../adapters/utils/networkUtils'); const Cache = require('../../util/cache'); const helper = require('./helper'); const { finaliseConsent } = require('../../util/googleUtils'); -const logger = require('../../../logger'); const conversionActionIdCache = new Cache(CONVERSION_ACTION_ID_CACHE_TTL); @@ -71,14 +69,6 @@ const getConversionActionId = async ({ headers, params, metadata }) => { const requestOptions = { headers, }; - logger.requestLog(`[${destType.toUpperCase()}] get conversion action id request`, { - metadata, - requestDetails: { - url: endpoint, - body: data, - method: 'post', - }, - }); let searchStreamResponse = await httpPOST(endpoint, data, requestOptions, { destType: 'google_adwords_offline_conversions', feature: 'transformation', @@ -88,15 +78,7 @@ const getConversionActionId = async ({ headers, params, metadata }) => { metadata, }); searchStreamResponse = processAxiosResponse(searchStreamResponse); - const { response, status, headers: responseHeaders } = searchStreamResponse; - logger.responseLog(`[${destType.toUpperCase()}] get conversion action id response`, { - metadata, - responseDetails: { - response, - status, - headers: responseHeaders, - }, - }); + const { response, status } = searchStreamResponse; if (!isHttpStatusSuccess(status)) { throw new AbortedError( `[Google Ads Offline Conversions]:: ${JSON.stringify( From 129965b0e3e659935b7591947f57078ed3e0593e Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Fri, 21 Jun 2024 13:53:02 +0530 Subject: [PATCH 02/12] chore: update request & response logs to info level, remove level based filtering --- src/logger.js | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/logger.js b/src/logger.js index edea85284e..3c2766240c 100644 --- a/src/logger.js +++ b/src/logger.js @@ -164,7 +164,7 @@ const error = (...args) => { const requestLog = (identifierMsg, { metadata, requestDetails: { url, body, method } }) => { const logger = getLogger(); const filteredMetadata = getMatchedMetadata(metadata); - if (LOGLEVELS[logLevel] === LOGLEVELS.warn && filteredMetadata.length > 0) { + if (filteredMetadata.length > 0) { const reqLogArgs = [identifierMsg, { metadata: filteredMetadata, url, body, method }]; log(logger.warn, reqLogArgs); } @@ -176,9 +176,9 @@ const responseLog = ( ) => { const logger = getLogger(); const filteredMetadata = getMatchedMetadata(metadata); - if (LOGLEVELS[logLevel] === LOGLEVELS.warn && filteredMetadata.length > 0) { + if (filteredMetadata.length > 0) { const resLogArgs = [identifierMsg, { metadata: filteredMetadata, body, status, headers }]; - log(logger.warn, resLogArgs); + log(logger.info, resLogArgs); } }; From cb516bc68bf64c4870928acb5c867e6b4c16221b Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Fri, 21 Jun 2024 15:00:46 +0530 Subject: [PATCH 03/12] chore: update to info log --- src/logger.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/logger.js b/src/logger.js index 3c2766240c..0c7b1738f7 100644 --- a/src/logger.js +++ b/src/logger.js @@ -166,7 +166,7 @@ const requestLog = (identifierMsg, { metadata, requestDetails: { url, body, meth const filteredMetadata = getMatchedMetadata(metadata); if (filteredMetadata.length > 0) { const reqLogArgs = [identifierMsg, { metadata: filteredMetadata, url, body, method }]; - log(logger.warn, reqLogArgs); + log(logger.info, reqLogArgs); } }; From 62613359e56c961f5c2e23a2ec4953cd403b29a0 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Fri, 21 Jun 2024 15:23:08 +0530 Subject: [PATCH 04/12] chore: clean-up code --- src/adapters/network.js | 8 -- .../networkHandler.js | 43 ++-------- .../networkHandler.js | 30 +------ .../networkHandler.js | 85 ++++--------------- src/v0/destinations/klaviyo/util.js | 22 +---- .../campaign_manager/networkHandler.js | 12 +-- src/v1/destinations/monday/networkHandler.js | 10 +-- 7 files changed, 30 insertions(+), 180 deletions(-) diff --git a/src/adapters/network.js b/src/adapters/network.js index 92411deab1..91d8d628fb 100644 --- a/src/adapters/network.js +++ b/src/adapters/network.js @@ -524,14 +524,6 @@ const proxyRequest = async (request, destType) => { headers, method, }; - // log.requestLog(`[${destType.toUpperCase()}] delivering data`, { - // metadata, - // requestDetails: { - // body: data, - // url: endpoint, - // method, - // }, - // }); const response = await httpSend(requestOptions, { feature: 'proxy', destType, diff --git a/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js b/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js index d82349c04d..68bccee753 100644 --- a/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js +++ b/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js @@ -39,10 +39,6 @@ const getConversionActionId = async ({ method, headers, params, metadata }) => { query: queryString, }; const searchStreamEndpoint = `${BASE_ENDPOINT}/${params.customerId}/googleAds:searchStream`; - logger.requestLog(`[${destType.toUpperCase()}] get conversion action id request`, { - metadata, - requestDetails: { url: searchStreamEndpoint, body: data, method }, - }); const requestBody = { url: searchStreamEndpoint, data, @@ -61,15 +57,7 @@ const getConversionActionId = async ({ method, headers, params, metadata }) => { metadata, }, ); - const { status, response, headers: responseHeaders } = gaecConversionActionIdResponse; - logger.responseLog(`[${destType.toUpperCase()}] get conversion action id response`, { - metadata, - responseDetails: { - response, - status, - headers: responseHeaders, - }, - }); + const { status, response } = gaecConversionActionIdResponse; if (!isHttpStatusSuccess(status)) { throw new NetworkError( `"${JSON.stringify( @@ -116,31 +104,14 @@ const ProxyRequest = async (request) => { 'conversionAdjustments[0].conversionAction', `customers/${params.customerId}/conversionActions/${conversionActionId}`, ); - logger.requestLog(`[${destType.toUpperCase()}] conversion enhancement request`, { - metadata, - requestDetails: { url: endpoint, body: body.JSON, method }, - }); const requestBody = { url: endpoint, data: body.JSON, headers, method }; - const { httpResponse: response, processedResponse } = await handleHttpRequest( - 'constructor', - requestBody, - { - destType: 'google_adwords_enhanced_conversions', - feature: 'proxy', - endpointPath: `/googleAds:uploadOfflineUserData`, - requestMethod: 'POST', - module: 'dataDelivery', - metadata, - }, - ); - const { response: processedResp, status, headers: responseHeaders } = processedResponse; - logger.responseLog(`[${destType.toUpperCase()}] conversion enhancement response`, { + const { httpResponse: response } = await handleHttpRequest('constructor', requestBody, { + destType: 'google_adwords_enhanced_conversions', + feature: 'proxy', + endpointPath: `/googleAds:uploadOfflineUserData`, + requestMethod: 'POST', + module: 'dataDelivery', metadata, - responseDetails: { - response: processedResp, - status, - headers: responseHeaders, - }, }); return response; }; diff --git a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js index f0486c3b93..26163bcf9a 100644 --- a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js +++ b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js @@ -118,14 +118,6 @@ const getConversionCustomVariable = async ({ headers, params, metadata }) => { const requestOptions = { headers, }; - logger.requestLog(`[${destType.toUpperCase()}] get conversion custom variable request`, { - metadata, - requestDetails: { - url: endpoint, - body: data, - method: 'post', - }, - }); let searchStreamResponse = await httpPOST(endpoint, data, requestOptions, { destType: 'google_adwords_offline_conversions', feature: 'proxy', @@ -135,15 +127,7 @@ const getConversionCustomVariable = async ({ headers, params, metadata }) => { metadata, }); searchStreamResponse = processAxiosResponse(searchStreamResponse); - const { response, status, headers: responseHeaders } = searchStreamResponse; - logger.responseLog(`[${destType.toUpperCase()}] get conversion custom variable`, { - metadata, - responseDetails: { - response, - status, - headers: responseHeaders, - }, - }); + const { response, status } = searchStreamResponse; if (!isHttpStatusSuccess(status)) { throw new NetworkError( `[Google Ads Offline Conversions]:: ${response?.[0]?.error?.message} during google_ads_offline_conversions response transformation`, @@ -290,10 +274,6 @@ const ProxyRequest = async (request) => { } } const requestBody = { url: endpoint, data: body.JSON, headers, method }; - // logger.requestLog(`[${destType.toUpperCase()}] offline conversion creation request`, { - // metadata, - // requestDetails: { url: requestBody.url, body: requestBody.data, method }, - // }); const { httpResponse } = await handleHttpRequest('constructor', requestBody, { feature: 'proxy', destType: 'gogole_adwords_offline_conversions', @@ -302,14 +282,6 @@ const ProxyRequest = async (request) => { module: 'dataDelivery', metadata, }); - // logger.responseLog(`[${destType.toUpperCase()}] deliver event to destination`, { - // metadata, - // responseDetails: { - // response, - // headers: responseHeaders, - // status, - // }, - // }); return httpResponse; }; diff --git a/src/v0/destinations/google_adwords_remarketing_lists/networkHandler.js b/src/v0/destinations/google_adwords_remarketing_lists/networkHandler.js index 82fb62b74e..4c9a9156e8 100644 --- a/src/v0/destinations/google_adwords_remarketing_lists/networkHandler.js +++ b/src/v0/destinations/google_adwords_remarketing_lists/networkHandler.js @@ -1,14 +1,12 @@ const { NetworkError } = require('@rudderstack/integrations-lib'); const { prepareProxyRequest, handleHttpRequest } = require('../../../adapters/network'); const { isHttpStatusSuccess, getAuthErrCategoryFromStCode } = require('../../util/index'); -const logger = require('../../../logger'); const { processAxiosResponse, getDynamicErrorType, } = require('../../../adapters/utils/networkUtils'); const tags = require('../../util/tags'); -const { destType } = require('./config'); /** * This function helps to create a offlineUserDataJobs * @param endpoint @@ -39,29 +37,13 @@ const createJob = async ({ endpoint, headers, method, params, metadata }) => { headers, method, }; - logger.requestLog(`[${destType.toUpperCase()}] job creation request`, { + const { httpResponse } = await handleHttpRequest('constructor', jobCreatingRequest, { + destType: 'google_adwords_remarketing_lists', + feature: 'proxy', + endpointPath: '/customers/create', + requestMethod: 'POST', + module: 'dataDelivery', metadata, - requestDetails: { - url: jobCreatingRequest.url, - body: jobCreatingRequest.data, - method: jobCreatingRequest.method, - }, - }); - const { httpResponse, processedResponse } = await handleHttpRequest( - 'constructor', - jobCreatingRequest, - { - destType: 'google_adwords_remarketing_lists', - feature: 'proxy', - endpointPath: '/customers/create', - requestMethod: 'POST', - module: 'dataDelivery', - metadata, - }, - ); - logger.responseLog(`[${destType.toUpperCase()}] job creation response`, { - metadata, - responseDetails: processedResponse, }); return httpResponse; }; @@ -82,29 +64,13 @@ const addUserToJob = async ({ endpoint, headers, method, jobId, body, metadata } headers, method, }; - logger.requestLog(`[${destType.toUpperCase()}] add user to job request`, { - metadata, - requestDetails: { - url: secondRequest.url, - body: secondRequest.data, - method: secondRequest.method, - }, - }); - const { httpResponse: response, processedResponse } = await handleHttpRequest( - 'constructor', - secondRequest, - { - destType: 'google_adwords_remarketing_lists', - feature: 'proxy', - endpointPath: '/addOperations', - requestMethod: 'POST', - module: 'dataDelivery', - metadata, - }, - ); - logger.responseLog(`[${destType.toUpperCase()}] add user to job response`, { + const { httpResponse: response } = await handleHttpRequest('constructor', secondRequest, { + destType: 'google_adwords_remarketing_lists', + feature: 'proxy', + endpointPath: '/addOperations', + requestMethod: 'POST', + module: 'dataDelivery', metadata, - responseDetails: processedResponse, }); return response; }; @@ -123,28 +89,13 @@ const runTheJob = async ({ endpoint, headers, method, jobId, metadata }) => { headers, method, }; - logger.requestLog(`[${destType.toUpperCase()}] run job request`, { - metadata, - requestDetails: { - url: thirdRequest.url, - body: thirdRequest.data, - method: thirdRequest.method, - }, - }); - const { httpResponse: response, processedResponse } = await handleHttpRequest( - 'constructor', - thirdRequest, - { - destType: 'google_adwords_remarketing_lists', - feature: 'proxy', - endpointPath: '/run', - requestMethod: 'POST', - module: 'dataDelivery', - }, - ); - logger.responseLog(`[${destType.toUpperCase()}] run job response`, { + const { httpResponse: response } = await handleHttpRequest('constructor', thirdRequest, { + destType: 'google_adwords_remarketing_lists', + feature: 'proxy', + endpointPath: '/run', + requestMethod: 'POST', + module: 'dataDelivery', metadata, - responseDetails: processedResponse, }); return response; }; diff --git a/src/v0/destinations/klaviyo/util.js b/src/v0/destinations/klaviyo/util.js index 4db59cfb05..3f6f6ca2ca 100644 --- a/src/v0/destinations/klaviyo/util.js +++ b/src/v0/destinations/klaviyo/util.js @@ -2,7 +2,6 @@ const { defaultRequestConfig } = require('rudder-transformer-cdk/build/utils'); const lodash = require('lodash'); const { NetworkError, InstrumentationError } = require('@rudderstack/integrations-lib'); const { WhiteListedTraits } = require('../../../constants'); -const logger = require('../../../logger'); const { constructPayload, @@ -18,13 +17,7 @@ const tags = require('../../util/tags'); const { handleHttpRequest } = require('../../../adapters/network'); const { JSON_MIME_TYPE, HTTP_STATUS_CODES } = require('../../util/constant'); const { getDynamicErrorType } = require('../../../adapters/utils/networkUtils'); -const { - BASE_ENDPOINT, - MAPPING_CONFIG, - CONFIG_CATEGORIES, - MAX_BATCH_SIZE, - destType, -} = require('./config'); +const { BASE_ENDPOINT, MAPPING_CONFIG, CONFIG_CATEGORIES, MAX_BATCH_SIZE } = require('./config'); const REVISION_CONSTANT = '2023-02-22'; @@ -43,14 +36,6 @@ const getIdFromNewOrExistingProfile = async ({ endpoint, payload, requestOptions let response; let profileId; const endpointPath = '/api/profiles'; - logger.requestLog(`[${destType.toUpperCase()}] get id from profile request`, { - metadata, - requestDetails: { - url: endpoint, - body: payload, - method: 'post', - }, - }); const { processedResponse: resp } = await handleHttpRequest( 'post', endpoint, @@ -62,12 +47,9 @@ const getIdFromNewOrExistingProfile = async ({ endpoint, payload, requestOptions endpointPath, requestMethod: 'POST', module: 'router', + metadata, }, ); - logger.responseLog(`[${destType.toUpperCase()}] get id from profile response`, { - metadata, - responseDetails: resp, - }); /** * 201 - profile is created with updated payload no need to update it again (suppress event with 299 status code) diff --git a/src/v1/destinations/campaign_manager/networkHandler.js b/src/v1/destinations/campaign_manager/networkHandler.js index eee3869fb5..300b5f9676 100644 --- a/src/v1/destinations/campaign_manager/networkHandler.js +++ b/src/v1/destinations/campaign_manager/networkHandler.js @@ -9,7 +9,6 @@ const { getDynamicErrorType, } = require('../../../adapters/utils/networkUtils'); const tags = require('../../../v0/util/tags'); -const logger = require('../../../logger'); function isEventAbortableAndExtractErrMsg(element, proxyOutputObj) { let isAbortable = false; @@ -39,16 +38,7 @@ const responseHandler = (responseParams) => { const { destinationResponse, rudderJobMetadata } = responseParams; const message = `[CAMPAIGN_MANAGER Response V1 Handler] - Request Processed Successfully`; const responseWithIndividualEvents = []; - const { response, status, headers } = destinationResponse; - - logger.responseLog('[campaign_manager] response handling', { - metadata: rudderJobMetadata, - responseDetails: { - headers, - response, - status, - }, - }); + const { response, status } = destinationResponse; if (isHttpStatusSuccess(status)) { // check for Partial Event failures and Successes diff --git a/src/v1/destinations/monday/networkHandler.js b/src/v1/destinations/monday/networkHandler.js index 5a0313a27b..fa54357873 100644 --- a/src/v1/destinations/monday/networkHandler.js +++ b/src/v1/destinations/monday/networkHandler.js @@ -42,16 +42,8 @@ const responseHandler = (responseParams) => { const message = '[MONDAY Response V1 Handler] - Request Processed Successfully'; const responseWithIndividualEvents = []; - const { response, status, headers } = destinationResponse; + const { response, status } = destinationResponse; - logger.responseLog('[monday] proxy response', { - metadata: rudderJobMetadata, - responseDetails: { - headers, - response, - status, - }, - }); // batching not supported if (isHttpStatusSuccess(status)) { const proxyOutput = { From c68f27f1ced1ce1bafa80da08f4bde9d4bc213f1 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Fri, 21 Jun 2024 15:27:06 +0530 Subject: [PATCH 05/12] chore: remove unused imports --- .../google_adwords_enhanced_conversions/networkHandler.js | 3 +-- .../google_adwords_offline_conversions/networkHandler.js | 1 - src/v1/destinations/monday/networkHandler.js | 1 - 3 files changed, 1 insertion(+), 4 deletions(-) diff --git a/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js b/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js index 68bccee753..21a5fff78b 100644 --- a/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js +++ b/src/v0/destinations/google_adwords_enhanced_conversions/networkHandler.js @@ -4,9 +4,8 @@ const { NetworkError, NetworkInstrumentationError } = require('@rudderstack/inte const SqlString = require('sqlstring'); const { prepareProxyRequest, handleHttpRequest } = require('../../../adapters/network'); const { isHttpStatusSuccess, getAuthErrCategoryFromStCode } = require('../../util/index'); -const { CONVERSION_ACTION_ID_CACHE_TTL, destType } = require('./config'); +const { CONVERSION_ACTION_ID_CACHE_TTL } = require('./config'); const Cache = require('../../util/cache'); -const logger = require('../../../logger'); const conversionActionIdCache = new Cache(CONVERSION_ACTION_ID_CACHE_TTL); diff --git a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js index 26163bcf9a..8c86fc9bc0 100644 --- a/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js +++ b/src/v0/destinations/google_adwords_offline_conversions/networkHandler.js @@ -21,7 +21,6 @@ const { getDynamicErrorType, } = require('../../../adapters/utils/networkUtils'); const tags = require('../../util/tags'); -const logger = require('../../../logger'); const conversionCustomVariableCache = new Cache(CONVERSION_CUSTOM_VARIABLE_CACHE_TTL); diff --git a/src/v1/destinations/monday/networkHandler.js b/src/v1/destinations/monday/networkHandler.js index fa54357873..28a7f1abc0 100644 --- a/src/v1/destinations/monday/networkHandler.js +++ b/src/v1/destinations/monday/networkHandler.js @@ -6,7 +6,6 @@ const { } = require('../../../adapters/utils/networkUtils'); const { isHttpStatusSuccess } = require('../../../v0/util/index'); const tags = require('../../../v0/util/tags'); -const logger = require('../../../logger'); const checkIfUpdationOfStatusRequired = (response) => { let errorMsg = ''; From 7123817c2982e13355513b75a393c6b0c29c7059 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Mon, 24 Jun 2024 10:51:20 +0530 Subject: [PATCH 06/12] chore: add test-case for request & response logs Signed-off-by: Sai Sankeerth --- src/adapters/network.test.js | 81 +++++++++++++++++++++++++++++++++++- src/logger.js | 27 +----------- src/util/logger.js | 25 +++++++++++ 3 files changed, 107 insertions(+), 26 deletions(-) create mode 100644 src/util/logger.js diff --git a/src/adapters/network.test.js b/src/adapters/network.test.js index ff112c53d4..598a42065b 100644 --- a/src/adapters/network.test.js +++ b/src/adapters/network.test.js @@ -1,6 +1,29 @@ -const { getFormData } = require('./network'); +const mockLoggerInstance = { + info: jest.fn(), +}; +const { getFormData, httpPOST } = require('./network'); const { getFuncTestData } = require('../../test/testHelper'); +jest.mock('@rudderstack/integrations-lib', () => { + return { + ...jest.requireActual('@rudderstack/integrations-lib'), + structuredLogger: jest.fn().mockReturnValue(mockLoggerInstance), + }; +}); + +jest.mock('axios', () => ({ + ...jest.requireActual('axios'), + post: jest.fn(), +})); + +jest.mock('../util/logger', () => ({ + ...jest.requireActual('../util/logger'), + getMatchedMetadata: jest.fn(), +})); + +const axios = require('axios'); +const loggerUtil = require('../util/logger'); + const funcName = 'getFormData'; describe(`${funcName} Tests`, () => { @@ -15,3 +38,59 @@ describe(`${funcName} Tests`, () => { expect(result.toString()).toEqual(output); }); }); + +describe('logging in http methods', () => { + test('when proper metadata is sent should call logger without error', async () => { + const statTags = { + metadata: { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + }, + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue([statTags.metadata]); + + axios.post.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + await expect(httpPOST('https://some.web.com/m/n/o', {}, {}, statTags)).resolves.not.toThrow( + Error, + ); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(1, ' [DT] /m/n/o request', { + body: {}, + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + url: 'https://some.web.com/m/n/o', + method: 'post', + }); + + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(2, ' [DT] /m/n/o response', { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + body: { a: 1, b: 2, c: 'abc' }, + status: 200, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + }); +}); diff --git a/src/logger.js b/src/logger.js index 0c7b1738f7..5bfeadd8c2 100644 --- a/src/logger.js +++ b/src/logger.js @@ -1,10 +1,8 @@ /* istanbul ignore file */ const { LOGLEVELS, structuredLogger } = require('@rudderstack/integrations-lib'); - +const { getMatchedMetadata } = require('./util/logger'); // LOGGER_IMPL can be `console` or `winston` const loggerImpl = process.env.LOGGER_IMPL ?? 'winston'; -const logDestIds = (process.env.LOG_DEST_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated -const logWspIds = (process.env.LOG_WSP_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated let logLevel = process.env.LOG_LEVEL ?? 'error'; @@ -73,24 +71,6 @@ const formLogArgs = (args) => { return [msg, ...otherArgs]; }; -const isMetadataMatching = (m) => { - const isDestIdConfigured = logDestIds?.find?.((envDId) => envDId && envDId === m?.destinationId); - const isWspIdConfigured = logWspIds?.find?.( - (envWspId) => envWspId && envWspId === m?.workspaceId, - ); - return Boolean(isDestIdConfigured || isWspIdConfigured); -}; - -const getMatchedMetadata = (metadata) => { - if (!Array.isArray(metadata)) { - if (isMetadataMatching(metadata)) { - return [metadata]; - } - return []; - } - return metadata.filter((m) => isMetadataMatching(m)); -}; - /** * Perform logging operation on logMethod passed * @@ -170,10 +150,7 @@ const requestLog = (identifierMsg, { metadata, requestDetails: { url, body, meth } }; -const responseLog = ( - identifierMsg, - { metadata, responseDetails: { response: body, status, headers } }, -) => { +const responseLog = (identifierMsg, { metadata, responseDetails: { body, status, headers } }) => { const logger = getLogger(); const filteredMetadata = getMatchedMetadata(metadata); if (filteredMetadata.length > 0) { diff --git a/src/util/logger.js b/src/util/logger.js new file mode 100644 index 0000000000..9a5a3d52db --- /dev/null +++ b/src/util/logger.js @@ -0,0 +1,25 @@ +const logDestIds = (process.env.LOG_DEST_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated +const logWspIds = (process.env.LOG_WSP_IDS ?? '').split(',')?.map?.((s) => s?.trim?.()); // should be comma separated + +const isMetadataMatching = (m) => { + const isDestIdConfigured = logDestIds?.find?.((envDId) => envDId && envDId === m?.destinationId); + const isWspIdConfigured = logWspIds?.find?.( + (envWspId) => envWspId && envWspId === m?.workspaceId, + ); + return Boolean(isDestIdConfigured || isWspIdConfigured); +}; + +const getMatchedMetadata = (metadata) => { + if (!Array.isArray(metadata)) { + if (isMetadataMatching(metadata)) { + return [metadata]; + } + return []; + } + return metadata.filter((m) => isMetadataMatching(m)); +}; + +module.exports = { + isMetadataMatching, + getMatchedMetadata, +}; From 2aec7b86dfa04a2394863ced8201b3415c87d7e6 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Mon, 24 Jun 2024 16:33:52 +0530 Subject: [PATCH 07/12] chore: add no metadata tc --- src/adapters/network.test.js | 44 ++++++++++++++++++++++++++++++++++++ 1 file changed, 44 insertions(+) diff --git a/src/adapters/network.test.js b/src/adapters/network.test.js index 598a42065b..b026d414f4 100644 --- a/src/adapters/network.test.js +++ b/src/adapters/network.test.js @@ -40,6 +40,10 @@ describe(`${funcName} Tests`, () => { }); describe('logging in http methods', () => { + beforeEach(() => { + mockLoggerInstance.info.mockClear(); + loggerUtil.getMatchedMetadata.mockClear(); + }); test('when proper metadata is sent should call logger without error', async () => { const statTags = { metadata: { @@ -93,4 +97,44 @@ describe('logging in http methods', () => { }, }); }); + + test('when metadata is not sent should call logger without error', async () => { + const statTags = { + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue([statTags.metadata]); + + axios.post.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + await expect(httpPOST('https://some.web.com/m/n/o', {}, {}, statTags)).resolves.not.toThrow( + Error, + ); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(1, ' [DT] /m/n/o request', { + body: {}, + url: 'https://some.web.com/m/n/o', + method: 'post', + }); + + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(2, ' [DT] /m/n/o response', { + body: { a: 1, b: 2, c: 'abc' }, + status: 200, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + }); }); From 78964467f6ecbf850838e903a9bb2ce5d3ed43f6 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Tue, 25 Jun 2024 10:48:31 +0530 Subject: [PATCH 08/12] chore: log when metadata is array of objects - add test-cases --- src/adapters/network.test.js | 132 ++++++++++++++++++++++++++++++++--- src/logger.js | 22 +++--- 2 files changed, 136 insertions(+), 18 deletions(-) diff --git a/src/adapters/network.test.js b/src/adapters/network.test.js index b026d414f4..5c9fe2dd9b 100644 --- a/src/adapters/network.test.js +++ b/src/adapters/network.test.js @@ -44,7 +44,7 @@ describe('logging in http methods', () => { mockLoggerInstance.info.mockClear(); loggerUtil.getMatchedMetadata.mockClear(); }); - test('when proper metadata is sent should call logger without error', async () => { + test('when proper metadata(object) is sent should call logger without error', async () => { const statTags = { metadata: { destType: 'DT', @@ -105,6 +105,32 @@ describe('logging in http methods', () => { endpointPath: '/m/n/o', requestMethod: 'post', }; + loggerUtil.getMatchedMetadata.mockReturnValue([]); + + axios.post.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + await expect(httpPOST('https://some.web.com/m/n/o', {}, {}, statTags)).resolves.not.toThrow( + Error, + ); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); + }); + + test('when metadata is string should call logger without error', async () => { + const statTags = { + metadata: 'random metadata', + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; loggerUtil.getMatchedMetadata.mockReturnValue([statTags.metadata]); axios.post.mockResolvedValueOnce({ @@ -120,21 +146,111 @@ describe('logging in http methods', () => { ); expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); - expect(mockLoggerInstance.info).toHaveBeenCalledTimes(2); + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); + }); - expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(1, ' [DT] /m/n/o request', { - body: {}, - url: 'https://some.web.com/m/n/o', - method: 'post', + test('when proper metadata(Array) is sent should call logger without error', async () => { + const metadata = [ + { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + jobId: 1, + }, + { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + jobId: 2, + }, + { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + jobId: 3, + }, + ]; + const statTags = { + metadata, + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue(statTags.metadata); + + axios.post.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, }); + await expect(httpPOST('https://some.web.com/m/n/o', {}, {}, statTags)).resolves.not.toThrow( + Error, + ); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); - expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(2, ' [DT] /m/n/o response', { - body: { a: 1, b: 2, c: 'abc' }, + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(metadata.length * 2); + + [1, 2, 3].forEach((i) => { + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith(i, ' [DT] /m/n/o request', { + body: {}, + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + url: 'https://some.web.com/m/n/o', + method: 'post', + }); + + expect(mockLoggerInstance.info).toHaveBeenNthCalledWith( + i + metadata.length, + ' [DT] /m/n/o response', + { + destType: 'DT', + destinationId: 'd1', + workspaceId: 'w1', + sourceId: 's1', + body: { a: 1, b: 2, c: 'abc' }, + status: 200, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }, + ); + }); + }); + + test('when proper metadata(Array of strings,numbers) is sent should call logger without error', async () => { + const metadata = [1, 2, '3']; + const statTags = { + metadata, + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue(statTags.metadata); + + axios.post.mockResolvedValueOnce({ status: 200, + data: { a: 1, b: 2, c: 'abc' }, headers: { 'Content-Type': 'apllication/json', 'X-Some-Header': 'headsome', }, }); + await expect(httpPOST('https://some.web.com/m/n/o', {}, {}, statTags)).resolves.not.toThrow( + Error, + ); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); }); }); diff --git a/src/logger.js b/src/logger.js index 5bfeadd8c2..4c80c938bb 100644 --- a/src/logger.js +++ b/src/logger.js @@ -88,16 +88,18 @@ const log = (logMethod, logArgs) => { if (logInfo) { const { metadata, ...otherLogInfoArgs } = logInfo; if (Array.isArray(metadata)) { - metadata.forEach((m) => { - logMethod( - message, - { - ...getLogMetadata(m), - ...otherLogInfoArgs, - }, - ...otherArgs, - ); - }); + metadata + .filter((m) => typeof m === 'object' && !Array.isArray(m)) + .forEach((m) => { + logMethod( + message, + { + ...getLogMetadata(m), + ...otherLogInfoArgs, + }, + ...otherArgs, + ); + }); return; } logMethod( From 5498d0bf5aab95675edc08bbfb88a55fc90b4549 Mon Sep 17 00:00:00 2001 From: Sankeerth Date: Tue, 25 Jun 2024 15:32:43 +0530 Subject: [PATCH 09/12] chore: empty string default endpointPath Co-authored-by: Sudip Paul <67197965+ItsSudip@users.noreply.github.com> --- src/adapters/network.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/adapters/network.js b/src/adapters/network.js index 91d8d628fb..4f3a7a81ef 100644 --- a/src/adapters/network.js +++ b/src/adapters/network.js @@ -151,7 +151,7 @@ const httpSend = async (options, statTags = {}) => { const requestOptions = enhanceRequestOptions(options); const { url, data, method } = requestOptions; - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; + const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath || ''}`; logger.requestLog(`${commonMsg} request`, { metadata: statTags?.metadata, requestDetails: { From e638ea151c9f1f5f8e20e2e1366c0f9620d6bada Mon Sep 17 00:00:00 2001 From: Sankeerth Date: Wed, 26 Jun 2024 17:38:38 +0530 Subject: [PATCH 10/12] chore: filtered logging and log for all destinations refactor (#3503) * chore: filtered logging and log for all destinations refactor Signed-off-by: Sai Sankeerth * chore: remove unnecessary comments * chore: rename variable --------- Signed-off-by: Sai Sankeerth Co-authored-by: Sai Sankeerth --- src/adapters/network.js | 193 +++++++++-------------------------- src/adapters/network.test.js | 90 ++++++++++++++-- 2 files changed, 128 insertions(+), 155 deletions(-) diff --git a/src/adapters/network.js b/src/adapters/network.js index 4f3a7a81ef..e5c7723783 100644 --- a/src/adapters/network.js +++ b/src/adapters/network.js @@ -140,29 +140,36 @@ const getResponseDetails = (clientResponse) => { }; }; -/** - * sends an http request with underlying client, expects request options - * @param {*} options - * @returns - */ -const httpSend = async (options, statTags = {}) => { +const getHttpMethodArgs = (method, { url, data, requestOptions }) => { + const requestMethod = method?.toLowerCase?.(); + switch (requestMethod) { + case 'post': + case 'put': + case 'patch': + return [url, data, requestOptions]; + case 'get': + case 'delete': + return [url, requestOptions]; + default: // constructor + return [requestOptions]; + } +}; +const commonHandler = async (axiosMethod, { statTags, method, ...args }) => { let clientResponse; - // here the options argument K-Vs will take priority over the default options - const requestOptions = enhanceRequestOptions(options); - - const { url, data, method } = requestOptions; + const { url, data, options, requestOptions } = args; const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath || ''}`; + logger.requestLog(`${commonMsg} request`, { metadata: statTags?.metadata, requestDetails: { - url, - body: options?.data, - method: options?.method || statTags?.requestMethod, + url: url || requestOptions?.url, + body: data || requestOptions?.data, + method, }, }); const startTime = new Date(); try { - const response = await axios(requestOptions); + const response = await axiosMethod(...getHttpMethodArgs(method, args)); clientResponse = { success: true, response }; } catch (err) { clientResponse = { success: false, response: err }; @@ -178,6 +185,16 @@ const httpSend = async (options, statTags = {}) => { return clientResponse; }; +/** + * sends an http request with underlying client, expects request options + * @param {*} options + * @returns + */ +const httpSend = async (options, statTags = {}) => { + const requestOptions = enhanceRequestOptions(options); + return commonHandler(axios, { statTags, options, requestOptions }); +}; + /** * * @param {*} url @@ -187,34 +204,8 @@ const httpSend = async (options, statTags = {}) => { * handles http GET requests returns promise as a response throws error in case of non 2XX statuses */ const httpGET = async (url, options, statTags = {}) => { - let clientResponse; - // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; - logger.requestLog(`${commonMsg} request`, { - metadata: statTags?.metadata, - requestDetails: { - url, - body: requestOptions?.data, - method: 'get', - }, - }); - const startTime = new Date(); - try { - const response = await axios.get(url, requestOptions); - clientResponse = { success: true, response }; - } catch (err) { - clientResponse = { success: false, response: err }; - } finally { - logger.responseLog(`${commonMsg} response`, { - metadata: statTags?.metadata, - responseDetails: getResponseDetails(clientResponse), - }); - fireHTTPStats(clientResponse, startTime, statTags); - } - setResponsesForMockAxiosAdapter({ url, options, method: 'GET' }, clientResponse); - return clientResponse; + return commonHandler(axios.get, { statTags, method: 'get', url, options, requestOptions }); }; /** @@ -226,34 +217,8 @@ const httpGET = async (url, options, statTags = {}) => { * handles http DELETE requests returns promise as a response throws error in case of non 2XX statuses */ const httpDELETE = async (url, options, statTags = {}) => { - let clientResponse; - // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; - logger.requestLog(`${commonMsg} request`, { - metadata: statTags?.metadata, - requestDetails: { - url, - body: requestOptions?.data, - method: 'delete', - }, - }); - const startTime = new Date(); - try { - const response = await axios.delete(url, requestOptions); - clientResponse = { success: true, response }; - } catch (err) { - clientResponse = { success: false, response: err }; - } finally { - logger.responseLog(`${commonMsg} response`, { - metadata: statTags?.metadata, - responseDetails: getResponseDetails(clientResponse), - }); - fireHTTPStats(clientResponse, startTime, statTags); - } - setResponsesForMockAxiosAdapter({ url, options, method: 'DELETE' }, clientResponse); - return clientResponse; + return commonHandler(axios.delete, { statTags, method: 'delete', url, options, requestOptions }); }; /** @@ -266,34 +231,15 @@ const httpDELETE = async (url, options, statTags = {}) => { * handles http POST requests returns promise as a response throws error in case of non 2XX statuses */ const httpPOST = async (url, data, options, statTags = {}) => { - let clientResponse; - // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; - logger.requestLog(`${commonMsg} request`, { - metadata: statTags?.metadata, - requestDetails: { - url, - body: data, - method: 'post', - }, + return commonHandler(axios.post, { + statTags, + url, + method: 'post', + data, + options, + requestOptions, }); - const startTime = new Date(); - try { - const response = await axios.post(url, data, requestOptions); - clientResponse = { success: true, response }; - } catch (err) { - clientResponse = { success: false, response: err }; - } finally { - logger.responseLog(`${commonMsg} response`, { - metadata: statTags?.metadata, - responseDetails: getResponseDetails(clientResponse), - }); - fireHTTPStats(clientResponse, startTime, statTags); - } - setResponsesForMockAxiosAdapter({ url, data, options, method: 'POST' }, clientResponse); - return clientResponse; }; /** @@ -306,33 +252,8 @@ const httpPOST = async (url, data, options, statTags = {}) => { * handles http PUT requests returns promise as a response throws error in case of non 2XX statuses */ const httpPUT = async (url, data, options, statTags = {}) => { - let clientResponse; - // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; - logger.requestLog(`${commonMsg} request`, { - metadata: statTags?.metadata, - requestDetails: { - url, - body: data, - method: 'put', - }, - }); - const startTime = new Date(); - try { - const response = await axios.put(url, data, requestOptions); - clientResponse = { success: true, response }; - } catch (err) { - clientResponse = { success: false, response: err }; - } finally { - logger.responseLog(`${commonMsg} response`, { - metadata: statTags?.metadata, - responseDetails: getResponseDetails(clientResponse), - }); - fireHTTPStats(clientResponse, startTime, statTags); - } - setResponsesForMockAxiosAdapter({ url, data, options, method: 'PUT' }, clientResponse); - return clientResponse; + return commonHandler(axios.put, { statTags, url, data, method: 'put', options, requestOptions }); }; /** @@ -345,33 +266,15 @@ const httpPUT = async (url, data, options, statTags = {}) => { * handles http PATCH requests returns promise as a response throws error in case of non 2XX statuses */ const httpPATCH = async (url, data, options, statTags = {}) => { - let clientResponse; - // here the options argument K-Vs will take priority over the default options const requestOptions = enhanceRequestOptions(options); - const commonMsg = `[${statTags?.destType?.toUpperCase?.() || ''}] ${statTags?.endpointPath}`; - logger.requestLog(`${commonMsg} request`, { - metadata: statTags?.metadata, - requestDetails: { - url, - body: data, - method: 'patch', - }, + return commonHandler(axios.patch, { + statTags, + url, + method: 'patch', + data, + options, + requestOptions, }); - const startTime = new Date(); - try { - const response = await axios.patch(url, data, requestOptions); - clientResponse = { success: true, response }; - } catch (err) { - clientResponse = { success: false, response: err }; - } finally { - logger.responseLog(`${commonMsg} response`, { - metadata: statTags?.metadata, - responseDetails: getResponseDetails(clientResponse), - }); - fireHTTPStats(clientResponse, startTime, statTags); - } - setResponsesForMockAxiosAdapter({ url, data, options, method: 'PATCH' }, clientResponse); - return clientResponse; }; const getPayloadData = (body) => { diff --git a/src/adapters/network.test.js b/src/adapters/network.test.js index 5c9fe2dd9b..5f5ad97437 100644 --- a/src/adapters/network.test.js +++ b/src/adapters/network.test.js @@ -1,7 +1,7 @@ const mockLoggerInstance = { info: jest.fn(), }; -const { getFormData, httpPOST } = require('./network'); +const { getFormData, httpPOST, httpGET, httpSend } = require('./network'); const { getFuncTestData } = require('../../test/testHelper'); jest.mock('@rudderstack/integrations-lib', () => { @@ -11,10 +11,7 @@ jest.mock('@rudderstack/integrations-lib', () => { }; }); -jest.mock('axios', () => ({ - ...jest.requireActual('axios'), - post: jest.fn(), -})); +jest.mock('axios', () => jest.fn()); jest.mock('../util/logger', () => ({ ...jest.requireActual('../util/logger'), @@ -24,6 +21,9 @@ jest.mock('../util/logger', () => ({ const axios = require('axios'); const loggerUtil = require('../util/logger'); +axios.post = jest.fn(); +axios.get = jest.fn(); + const funcName = 'getFormData'; describe(`${funcName} Tests`, () => { @@ -44,7 +44,7 @@ describe('logging in http methods', () => { mockLoggerInstance.info.mockClear(); loggerUtil.getMatchedMetadata.mockClear(); }); - test('when proper metadata(object) is sent should call logger without error', async () => { + test('post - when proper metadata(object) is sent should call logger without error', async () => { const statTags = { metadata: { destType: 'DT', @@ -98,7 +98,7 @@ describe('logging in http methods', () => { }); }); - test('when metadata is not sent should call logger without error', async () => { + test('post - when metadata is not sent should call logger without error', async () => { const statTags = { destType: 'DT', feature: 'feat', @@ -123,7 +123,7 @@ describe('logging in http methods', () => { expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); }); - test('when metadata is string should call logger without error', async () => { + test('post - when metadata is string should call logger without error', async () => { const statTags = { metadata: 'random metadata', destType: 'DT', @@ -149,7 +149,7 @@ describe('logging in http methods', () => { expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); }); - test('when proper metadata(Array) is sent should call logger without error', async () => { + test('post - when proper metadata(Array) is sent should call logger without error', async () => { const metadata = [ { destType: 'DT', @@ -227,7 +227,7 @@ describe('logging in http methods', () => { }); }); - test('when proper metadata(Array of strings,numbers) is sent should call logger without error', async () => { + test('post - when proper metadata(Array of strings,numbers) is sent should call logger without error', async () => { const metadata = [1, 2, '3']; const statTags = { metadata, @@ -251,6 +251,76 @@ describe('logging in http methods', () => { ); expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + expect(axios.post).toHaveBeenCalledWith( + 'https://some.web.com/m/n/o', + {}, + expect.objectContaining({}), + ); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); + }); + + test('get - when proper metadata(Array of strings,numbers) is sent should call logger without error', async () => { + const metadata = [1, 2, '3']; + const statTags = { + metadata, + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue(statTags.metadata); + + axios.get.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + await expect(httpGET('https://some.web.com/m/n/o', {}, statTags)).resolves.not.toThrow(Error); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(axios.get).toHaveBeenCalledWith( + 'https://some.web.com/m/n/o', + expect.objectContaining({}), + ); + + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); + }); + + test('constructor - when proper metadata(Array of strings,numbers) is sent should call logger without error', async () => { + const metadata = [1, 2, '3']; + const statTags = { + metadata, + destType: 'DT', + feature: 'feat', + endpointPath: '/m/n/o', + requestMethod: 'post', + }; + loggerUtil.getMatchedMetadata.mockReturnValue(statTags.metadata); + + axios.mockResolvedValueOnce({ + status: 200, + data: { a: 1, b: 2, c: 'abc' }, + headers: { + 'Content-Type': 'apllication/json', + 'X-Some-Header': 'headsome', + }, + }); + await expect( + httpSend({ url: 'https://some.web.com/m/n/o', method: 'get' }, statTags), + ).resolves.not.toThrow(Error); + expect(loggerUtil.getMatchedMetadata).toHaveBeenCalledTimes(2); + + expect(axios).toHaveBeenCalledWith( + expect.objectContaining({ + url: 'https://some.web.com/m/n/o', + method: 'get', + }), + ); + expect(mockLoggerInstance.info).toHaveBeenCalledTimes(0); }); }); From f133d178be45ad9634f854b58033ffcd0f23a4e4 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Mon, 1 Jul 2024 15:48:46 +0530 Subject: [PATCH 11/12] chore: update log level to always lower-case --- src/logger.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/logger.js b/src/logger.js index 4c80c938bb..6863bc4558 100644 --- a/src/logger.js +++ b/src/logger.js @@ -4,7 +4,7 @@ const { getMatchedMetadata } = require('./util/logger'); // LOGGER_IMPL can be `console` or `winston` const loggerImpl = process.env.LOGGER_IMPL ?? 'winston'; -let logLevel = process.env.LOG_LEVEL ?? 'error'; +let logLevel = (process.env.LOG_LEVEL ?? 'error').toLowerCase(); const logger = structuredLogger({ level: logLevel, From 52995bd5fe9c5d291dacfbd4efb30d172b4eb098 Mon Sep 17 00:00:00 2001 From: Sai Sankeerth Date: Mon, 1 Jul 2024 17:23:16 +0530 Subject: [PATCH 12/12] chore: fix error response handling in commonHandler --- src/adapters/network.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/adapters/network.js b/src/adapters/network.js index e5c7723783..86af19d6a1 100644 --- a/src/adapters/network.js +++ b/src/adapters/network.js @@ -120,7 +120,7 @@ const enhanceRequestOptions = (options) => { const getResponseDetails = (clientResponse) => { if (!clientResponse.success) { - const { response } = clientResponse; + const { response } = clientResponse.response; // non 2xx status handling for axios response if (response) { const { data, status, headers } = response;