Skip to content

add logs #1413

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
sahusanket wants to merge 1 commit into
base: release/6.10
Choose a base branch
from
Draft

add logs #1413

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions graphql/Query/pipelinesResolver.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,9 @@ import { getCDAPConfig } from 'server/cdap-config';
import { getGETRequestOptions, requestPromiseWrapper } from 'gql/resolvers-common';
import { orderBy } from 'natural-orderby';
import { ApolloError } from 'apollo-server';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

let cdapConfig;
getCDAPConfig().then(function(value) {
Expand All @@ -27,6 +30,9 @@ getCDAPConfig().then(function(value) {

export async function queryTypePipelinesResolver(parent, args, context) {
const namespace = args.namespace;
const queryId = context.queryId || 'Internal';
log.info(`[Query:${queryId}] Parent pipelinesResolver fetching apps list for namespace: ${namespace}`);

const options = getGETRequestOptions();

const pipelineArtifacts = ['cdap-data-pipeline', 'cdap-data-streams', 'cdap-sql-pipeline'];
Expand Down Expand Up @@ -57,5 +63,7 @@ export async function queryTypePipelinesResolver(parent, args, context) {
};

const apps = await requestPromiseWrapper(options, context, null, errorModifiersFn);
const appCount = apps && apps.applications ? apps.applications.length : 0;
log.info(`[Query:${queryId}] Parent pipelinesResolver successfully fetched ${appCount} apps for namespace: ${namespace}`);
return apps;
}
9 changes: 9 additions & 0 deletions graphql/graphql.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,11 +38,17 @@ const getApolloServer = (cdapConfig, logger = console) =>
typeDefs,
resolvers,
context: ({ req }) => {
const queryId = Math.random().toString(36).substring(2, 9);
log.info(`[Query:${queryId}] Incoming GraphQL request context initialization.`);

if (!req || !req.headers || !req.headers.authorization) {
log.info(`[Query:${queryId}] No Authorization header. Bypassing session token verification.`);
return {
queryId,
loaders: createLoaders(),
};
}

const sToken = req.headers['session-token'];
const auth = req.headers.authorization;
let userIdValue, userIdProperty;
Expand All @@ -51,11 +57,14 @@ const getApolloServer = (cdapConfig, logger = console) =>
userIdValue = req.headers[userIdProperty];
}

log.info(`[Query:${queryId}] Verifying session token for authenticated user context...`);
if (!sToken || (sToken && !sessionToken.validateToken(sToken, cdapConfig, logger, auth))) {
throw new Error('Invalid Sesion Token');
}
log.info(`[Query:${queryId}] Session token validated successfully.`);

return {
queryId,
auth,
userIdProperty,
userIdValue,
Expand Down
6 changes: 6 additions & 0 deletions graphql/helpers/BatchEndpoints/nextRuntime.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,9 @@ import { constructUrl } from 'server/url-helper';
import { getCDAPConfig } from 'server/cdap-config';
import { ApolloError } from 'apollo-server';
import { getPOSTRequestOptions, requestPromiseWrapper } from 'gql/resolvers-common';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

let cdapConfig;
getCDAPConfig().then(function(value) {
Expand All @@ -30,6 +33,9 @@ export async function batchNextRuntime(req, auth, userIdProperty, userIdValue) {
options.url = constructUrl(cdapConfig, `/v3/namespaces/${namespace}/nextruntime`);
const body = req.slice(0, 25).map((reqObj) => reqObj.program);
options.body = body;

const names = body.map(p => p.appId).join(', ');
log.info(`[DataLoader:nextRuntime] Dispatching batch request for ${body.length} pipelines: [${names}]`);
const errorModifiersFn = (error, statusCode) => {
return new ApolloError(error, statusCode, { errorOrigin: "runs" });
};
Expand Down
11 changes: 9 additions & 2 deletions graphql/helpers/BatchEndpoints/programRuns.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,8 +17,10 @@
import { constructUrl } from 'server/url-helper';
import { getCDAPConfig } from 'server/cdap-config';
import { ApolloError } from 'apollo-server';

import { getPOSTRequestOptions, requestPromiseWrapper } from 'gql/resolvers-common';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

let cdapConfig;
getCDAPConfig().then(function(value) {
Expand All @@ -29,7 +31,12 @@ export async function batchProgramRuns(req, auth, userIdProperty, userIdValue) {
const namespace = req[0].namespace;
const options = getPOSTRequestOptions();
options.url = constructUrl(cdapConfig, `/v3/namespaces/${namespace}/runs`);
options.body = req.slice(0, 25).map((reqObj) => reqObj.program);
const body = req.slice(0, 25).map((reqObj) => reqObj.program);
options.body = body;

const names = body.map(p => p.appId).join(', ');
log.info(`[DataLoader:programRuns] Dispatching batch request for ${body.length} pipelines: [${names}]`);

const errorModifiersFn = (error, statusCode) => {
return new ApolloError(error, statusCode, { errorOrigin: 'programRuns' });
}
Expand Down
6 changes: 6 additions & 0 deletions graphql/helpers/BatchEndpoints/totalRuns.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,9 @@ import { getCDAPConfig } from 'server/cdap-config';
import { getPOSTRequestOptions, requestPromiseWrapper } from 'gql/resolvers-common';
import { ApolloError } from 'apollo-server';
import chunk from 'lodash/chunk';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

let cdapConfig;
getCDAPConfig().then(function(value) {
Expand All @@ -35,6 +38,9 @@ export async function batchTotalRuns(req, auth, userIdProperty, userIdValue) {
}

const body = req.slice(0, 25).map((reqObj) => reqObj.program);
const names = body.map(p => p.appId).join(', ');
log.info(`[DataLoader:totalRuns] Dispatching batch request for ${body.length} pipelines: [${names}]`);

const chunkedBody = chunk(body, 100);

let runInfo = await Promise.all(
Expand Down
23 changes: 20 additions & 3 deletions graphql/resolvers-common.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,9 @@

import request from 'request';
import { ApolloError } from 'apollo-server';
import log4js from 'log4js';

const log = log4js.getLogger('graphql-client');

export function getGETRequestOptions() {
return {
Expand Down Expand Up @@ -43,21 +46,33 @@ export function requestPromiseWrapper(options, { auth: token, userIdProperty, us
options.headers[userIdProperty] = userIdValue;
}

if (!options.timeout) {
options.timeout = 5 * 60 * 1000; // 5mins
}

const requestId = Math.random().toString(36).substring(2, 9);
const startTime = Date.now();
log.info(`[Req:${requestId}] Sending backend request: ${options.method} ${options.url}`);

return new Promise((resolve, reject) => {
request(options, (err, response, body) => {
const statusCode = response.statusCode;
const duration = Date.now() - startTime;

if (err) {
log.error(`[Req:${requestId}] Backend request failed after ${duration}ms: ${options.method} ${options.url}. Error: ${err.message || err}`);
let exception;
if (typeof errorModifiersFn === 'function') {
exception = errorModifiersFn(err, statusCode ? statusCode.toString() : '500');
exception = errorModifiersFn(err, '500');
} else {
exception = new ApolloError(err, statusCode ? statusCode.toString() : '500');
exception = new ApolloError(err, '500');
}
return reject(exception);
}

const statusCode = response ? response.statusCode : 500;

if (typeof statusCode === 'undefined' || statusCode != 200) {
log.error(`[Req:${requestId}] Backend request failed with status ${statusCode} after ${duration}ms: ${options.method} ${options.url}`);
let error;
if (typeof errorModifiersFn === 'function') {
error = errorModifiersFn(body, statusCode.toString());
Expand All @@ -67,6 +82,8 @@ export function requestPromiseWrapper(options, { auth: token, userIdProperty, us
return reject(error);
}

log.info(`[Req:${requestId}] Backend request completed successfully in ${duration}ms with status ${statusCode}: ${options.method} ${options.url}`);

let resultBody = body;
if (typeof bodyModifiersFn === 'function') {
resultBody = bodyModifiersFn(body);
Expand Down
8 changes: 8 additions & 0 deletions graphql/types/PipelineRecord/nextRuntimeResolver.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,14 @@
*/

import { PIPELINE_PROGRAMS_MAP } from 'gql/types/PipelineRecord/common';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

export async function nextRuntimeResolvers(parent, args, context) {
const namespace = context.namespace;
const name = parent.name;
const queryId = context.queryId || 'Internal';

const pipelineType = parent.artifact.name || 'cdap-data-pipeline';

Expand All @@ -30,11 +34,15 @@ export async function nextRuntimeResolvers(parent, args, context) {
programId: programId,
};

log.info(`[Query:${queryId}] Queueing nextRuntime load for pipeline: ${name}`);

const nextRuntimeInfo = await context.loaders.nextRuntime.load({
namespace,
program,
});

log.info(`[Query:${queryId}] Resolved nextRuntime for pipeline: ${name}`);
Comment on lines +37 to +44

@gemini-code-assist gemini-code-assist Bot Jun 18, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

Since this resolver is executed for each individual pipeline in a list, logging at info level here will generate $O(N)$ log entries (where $N$ is the number of pipelines). This can severely flood the application logs and degrade performance.

Since the DataLoader batch endpoint already logs the batched dispatch (which is much cleaner and grouped), we should change these individual queue/resolve logs to debug level or remove them entirely.

Suggested change
log.info(`[Query:${queryId}] Queueing nextRuntime load for pipeline: ${name}`);
const nextRuntimeInfo = await context.loaders.nextRuntime.load({
namespace,
program,
});
log.info(`[Query:${queryId}] Resolved nextRuntime for pipeline: ${name}`);
log.debug(`[Query:\${queryId}] Queueing nextRuntime load for pipeline: \${name}`);
const nextRuntimeInfo = await context.loaders.nextRuntime.load({
namespace,
program,
});
log.debug(`[Query:\${queryId}] Resolved nextRuntime for pipeline: \${name}`);


if (!nextRuntimeInfo) {
return;
}
Expand Down
8 changes: 8 additions & 0 deletions graphql/types/PipelineRecord/pipelineRunsResolver.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,14 @@
*/

import { PIPELINE_PROGRAMS_MAP } from 'gql/types/PipelineRecord/common';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

export async function pipelineRunsResolver(parent, args, context) {
const namespace = context.namespace;
const name = parent.name;
const queryId = context.queryId || 'Internal';

const pipelineType = parent.artifact.name || 'cdap-data-pipeline';

Expand All @@ -30,11 +34,15 @@ export async function pipelineRunsResolver(parent, args, context) {
programId: programId,
};

log.info(`[Query:${queryId}] Queueing programRuns load for pipeline: ${name}`);

const runInfo = await context.loaders.programRuns.load({
namespace,
program,
});

log.info(`[Query:${queryId}] Resolved programRuns for pipeline: ${name}`);
Comment on lines +37 to +44

@gemini-code-assist gemini-code-assist Bot Jun 18, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

Since this resolver is executed for each individual pipeline in a list, logging at info level here will generate $O(N)$ log entries. This can flood the logs and impact performance.

Since the DataLoader batch endpoint already logs the batched dispatch, we should change these individual queue/resolve logs to debug level or remove them entirely.

Suggested change
log.info(`[Query:${queryId}] Queueing programRuns load for pipeline: ${name}`);
const runInfo = await context.loaders.programRuns.load({
namespace,
program,
});
log.info(`[Query:${queryId}] Resolved programRuns for pipeline: ${name}`);
log.debug(`[Query:\${queryId}] Queueing programRuns load for pipeline: \${name}`);
const runInfo = await context.loaders.programRuns.load({
namespace,
program,
});
log.debug(`[Query:\${queryId}] Resolved programRuns for pipeline: \${name}`);


if (!runInfo || (Array.isArray(runInfo) && runInfo.length === 0)) {
return;
}
Expand Down
8 changes: 8 additions & 0 deletions graphql/types/PipelineRecord/totalRunsResolver.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,14 @@
*/

import { PIPELINE_PROGRAMS_MAP } from 'gql/types/PipelineRecord/common';
import log4js from 'log4js';

const log = log4js.getLogger('graphql');

export async function totalRunsResolvers(parent, args, context) {
const namespace = context.namespace;
const name = parent.name;
const queryId = context.queryId || 'Internal';

const pipelineType = parent.artifact.name || 'cdap-data-pipeline';

Expand All @@ -30,11 +34,15 @@ export async function totalRunsResolvers(parent, args, context) {
programId: programId,
};

log.info(`[Query:${queryId}] Queueing totalRuns load for pipeline: ${name}`);

const runInfo = await context.loaders.totalRuns.load({
namespace,
program,
});

log.info(`[Query:${queryId}] Resolved totalRuns for pipeline: ${name}`);
Comment on lines +37 to +44

@gemini-code-assist gemini-code-assist Bot Jun 18, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

Since this resolver is executed for each individual pipeline in a list, logging at info level here will generate $O(N)$ log entries. This can flood the logs and impact performance.

Since the DataLoader batch endpoint already logs the batched dispatch, we should change these individual queue/resolve logs to debug level or remove them entirely.

Suggested change
log.info(`[Query:${queryId}] Queueing totalRuns load for pipeline: ${name}`);
const runInfo = await context.loaders.totalRuns.load({
namespace,
program,
});
log.info(`[Query:${queryId}] Resolved totalRuns for pipeline: ${name}`);
log.debug(`[Query:\${queryId}] Queueing totalRuns load for pipeline: \${name}`);
const runInfo = await context.loaders.totalRuns.load({
namespace,
program,
});
log.debug(`[Query:\${queryId}] Resolved totalRuns for pipeline: \${name}`);


if (!runInfo || !runInfo.runCount) {
return 0;
}
Expand Down