From 34bcba02978c0246016d146da389ac5c81ddfdeb Mon Sep 17 00:00:00 2001 From: Julien Richard Date: Fri, 10 Jan 2025 00:08:40 +0100 Subject: [PATCH 1/2] [backend] Ensure log lines would be efficiently streamed to log visualization tools (#4199) + rework logging messages --- opencti-platform/opencti-graphql/src/boot.js | 5 +- .../opencti-graphql/src/config/conf.js | 36 ++- .../opencti-graphql/src/config/providers.js | 4 +- .../importCsv/importCsv-connector.ts | 14 +- .../opencti-graphql/src/database/engine.js | 11 +- .../src/database/file-storage.js | 6 +- .../src/database/middleware.js | 11 +- .../opencti-graphql/src/database/migration.js | 4 +- .../opencti-graphql/src/database/rabbitmq.js | 6 +- .../opencti-graphql/src/database/redis.ts | 4 +- .../src/domain/retentionRule.js | 2 +- .../opencti-graphql/src/domain/user.js | 2 +- .../opencti-graphql/src/domain/work.js | 2 - .../opencti-graphql/src/graphql/graphql.js | 10 +- .../src/graphql/loggerPlugin.js | 11 +- .../src/graphql/sseMiddleware.js | 4 +- .../opencti-graphql/src/http/httpPlatform.js | 20 +- .../opencti-graphql/src/http/httpServer.js | 5 +- .../src/listener/supportPackageListener.ts | 6 +- .../src/manager/activityManager.ts | 4 +- .../src/manager/connectorManager.js | 2 +- .../src/manager/expiredManager.js | 2 +- .../src/manager/fileIndexManager.ts | 10 +- .../src/manager/garbageCollectionManager.ts | 2 +- .../src/manager/historyManager.ts | 4 +- .../src/manager/ingestionManager.ts | 8 +- .../src/manager/managerModule.ts | 4 +- .../src/manager/notificationManager.ts | 6 +- .../src/manager/playbookManager.ts | 16 +- .../src/manager/publisherManager.ts | 12 +- .../src/manager/retentionManager.ts | 2 +- .../src/manager/ruleManager.ts | 6 +- .../src/manager/syncManager.js | 6 +- .../src/manager/taskManager.js | 10 +- .../src/modules/xtm/xtm-domain.js | 7 +- .../opencti-graphql/src/parser/csv-bundler.ts | 4 +- .../src/python/pythonBridge.js | 10 +- .../opencti-graphql/src/resolvers/user.js | 2 +- .../tests/01-unit/utils/logger-test.ts | 228 ++++++++++++++++++ 39 files changed, 383 insertions(+), 125 deletions(-) create mode 100644 opencti-platform/opencti-graphql/tests/01-unit/utils/logger-test.ts diff --git a/opencti-platform/opencti-graphql/src/boot.js b/opencti-platform/opencti-graphql/src/boot.js index b1fab0c8cfc3..c7132c5076f1 100644 --- a/opencti-platform/opencti-graphql/src/boot.js +++ b/opencti-platform/opencti-graphql/src/boot.js @@ -39,7 +39,6 @@ export const platformStart = async () => { throw modulesError; } } catch (mainError) { - logApp.error(mainError); process.exit(1); } }; @@ -58,7 +57,7 @@ export const platformStop = async () => { // region signals management process.on('unhandledRejection', (reason, p) => { - logApp.error(UnknownError('Engine unhandled rejection', { reason: reason?.stack, promise: p?.stack })); + logApp.error('[OPENCTI] Engine unhandled rejection', { reason: reason?.stack, promise: p?.stack }); }); ['SIGTERM', 'SIGINT', 'message'].forEach((signal) => { @@ -71,7 +70,7 @@ process.on('unhandledRejection', (reason, p) => { await platformStop(); process.exit(0); } catch (e) { - logApp.error(e); + logApp.error('[OPENCTI] Error stopping the platform', { cause: e }); process.exit(1); } } diff --git a/opencti-platform/opencti-graphql/src/config/conf.js b/opencti-platform/opencti-graphql/src/config/conf.js index 5e1c1bafea89..83ecd9b5d853 100644 --- a/opencti-platform/opencti-graphql/src/config/conf.js +++ b/opencti-platform/opencti-graphql/src/config/conf.js @@ -96,6 +96,8 @@ nconf.file('default', resolveEnvFile('default')); const appLogLevel = nconf.get('app:app_logs:logs_level'); const appLogFileTransport = booleanConf('app:app_logs:logs_files', true); const appLogConsoleTransport = booleanConf('app:app_logs:logs_console', true); +export const appLogLevelMaxArraySize = nconf.get('app:app_logs:max_array_size') ?? 50; +export const appLogLevelMaxStringSize = nconf.get('app:app_logs:max_string_size') ?? 5000; export const appLogExtendedErrors = booleanConf('app:app_logs:extended_error_message', false); export const extendedErrors = (metaExtension) => { if (appLogExtendedErrors) { @@ -103,6 +105,32 @@ export const extendedErrors = (metaExtension) => { } return {}; }; +export const limitMetaErrorComplexity = (obj) => { + if (Array.isArray(obj)) { + // Create a new array with a limited size + const limitedArray = obj.slice(0, appLogLevelMaxArraySize); + // Recursively process each item in the truncated array + const processedArray = []; + for (let i = 0; i < limitedArray.length; i += 1) { + processedArray[i] = limitMetaErrorComplexity(limitedArray[i]); + } + return processedArray; + } + if (typeof obj === 'string' && obj.length > appLogLevelMaxStringSize) { + return `${obj.substring(0, appLogLevelMaxStringSize - 3)}...`; + } + if (obj !== null && typeof obj === 'object') { + // Create a new object to hold the processed properties + const limitedObject = {}; + const keys = Object.keys(obj); // Get the keys of the object + for (let i = 0; i < keys.length; i += 1) { + const key = keys[i]; + limitedObject[key] = limitMetaErrorComplexity(obj[key]); + } + return limitedObject; + } + return obj; +}; const appLogTransports = []; const logsDirname = nconf.get('app:app_logs:logs_directory'); @@ -196,7 +224,6 @@ const buildMetaErrors = (error) => { if (error instanceof GraphQLError) { const extensions = error.extensions ?? {}; const extensionsData = extensions.data ?? {}; - // const attributes = R.dissoc('cause', extensionsData); const { cause: _, ...attributes } = extensionsData; const baseError = { name: extensions.code ?? error.name, message: error.message, stack: error.stack, attributes }; errors.push(baseError); @@ -223,8 +250,11 @@ export const logS3Debug = { export const logApp = { _log: (level, message, error, meta = {}) => { - if (appLogTransports.length > 0) { - appLogger.log(level, message, addBasicMetaInformation(LOG_APP, error, { ...meta, source: 'backend' })); + if (appLogTransports.length > 0 && appLogger.isLevelEnabled(level)) { + const data = addBasicMetaInformation(LOG_APP, error, { ...meta, source: 'backend' }); + // Prevent meta information to be too massive. + const limitedData = limitMetaErrorComplexity(data); + appLogger.log(level, message, limitedData); } }, _logWithError: (level, messageOrError, meta = {}) => { diff --git a/opencti-platform/opencti-graphql/src/config/providers.js b/opencti-platform/opencti-graphql/src/config/providers.js index bd571f03d69a..f138cc0fc710 100644 --- a/opencti-platform/opencti-graphql/src/config/providers.js +++ b/opencti-platform/opencti-graphql/src/config/providers.js @@ -12,7 +12,7 @@ import { OAuth2Strategy as GoogleStrategy } from 'passport-google-oauth'; import validator from 'validator'; import { findById, HEADERS_AUTHENTICATORS, initAdmin, login, loginFromProvider, userDelete } from '../domain/user'; import conf, { getPlatformHttpProxyAgent, logApp } from './conf'; -import { AuthenticationFailure, ConfigurationError, UnsupportedError } from './errors'; +import { AuthenticationFailure, ConfigurationError } from './errors'; import { isEmptyField, isNotEmptyField } from '../database/utils'; import { DEFAULT_INVALID_CONF_VALUE, SYSTEM_USER } from '../utils/access'; import { enrichWithRemoteCredentials } from './credentials'; @@ -402,7 +402,7 @@ for (let i = 0; i < providerKeys.length; i += 1) { passport.use(providerRef, openIDStrategy); providers.push({ name: providerName, type: AUTH_SSO, strategy, provider: providerRef }); }).catch((err) => { - logApp.error(UnsupportedError('[OPENID] Error initializing authentication provider', { cause: err, provider: providerRef })); + logApp.error('[OPENID] Error initializing authentication provider', { cause: err, provider: providerRef }); }); }); } diff --git a/opencti-platform/opencti-graphql/src/connector/importCsv/importCsv-connector.ts b/opencti-platform/opencti-graphql/src/connector/importCsv/importCsv-connector.ts index 16e7ea8f7c4d..3379a47cbd77 100644 --- a/opencti-platform/opencti-graphql/src/connector/importCsv/importCsv-connector.ts +++ b/opencti-platform/opencti-graphql/src/connector/importCsv/importCsv-connector.ts @@ -12,7 +12,7 @@ import { OPENCTI_SYSTEM_UUID } from '../../schema/general'; import { resolveUserByIdFromCache } from '../../domain/user'; import { parseCsvMapper, sanitized, validateCsvMapper } from '../../modules/internal/csvMapper/csvMapper-utils'; import { IMPORT_CSV_CONNECTOR } from './importCsv'; -import { DatabaseError, FunctionalError } from '../../config/errors'; +import { FunctionalError } from '../../config/errors'; import { uploadToStorage } from '../../database/file-storage-helper'; import { storeLoadByIdWithRefs } from '../../database/middleware'; import type { ConnectorConfig } from '../internalConnector'; @@ -46,7 +46,7 @@ const processCSVforWorkbench = async (context: AuthContext, fileId: string, opts hasError = true; const errorData = { error: error.message, source: fileId }; await reportExpectation(context, applicantUser, workId, errorData); - logApp.error(error); + logApp.error(`${LOG_PREFIX} Error streaming the CSV data`, { error }); }).on('end', async () => { if (!hasError) { // it's fine to use deprecated bundleProcess since this whole method is also deprecated for drafts. @@ -132,15 +132,14 @@ export const processCSVforWorkers = async (context: AuthContext, fileId: string, totalBundlesCount += bundleCount; } catch (error: any) { const errorData = { error: error.message, source: `${fileId}, from ${lineNumber} and ${BULK_LINE_PARSING_NUMBER} following lines.` }; - logApp.error(error, { errorData }); + logApp.error(`${LOG_PREFIX} CSV line parsing error`, { error: errorData }); await reportExpectation(context, applicantUser, workId, errorData); } } } catch (error: any) { - logApp.error(error); + logApp.error(`${LOG_PREFIX} CSV global parsing error`, { error }); const errorData = { error: error.message, source: fileId }; await reportExpectation(context, applicantUser, workId, errorData); - // circuit breaker hasMoreBulk = false; } finally { @@ -197,7 +196,6 @@ const consumeQueueCallback = async (context: AuthContext, message: string) => { entity, connectorId: connector.internal_id }; - await updateReceivedTime(context, applicantUser, workId, 'Connector ready to process the operation'); const validateBeforeImport = connectorConfig.config.validate_before_import; if (validateBeforeImport) { @@ -206,8 +204,8 @@ const consumeQueueCallback = async (context: AuthContext, message: string) => { await processCSVforWorkers(context, fileId, opts); } } catch (error: any) { + logApp.error(`${LOG_PREFIX} CSV global parsing error`, { error, source: fileId }); const errorData = { error: error.stack, source: fileId }; - logApp.error(error, { context, errorData }); await reportExpectation(context, applicantUser, workId, errorData); } }; @@ -227,7 +225,7 @@ export const initImportCsvConnector = () => { try { rabbitMqConnection.close(); } catch (e) { - logApp.error(DatabaseError(`${LOG_PREFIX} Closing RabbitMQ connection failed`, { cause: e })); + logApp.error(`${LOG_PREFIX} Closing RabbitMQ connection failed`, { cause: e }); } } // TODO REMOVE TYPING, don't know why it's not working diff --git a/opencti-platform/opencti-graphql/src/database/engine.js b/opencti-platform/opencti-graphql/src/database/engine.js index 5812c630c129..e74b8ab69d4e 100644 --- a/opencti-platform/opencti-graphql/src/database/engine.js +++ b/opencti-platform/opencti-graphql/src/database/engine.js @@ -1079,7 +1079,7 @@ export const elConfigureAttachmentProcessor = async () => { } ] }).catch((e) => { - logApp.error(ConfigurationError('Engine attachment processor configuration fail', { cause: e })); + logApp.error('Engine attachment processor configuration fail', { cause: e }); success = false; }); } else { @@ -1101,7 +1101,7 @@ export const elConfigureAttachmentProcessor = async () => { ] } }).catch((e) => { - logApp.error(ConfigurationError('Engine attachment processor configuration fail', { cause: e })); + logApp.error('Engine attachment processor configuration fail', { cause: e }); success = false; }); } @@ -1154,7 +1154,7 @@ export const elDeleteIndices = async (indexesToDelete) => { .catch((err) => { /* v8 ignore next */ if (err.meta.body && err.meta.body.error.type !== 'index_not_found_exception') { - logApp.error(DatabaseError('Indices deletion fail', { cause: err })); + logApp.error('Indices deletion fail', { cause: err }); } }); }) @@ -3737,7 +3737,9 @@ export const elDeleteElements = async (context, user, elements, opts = {}) => { const { relations, relationsToRemoveMap } = await getRelationsToRemove(context, SYSTEM_USER, elements); // User must have access to all relations to remove to be able to delete const filteredRelations = await userFilterStoreElements(context, user, relations); - if (relations.length !== filteredRelations.length) throw FunctionalError('Cannot delete element: cannot access all related relations'); + if (relations.length !== filteredRelations.length) { + throw FunctionalError('Cannot delete element: cannot access all related relations'); + } relations.forEach((instance) => controlUserConfidenceAgainstElement(user, instance)); relations.forEach((instance) => controlUserRestrictDeleteAgainstElement(user, instance)); // Compute the id that needs to be removed from rel @@ -3765,7 +3767,6 @@ export const elDeleteElements = async (context, user, elements, opts = {}) => { const ids = idsByIndex.get(sourceIndex); reindexPromises.push(elReindexElements(context, user, ids, sourceIndex, INDEX_DELETED_OBJECTS)); }); - await Promise.all(reindexPromises); await createDeleteOperationElement(context, user, elements[0], entitiesToDelete); } diff --git a/opencti-platform/opencti-graphql/src/database/file-storage.js b/opencti-platform/opencti-graphql/src/database/file-storage.js index 2c4c56f4da98..753cee7c9fbb 100644 --- a/opencti-platform/opencti-graphql/src/database/file-storage.js +++ b/opencti-platform/opencti-graphql/src/database/file-storage.js @@ -10,7 +10,7 @@ import { CopyObjectCommand } from '@aws-sdk/client-s3'; import nconf from 'nconf'; import conf, { booleanConf, ENABLED_FILE_INDEX_MANAGER, isFeatureEnabled, logApp, logS3Debug } from '../config/conf'; import { now, sinceNowInMinutes, truncate, utcDate } from '../utils/format'; -import { DatabaseError, FunctionalError, UnsupportedError } from '../config/errors'; +import { FunctionalError, UnsupportedError } from '../config/errors'; import { createWork, deleteWorkForFile } from '../domain/work'; import { isNotEmptyField, READ_DATA_INDICES, READ_INDEX_DELETED_OBJECTS } from './utils'; import { connectorsForImport } from './repository'; @@ -141,7 +141,7 @@ export const deleteFile = async (context, user, id) => { logApp.debug(`[FILE STORAGE] delete file ${id} in index`); await elDeleteFilesByIds([id]) .catch((err) => { - logApp.error(err); + logApp.error('[FILE STORAGE] Error deleting file', { cause: err }); }); } return up; @@ -403,7 +403,7 @@ export const loadedFilesListing = async (context, user, directory, opts = {}) => requestParams.ContinuationToken = response.NextContinuationToken; } } catch (err) { - logApp.error(DatabaseError('[FILE STORAGE] Storage files read fail', { cause: err })); + logApp.error('[FILE STORAGE] Storage files read fail', { cause: err }); truncated = false; } } diff --git a/opencti-platform/opencti-graphql/src/database/middleware.js b/opencti-platform/opencti-graphql/src/database/middleware.js index 30677c56c9e3..bb31fcf8a4e9 100644 --- a/opencti-platform/opencti-graphql/src/database/middleware.js +++ b/opencti-platform/opencti-graphql/src/database/middleware.js @@ -2240,7 +2240,7 @@ export const updateAttributeFromLoadedWithRefs = async (context, user, initial, export const updateAttribute = async (context, user, id, type, inputs, opts = {}) => { const initial = await storeLoadByIdWithRefs(context, user, id, { ...opts, type }); if (!initial) { - throw FunctionalError(`Cant find element to update ${id} (${type})`, { id, type }); + throw FunctionalError('Cant find element to update', { id, type }); } // Validate input attributes const entitySetting = await getEntitySettingFromCache(context, initial.entity_type); @@ -3168,9 +3168,9 @@ export const internalDeleteElementById = async (context, user, id, opts = {}) => if (!element) { throw AlreadyDeletedError({ id }); } - - if (element._index.includes(INDEX_DRAFT_OBJECTS)) return draftInternalDeleteElement(context, user, element); - + if (element._index.includes(INDEX_DRAFT_OBJECTS)) { + return draftInternalDeleteElement(context, user, element); + } // region confidence control controlUserConfidenceAgainstElement(user, element); // region restrict delete control @@ -3248,7 +3248,6 @@ export const internalDeleteElementById = async (context, user, id, opts = {}) => // if trash is disabled globally or for this element, delete permanently await deleteAllObjectFiles(context, user, element); } - // Delete all linked elements await elDeleteElements(context, user, [element], { forceDelete }); // Publish event in the stream @@ -3325,7 +3324,7 @@ export const deleteInferredRuleElement = async (rule, instance, deletedDependenc if (err.name === ALREADY_DELETED_ERROR) { logApp.info(err); } else { - logApp.error(err); + logApp.error('Error handling inference', { cause: err }); } } return false; diff --git a/opencti-platform/opencti-graphql/src/database/migration.js b/opencti-platform/opencti-graphql/src/database/migration.js index 63a396e17a0b..44d3c550b9a4 100644 --- a/opencti-platform/opencti-graphql/src/database/migration.js +++ b/opencti-platform/opencti-graphql/src/database/migration.js @@ -83,7 +83,7 @@ const migrationStorage = { logApp.info(`[MIGRATION] Saving current configuration, ${mig.title}`); return fn(); } catch (err) { - logApp.error(err); + logApp.error('Error handling migration', { cause: err }); return fn(); } }, @@ -124,7 +124,7 @@ export const applyMigration = (context) => { // Start the set migration set.up((migrationError) => { if (migrationError) { - logApp.error(migrationError); + logApp.error('Migration up error', { cause: migrationError }); reject(migrationError); return; } diff --git a/opencti-platform/opencti-graphql/src/database/rabbitmq.js b/opencti-platform/opencti-graphql/src/database/rabbitmq.js index f4e44be9cda2..ee3591d19d3e 100644 --- a/opencti-platform/opencti-graphql/src/database/rabbitmq.js +++ b/opencti-platform/opencti-graphql/src/database/rabbitmq.js @@ -97,7 +97,7 @@ export const getConnectorQueueDetails = async (connectorId) => { messages_size: queueDetailResponse.message_bytes || 0 }; } catch (e) { - logApp.error(e, { connectorId }); + logApp.error('Get connector queue details fail', { cause: e, connectorId }); return { messages_number: 0, messages_size: 0 @@ -357,10 +357,10 @@ export const consumeQueue = async (context, connectorId, connectionSetterCallbac } }, { noAck: true }, (consumeError) => { if (consumeError) { - logApp.error(DatabaseError('[QUEUEING] Consumption fail', { + logApp.error('[QUEUEING] Consumption fail', { connectorId, cause: consumeError - })); + }); } }); } diff --git a/opencti-platform/opencti-graphql/src/database/redis.ts b/opencti-platform/opencti-graphql/src/database/redis.ts index 815762e5b9a2..003c02a1f57b 100644 --- a/opencti-platform/opencti-graphql/src/database/redis.ts +++ b/opencti-platform/opencti-graphql/src/database/redis.ts @@ -130,7 +130,7 @@ export const createRedisClient = async (provider: string, autoReconnect = false) client.on('close', () => logApp.info(`[REDIS] Redis '${provider}' client closed`)); client.on('ready', () => logApp.info(`[REDIS] Redis '${provider}' client ready`)); - client.on('error', (err) => logApp.error(DatabaseError('Redis client connection fail', { cause: err, provider }))); + client.on('error', (err) => logApp.error('Redis client connection fail', { cause: err, provider })); client.on('reconnecting', () => logApp.info(`[REDIS] '${provider}' Redis client reconnecting`)); return client; }; @@ -705,7 +705,7 @@ export const createStreamProcessor = ( await processStreamResult([], callback, opts.withInternal); } } catch (err) { - logApp.error(DatabaseError('Redis stream consume fail', { cause: err, provider })); + logApp.error('Redis stream consume fail', { cause: err, provider }); if (opts.autoReconnect) { await waitInSec(2); } else { diff --git a/opencti-platform/opencti-graphql/src/domain/retentionRule.js b/opencti-platform/opencti-graphql/src/domain/retentionRule.js index a79450c2c8a0..dbffa0e6b204 100644 --- a/opencti-platform/opencti-graphql/src/domain/retentionRule.js +++ b/opencti-platform/opencti-graphql/src/domain/retentionRule.js @@ -29,7 +29,7 @@ export const checkRetentionRule = async (context, input) => { } else if (scope === 'workbench') { result = await paginatedForPathWithEnrichment(context, RETENTION_MANAGER_USER, 'import/pending', undefined, { notModifiedSince: before.toISOString() }); } else { - logApp.error(`[Retention manager] Scope ${scope} not existing for Retention Rule.`); + logApp.error('[Retention manager] Scope not existing for Retention Rule.', { scope }); } if (scope === 'file' || scope === 'workbench') { // don't delete progress files or files with works in progress result.edges = result.edges.filter((e) => DELETABLE_FILE_STATUSES.includes(e.node.uploadStatus) diff --git a/opencti-platform/opencti-graphql/src/domain/user.js b/opencti-platform/opencti-graphql/src/domain/user.js index 3a3aaa02dacc..915306c3eac0 100644 --- a/opencti-platform/opencti-graphql/src/domain/user.js +++ b/opencti-platform/opencti-graphql/src/domain/user.js @@ -1579,7 +1579,7 @@ export const authenticateUserFromRequest = async (context, req, res, isSessionRe return await authenticateUser(context, req, user, loginProvider, opts); } } catch (err) { - logApp.error(err); + logApp.error('Error resolving user by token', { cause: err }); } } // If user still not identified, try headers authentication diff --git a/opencti-platform/opencti-graphql/src/domain/work.js b/opencti-platform/opencti-graphql/src/domain/work.js index 1189e262c2c7..3da762c97492 100644 --- a/opencti-platform/opencti-graphql/src/domain/work.js +++ b/opencti-platform/opencti-graphql/src/domain/work.js @@ -13,7 +13,6 @@ import { addFilter } from '../utils/filtering/filtering-utils'; import { IMPORT_CSV_CONNECTOR, IMPORT_CSV_CONNECTOR_ID } from '../connector/importCsv/importCsv'; import { RELATION_OBJECT_MARKING } from '../schema/stixRefRelationship'; import { DRAFT_VALIDATION_CONNECTOR, DRAFT_VALIDATION_CONNECTOR_ID } from '../modules/draftWorkspace/draftWorkspace-connector'; -import { logApp } from '../config/conf'; export const workToExportFile = (work) => { const lastModifiedSinceMin = sinceNowInMinutes(work.updated_at); @@ -221,7 +220,6 @@ export const reportExpectation = async (context, user, workId, errorData) => { sourceScript += 'if (ctx._source.errors.length < 100) { ctx._source.errors.add(["timestamp": params.now, "message": params.error, "source": params.source]); }'; params.source = source; params.error = error; - logApp.error(error, { errorData }); } // Update elastic const currentWork = await loadWorkById(context, user, workId); diff --git a/opencti-platform/opencti-graphql/src/graphql/graphql.js b/opencti-platform/opencti-graphql/src/graphql/graphql.js index 655e1824b533..0d6fcdf00dcf 100644 --- a/opencti-platform/opencti-graphql/src/graphql/graphql.js +++ b/opencti-platform/opencti-graphql/src/graphql/graphql.js @@ -3,14 +3,13 @@ import { ApolloArmor } from '@escape.tech/graphql-armor'; import { dissocPath } from 'ramda'; import { ApolloServerPluginLandingPageDisabled } from '@apollo/server/plugin/disabled'; import { ApolloServerPluginLandingPageGraphQLPlayground } from '@apollo/server-plugin-landing-page-graphql-playground'; -import { ApolloServerErrorCode } from '@apollo/server/errors'; import { createValidation as createAliasBatch } from 'graphql-no-alias'; import { constraintDirectiveDocumentation } from 'graphql-constraint-directive'; import { GraphQLError } from 'graphql/error'; import { createApollo4QueryValidationPlugin } from 'graphql-constraint-directive/apollo4'; import createSchema from './schema'; import conf, { basePath, DEV_MODE, ENABLED_METRICS, ENABLED_TRACING, GRAPHQL_ARMOR_DISABLED, PLAYGROUND_ENABLED, PLAYGROUND_INTROSPECTION_DISABLED } from '../config/conf'; -import { ForbiddenAccess, ValidationError } from '../config/errors'; +import { ForbiddenAccess } from '../config/errors'; import loggerPlugin from './loggerPlugin'; import telemetryPlugin from './telemetryPlugin'; import tracingPlugin from './tracingPlugin'; @@ -107,12 +106,7 @@ const createApolloServer = () => { csrfPrevention: false, // CSRF is handled by helmet tracing: DEV_MODE, plugins: apolloPlugins, - formatError: (formattedError) => { - let error = formattedError; - // For constraint lib user input failure, replace the lib error by the opencti validation one. - if (formattedError.extensions?.code === ApolloServerErrorCode.BAD_USER_INPUT) { - error = ValidationError(formattedError.message, formattedError.extensions?.field, formattedError.extensions); - } + formatError: (error) => { // To maintain compatibility with client in version 3. const enrichedError = { ...error, name: error.extensions?.code ?? error.name }; // Remove the exception stack in production. diff --git a/opencti-platform/opencti-graphql/src/graphql/loggerPlugin.js b/opencti-platform/opencti-graphql/src/graphql/loggerPlugin.js index a4745c0c28b3..80efc4b8481f 100644 --- a/opencti-platform/opencti-graphql/src/graphql/loggerPlugin.js +++ b/opencti-platform/opencti-graphql/src/graphql/loggerPlugin.js @@ -1,9 +1,10 @@ import { filter, head, isEmpty, isNil } from 'ramda'; import { stripIgnoredCharacters } from 'graphql/utilities'; +import { ApolloServerErrorCode } from '@apollo/server/errors'; import conf, { appLogExtendedErrors, booleanConf, logApp } from '../config/conf'; import { isEmptyField, isNotEmptyField } from '../database/utils'; import { getMemoryStatistics } from '../domain/settings'; -import { AUTH_ERRORS, FORBIDDEN_ACCESS, FUNCTIONAL_ERRORS } from '../config/errors'; +import { AUTH_ERRORS, FORBIDDEN_ACCESS, FUNCTIONAL_ERRORS, ValidationError } from '../config/errors'; import { publishUserAction } from '../listener/UserActionListener'; const innerCompute = (inners) => { @@ -114,7 +115,13 @@ export default { size, }; if (isCallError) { - const callError = head(context.errors); + let callError = head(context.errors); + // For errors directly generated by appollo + if (Object.keys(ApolloServerErrorCode).includes(callError.extensions?.code)) { + const data = { source: callError.message, ...callError.extensions }; + callError = ValidationError('[OPENCTI] API GraphQL framework error', callError.extensions?.field, data); + } + // Handle extended error option if (appLogExtendedErrors) { callMetaData.variables = variables; callMetaData.operation_query = stripIgnoredCharacters(context.request.query); diff --git a/opencti-platform/opencti-graphql/src/graphql/sseMiddleware.js b/opencti-platform/opencti-graphql/src/graphql/sseMiddleware.js index 6e4ed558f354..cbd134c79f86 100644 --- a/opencti-platform/opencti-graphql/src/graphql/sseMiddleware.js +++ b/opencti-platform/opencti-graphql/src/graphql/sseMiddleware.js @@ -295,7 +295,7 @@ const createSseMiddleware = () => { res.end(); req.session.destroy(); } catch (e) { - logApp.error(e, { action: 'close', clientId: channel.userId }); + logApp.error('Stream session destroy fail', { cause: e, action: 'close', clientId: channel.userId }); } } }, @@ -700,7 +700,7 @@ const createSseMiddleware = () => { // noinspection ES6MissingAwait processor.start(isRecoveryMode ? recoverStreamId : startStreamId); } catch (e) { - logApp.error(e, { id, type: 'live' }); + logApp.error('Stream handling error', { cause: e, id, type: 'live' }); res.statusMessage = `Error in stream ${id}: ${e.message}`; sendErrorStatusAndKillSession(req, res, 500); } diff --git a/opencti-platform/opencti-graphql/src/http/httpPlatform.js b/opencti-platform/opencti-graphql/src/http/httpPlatform.js index 6429564c17cd..38572222ec88 100644 --- a/opencti-platform/opencti-graphql/src/http/httpPlatform.js +++ b/opencti-platform/opencti-graphql/src/http/httpPlatform.js @@ -27,7 +27,6 @@ import { isEmptyField, isNotEmptyField } from '../database/utils'; import { buildContextDataForFile, publishUserAction } from '../listener/UserActionListener'; import { internalLoadById } from '../database/middleware-loader'; import { delUserContext, redisIsAlive } from '../database/redis'; -import { UnknownError } from '../config/errors'; import { rabbitMQIsAlive } from '../database/rabbitmq'; import { isEngineAlive } from '../database/engine'; @@ -207,7 +206,7 @@ const createApp = async (app) => { stream.pipe(res); } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error getting storage get file', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -237,7 +236,7 @@ const createApp = async (app) => { stream.pipe(res); } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error getting storage view file', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -267,7 +266,7 @@ const createApp = async (app) => { } } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error getting html file', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -292,7 +291,7 @@ const createApp = async (app) => { archive.pipe(res); } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error getting encrypted file', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -332,7 +331,7 @@ const createApp = async (app) => { } } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error auth by cert', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -391,7 +390,7 @@ const createApp = async (app) => { } } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error logout', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -415,7 +414,7 @@ const createApp = async (app) => { })(req, res, next); } catch (e) { setCookieError(res, e.message); - logApp.error(e); + logApp.error('Error auth provider', { cause: e }); res.status(503).send({ status: 'error', error: e.message }); } }); @@ -439,7 +438,7 @@ const createApp = async (app) => { const logged = await callbackLogin(); await authenticateUser(context, req, logged, provider); } catch (e) { - logApp.error(e, { provider }); + logApp.error('Error auth provider callback', { cause: e, provider }); setCookieError(res, 'Invalid authentication, please ask your administrator'); res.status(503).send({ status: 'error', error: e.message }); } finally { @@ -507,8 +506,7 @@ const createApp = async (app) => { // Error handling // eslint-disable-next-line @typescript-eslint/no-unused-vars app.use((err, req, res, next) => { - const error = UnknownError('Http call interceptor fail', { cause: err, referer: req.headers?.referer }); - logApp.error(error); + logApp.error('Http call interceptor fail', { cause: err, referer: req.headers?.referer }); res.status(500).send({ status: 'error', error: err.stack }); }); diff --git a/opencti-platform/opencti-graphql/src/http/httpServer.js b/opencti-platform/opencti-graphql/src/http/httpServer.js index aa0c5ee294b8..b03d68532f3c 100644 --- a/opencti-platform/opencti-graphql/src/http/httpServer.js +++ b/opencti-platform/opencti-graphql/src/http/httpServer.js @@ -18,7 +18,6 @@ import { isStrategyActivated, STRATEGY_CERT } from '../config/providers'; import { applicationSession } from '../database/session'; import { executionContext } from '../utils/access'; import { authenticateUserFromRequest, userWithOrigin } from '../domain/user'; -import { UnknownError } from '../config/errors'; const MIN_20 = 20 * 60 * 1000; const REQ_TIMEOUT = conf.get('app:request_timeout'); @@ -134,7 +133,7 @@ const createHttpServer = async () => { executeContext.user = userWithOrigin(req, user); } } catch (error) { - logApp.error(error); + logApp.error('Fail to authenticate the user in graphql context hook', { cause: error }); } return executeContext; } @@ -156,7 +155,7 @@ const listenServer = async () => { resolve({ server }); }); } catch (e) { - logApp.error(UnknownError('Http listen server fail', { cause: e })); + logApp.error('Http listen server fail', { cause: e }); reject(e); } }); diff --git a/opencti-platform/opencti-graphql/src/listener/supportPackageListener.ts b/opencti-platform/opencti-graphql/src/listener/supportPackageListener.ts index f0ccfd3251ac..025c3f98e0e0 100644 --- a/opencti-platform/opencti-graphql/src/listener/supportPackageListener.ts +++ b/opencti-platform/opencti-graphql/src/listener/supportPackageListener.ts @@ -25,16 +25,16 @@ export const onSupportPackageMessage = async (event: { instance: BasicStoreEntit await sendCurrentNodeSupportLogToS3(context, SYSTEM_USER, event.instance as StoreEntitySupportPackage); await registerNodeInSupportPackage(context, SYSTEM_USER, event.instance.id, PackageStatus.Ready); } else { - logApp.warn(`${event.instance.entity_type} entity cannot be sent to SupportPackage PubSubListener`); + logApp.warn('Entity cannot be sent to SupportPackage PubSubListener', { type: event.instance.entity_type }); } } catch (error) { + logApp.error('Error generating support package (first round)', { cause: error, from: 'supportListener', nodeId: NODE_INSTANCE_ID, packageId: event.instance.id }); try { await registerNodeInSupportPackage(context, SYSTEM_USER, event.instance.id, PackageStatus.InError); } catch (errorInError) { // Well we cannot do much here.... elastic seems broken. - logApp.error(errorInError, { from: 'supportListener', nodeId: NODE_INSTANCE_ID, packageId: event.instance.id }); + logApp.error('Error generating support package (second round)', { cause: errorInError, from: 'supportListener', nodeId: NODE_INSTANCE_ID, packageId: event.instance.id }); } - logApp.error(error, { from: 'supportListener', nodeId: NODE_INSTANCE_ID, packageId: event.instance.id }); } }; diff --git a/opencti-platform/opencti-graphql/src/manager/activityManager.ts b/opencti-platform/opencti-graphql/src/manager/activityManager.ts index 1c0e828d21dc..bcc316afcb16 100644 --- a/opencti-platform/opencti-graphql/src/manager/activityManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/activityManager.ts @@ -135,7 +135,7 @@ const activityStreamHandler = async (streamEvents: Array { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Activity manager already started by another API'); } else { - logApp.error(e, { manager: 'ACTIVITY_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Activity manager execution error', { cause: e, manager: 'ACTIVITY_MANAGER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/connectorManager.js b/opencti-platform/opencti-graphql/src/manager/connectorManager.js index 36390a31872e..33bdd707f4f1 100644 --- a/opencti-platform/opencti-graphql/src/manager/connectorManager.js +++ b/opencti-platform/opencti-graphql/src/manager/connectorManager.js @@ -128,7 +128,7 @@ const connectorHandler = async () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Connector manager already started by another API'); } else { - logApp.error(e, { manager: 'CONNECTOR_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Connector manager handling error', { cause: e, manager: 'CONNECTOR_MANAGER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/expiredManager.js b/opencti-platform/opencti-graphql/src/manager/expiredManager.js index 8c6929d02cdb..4f8abe4cf8cb 100644 --- a/opencti-platform/opencti-graphql/src/manager/expiredManager.js +++ b/opencti-platform/opencti-graphql/src/manager/expiredManager.js @@ -82,7 +82,7 @@ const expireHandler = async () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Expiration manager already started by another API'); } else { - logApp.error(e, { manager: 'EXPIRATION_SCHEDULER' }); + logApp.error('[OPENCTI-MODULE] Expiration manager handling error', { cause: e, manager: 'EXPIRATION_SCHEDULER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/fileIndexManager.ts b/opencti-platform/opencti-graphql/src/manager/fileIndexManager.ts index ef516bcffc50..aa17a9ff4955 100644 --- a/opencti-platform/opencti-graphql/src/manager/fileIndexManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/fileIndexManager.ts @@ -86,7 +86,7 @@ export const indexImportedFiles = async (context: AuthContext, indexFromDate: st }; }); const filesToIndex = await BluePromise.map(filesToLoad, loadFilesToIndex, { concurrency: 5 }) - .catch((error) => logApp.error(error, { manager: 'FILE_INDEX_MANAGER' })); + .catch((error) => logApp.error('[OPENCTI-MODULE] Index manager indexing error', { cause: error, manager: 'FILE_INDEX_MANAGER' })); // index all files one by one await elIndexFiles(context, SYSTEM_USER, filesToIndex); @@ -94,7 +94,7 @@ export const indexImportedFiles = async (context: AuthContext, indexFromDate: st } } catch (e) { // if one file processing raise an exception, we log and skip the bulk. - logApp.error(e, { manager: 'FILE_INDEX_MANAGER' }); + logApp.error('[OPENCTI-MODULE] File index manager handling error', { cause: e, manager: 'FILE_INDEX_MANAGER' }); } } }; @@ -124,7 +124,7 @@ const handleStreamEvents = async (streamEvents: Array> } } } catch (e) { - logApp.error(e, { manager: 'FILE_INDEX_MANAGER' }); + logApp.error('[OPENCTI-MODULE] File index manager handling error', { cause: e, manager: 'FILE_INDEX_MANAGER' }); } }; @@ -164,7 +164,7 @@ const initFileIndexManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] File index manager handler already started by another API'); } else { - logApp.error(e, { manager: 'FILE_INDEX_MANAGER' }); + logApp.error('[OPENCTI-MODULE] File index manager handling error', { cause: e, manager: 'FILE_INDEX_MANAGER' }); } } finally { running = false; @@ -194,7 +194,7 @@ const initFileIndexManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] File index manager stream handler already started by another API'); } else { - logApp.error(e, { manager: 'FILE_INDEX_MANAGER' }); + logApp.error('[OPENCTI-MODULE] File index manager handling error', { cause: e, manager: 'FILE_INDEX_MANAGER' }); } } finally { if (streamProcessor) await streamProcessor.shutdown(); diff --git a/opencti-platform/opencti-graphql/src/manager/garbageCollectionManager.ts b/opencti-platform/opencti-graphql/src/manager/garbageCollectionManager.ts index b2961b917149..cc618c2927cd 100644 --- a/opencti-platform/opencti-graphql/src/manager/garbageCollectionManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/garbageCollectionManager.ts @@ -24,7 +24,7 @@ export const garbageCollectionHandler = async () => { const deleteOperation = deleteOperationsToManage[i]; await confirmDelete(context, GARBAGE_COLLECTION_MANAGER_USER, deleteOperation.id); } catch (e) { - logApp.error(e, { manager: '[OPENCTI-MODULE] Garbage collection', id: deleteOperationsToManage[i].id, errorCount }); + logApp.error('[OPENCTI-MODULE] Garbage collection delete error', { cause: e, manager: 'GARBAGE_MANAGER', id: deleteOperationsToManage[i].id, errorCount }); errorCount += 1; } } diff --git a/opencti-platform/opencti-graphql/src/manager/historyManager.ts b/opencti-platform/opencti-graphql/src/manager/historyManager.ts index a20d57a0c1c9..736dcd1ca000 100644 --- a/opencti-platform/opencti-graphql/src/manager/historyManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/historyManager.ts @@ -195,7 +195,7 @@ const historyStreamHandler = async (streamEvents: Array { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] History manager already started by another API'); } else { - logApp.error(e, { manager: 'HISTORY_MANAGER' }); + logApp.error('[OPENCTI-MODULE] History manager handling error', { cause: e, manager: 'HISTORY_MANAGER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/ingestionManager.ts b/opencti-platform/opencti-graphql/src/manager/ingestionManager.ts index d9aff08041be..f97745d22c00 100644 --- a/opencti-platform/opencti-graphql/src/manager/ingestionManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/ingestionManager.ts @@ -268,7 +268,7 @@ const rssExecutor = async (context: AuthContext, turndownService: TurndownServic if (messages_number === 0) { const ingestionPromise = rssDataHandler(context, httpGet, turndownService, ingestion) .catch((e) => { - logApp.warn(e, { name: ingestion.name, context: '[OPENCTI-MODULE] INGESTION - RSS ingestion execution' }); + logApp.warn('[OPENCTI-MODULE] INGESTION - RSS ingestion execution', { cause: e, name: ingestion.name }); }); ingestionPromises.push(ingestionPromise); } else { @@ -443,7 +443,7 @@ const taxiiExecutor = async (context: AuthContext) => { } const ingestionPromise = taxiiHandler(context, ingestion) .catch((e) => { - logApp.warn(e, { name: ingestion.name, context: '[OPENCTI-MODULE] INGESTION - Taxii ingestion execution' }); + logApp.warn('[OPENCTI-MODULE] INGESTION - Taxii ingestion execution', { cause: e, name: ingestion.name }); }); ingestionPromises.push(ingestionPromise); } else { @@ -525,7 +525,7 @@ const csvExecutor = async (context: AuthContext) => { if (messages_number === 0) { const ingestionPromise = csvDataHandler(context, ingestion) .catch((e) => { - logApp.warn(e, { name: ingestion.name, context: '[OPENCTI-MODULE] INGESTION - CSV ingestion execution' }); + logApp.warn('[OPENCTI-MODULE] INGESTION - CSV ingestion execution', { cause: e, name: ingestion.name }); }); ingestionPromises.push(ingestionPromise); } else { @@ -558,7 +558,7 @@ const ingestionHandler = async () => { if (e.name === TYPE_LOCK_ERROR) { logApp.info('[OPENCTI-MODULE] INGESTION - Ingestion manager already in progress by another API'); } else { - logApp.error(e, { manager: 'INGESTION_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Ingestion manager handling error', { cause: e, manager: 'INGESTION_MANAGER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/managerModule.ts b/opencti-platform/opencti-graphql/src/manager/managerModule.ts index 217f9a5d8096..455c3007ea5b 100644 --- a/opencti-platform/opencti-graphql/src/manager/managerModule.ts +++ b/opencti-platform/opencti-graphql/src/manager/managerModule.ts @@ -78,7 +78,7 @@ const initManager = (manager: ManagerDefinition) => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug(`[OPENCTI-MODULE] ${manager.label} already started by another API`); } else { - logApp.error(e, { manager: manager.id }); + logApp.error(`[OPENCTI-MODULE] ${manager.label} handling error`, { cause: e, manager: manager.id }); } } finally { running = false; @@ -112,7 +112,7 @@ const initManager = (manager: ManagerDefinition) => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug(`[OPENCTI-MODULE] ${manager.label} stream handler already started by another API`); } else { - logApp.error(e, { manager: manager.id }); + logApp.error(`[OPENCTI-MODULE] ${manager.label} stream error`, { cause: e, manager: manager.id }); } } finally { if (streamProcessor) await streamProcessor.shutdown(); diff --git a/opencti-platform/opencti-graphql/src/manager/notificationManager.ts b/opencti-platform/opencti-graphql/src/manager/notificationManager.ts index ed344db2411d..01417dfe2a69 100644 --- a/opencti-platform/opencti-graphql/src/manager/notificationManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/notificationManager.ts @@ -571,7 +571,7 @@ const notificationLiveStreamHandler = async (streamEvents: Array { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Notification manager already started by another API'); } else { - logApp.error(e, { manager: 'NOTIFICATION_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Notification manager live handler error', { cause: e, manager: 'NOTIFICATION_MANAGER' }); } } finally { if (streamProcessor) await streamProcessor.shutdown(); @@ -669,7 +669,7 @@ const initNotificationManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Notification manager (digest) already started by another API'); } else { - logApp.error(e, { manager: 'NOTIFICATION_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Notification manager digest handler error', { cause: e, manager: 'NOTIFICATION_MANAGER' }); } } finally { if (lock) await lock.unlock(); diff --git a/opencti-platform/opencti-graphql/src/manager/playbookManager.ts b/opencti-platform/opencti-graphql/src/manager/playbookManager.ts index b7acbdbbd4fb..1f836d348ad1 100644 --- a/opencti-platform/opencti-graphql/src/manager/playbookManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/playbookManager.ts @@ -174,7 +174,7 @@ export const playbookExecutor = async ({ } catch (error) { // Error executing the step, register const executionError = error as Error; - logApp.error(error, { step: instanceWithConfig, bundle: baseBundle }); + logApp.error('[OPENCTI-MODULE] Playbook manager executor error', { cause: error, manager: 'PLAYBOOK_MANAGER', step: instanceWithConfig, bundle: baseBundle }); const end = utcDate(); const durationDiff = end.diff(start); const duration = moment.duration(durationDiff); @@ -304,7 +304,7 @@ const playbookStreamHandler = async (streamEvents: Array logApp.error(reason, { id: entityId, manager: 'PLAYBOOK_MANAGER' })); + }).catch((err) => { + logApp.error('[OPENCTI-MODULE] Playbook manager step executor error', { cause: err, id: entityId, manager: 'PLAYBOOK_MANAGER' }); + }); return true; } catch (e) { - logApp.error(e, { id: entityId, manager: 'PLAYBOOK_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Playbook manager step executor error', { cause: e, id: entityId, manager: 'PLAYBOOK_MANAGER' }); return false; } } @@ -389,7 +391,7 @@ const initPlaybookManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Playbook manager already started by another API'); } else { - logApp.error(e, { manager: 'PLAYBOOK_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Playbook manager error', { cause: e, manager: 'PLAYBOOK_MANAGER' }); } } finally { if (streamProcessor) await streamProcessor.shutdown(); @@ -486,7 +488,7 @@ const initPlaybookManager = () => { bundle, }); } catch (e) { - logApp.error(e, { id: node.id, manager: 'PLAYBOOK_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Playbook manager cron error', { cause: e, id: node.id, manager: 'PLAYBOOK_MANAGER' }); } } } @@ -512,7 +514,7 @@ const initPlaybookManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Playbook manager (cron) already started by another API'); } else { - logApp.error(e, { manager: 'PLAYBOOK_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Playbook manager cron handler error', { cause: e, manager: 'PLAYBOOK_MANAGER' }); } } finally { if (lock) await lock.unlock(); diff --git a/opencti-platform/opencti-graphql/src/manager/publisherManager.ts b/opencti-platform/opencti-graphql/src/manager/publisherManager.ts index df34b0e33414..ae8ecdfb5346 100644 --- a/opencti-platform/opencti-graphql/src/manager/publisherManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/publisherManager.ts @@ -81,7 +81,7 @@ export const internalProcessNotification = async ( is_read: false }; addNotification(context, SYSTEM_USER, createNotification).catch((err) => { - logApp.error(err, { manager: 'PUBLISHER_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Publisher manager add notification error', { cause: err, manager: 'PUBLISHER_MANAGER' }); return { error: err }; }); } else if (notifier_connector_id === NOTIFIER_CONNECTOR_EMAIL) { @@ -90,7 +90,7 @@ export const internalProcessNotification = async ( const generatedEmail = ejs.render(template, { ...templateData, url_suffix: urlSuffix }); const mail = { from: settings.platform_email, to: user.user_email, subject: generatedTitle, html: generatedEmail }; await sendMail(mail).catch((err) => { - logApp.error(err, { manager: 'PUBLISHER_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Publisher manager send email error', { cause: err, manager: 'PUBLISHER_MANAGER' }); return { error: err }; }); } else if (notifier_connector_id === NOTIFIER_CONNECTOR_SIMPLIFIED_EMAIL) { @@ -116,7 +116,7 @@ export const internalProcessNotification = async ( const generatedEmail = ejs.render(SIMPLIFIED_EMAIL_TEMPLATE, finalTemplateData); const mail = { from: settings.platform_email, to: user.user_email, subject: generatedTitle, html: generatedEmail }; await sendMail(mail).catch((err) => { - logApp.error(err, { manager: 'PUBLISHER_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Publisher manager send email error', { cause: err, manager: 'PUBLISHER_MANAGER' }); return { error: err }; }); } else if (notifier_connector_id === NOTIFIER_CONNECTOR_WEBHOOK) { @@ -128,7 +128,7 @@ export const internalProcessNotification = async ( const httpClientOptions: GetHttpClient = { responseType: 'json', headers: dataHeaders }; const httpClient = getHttpClient(httpClientOptions); await httpClient.call({ url, method: verb, params: dataParameters, data: dataJson }).catch((err) => { - logApp.error(err, { manager: 'PUBLISHER_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Publisher manager webhook error', { cause: err, manager: 'PUBLISHER_MANAGER' }); return { error: err }; }); } else { @@ -210,7 +210,7 @@ const publisherStreamHandler = async (streamEvents: Array { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-PUBLISHER] Publisher manager already started by another API'); } else { - logApp.error(e, { manager: 'PUBLISHER_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Publisher manager error', { cause: e, manager: 'PUBLISHER_MANAGER' }); } } finally { if (streamProcessor) await streamProcessor.shutdown(); diff --git a/opencti-platform/opencti-graphql/src/manager/retentionManager.ts b/opencti-platform/opencti-graphql/src/manager/retentionManager.ts index 700407747f01..afdd1edd4e90 100644 --- a/opencti-platform/opencti-graphql/src/manager/retentionManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/retentionManager.ts @@ -91,7 +91,7 @@ const executeProcessing = async (context: AuthContext, retentionRule: RetentionR } catch (err: any) { // Only log the error if not an already deleted message (that can happen though concurrency deletion) if (err?.extensions?.code !== ALREADY_DELETED_ERROR) { - logApp.error(err, { id: node.id, manager: 'RETENTION_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Retention manager error', { cause: err, id: node.id, manager: 'RETENTION_MANAGER' }); } } }; diff --git a/opencti-platform/opencti-graphql/src/manager/ruleManager.ts b/opencti-platform/opencti-graphql/src/manager/ruleManager.ts index 23ab4305cdcb..5e49a6e7a1e8 100644 --- a/opencti-platform/opencti-graphql/src/manager/ruleManager.ts +++ b/opencti-platform/opencti-graphql/src/manager/ruleManager.ts @@ -138,7 +138,7 @@ const isMatchRuleFilters = (rule: RuleDefinition, element: StixCoreObject): bool const handleRuleError = async (event: BaseEvent, error: unknown) => { const { type } = event; - logApp.error(error, { event, type }); + logApp.error('[OPENCTI-MODULE] Rule manager error', { cause: error, event, type }); }; const applyCleanupOnDependencyIds = async (deletionIds: Array, rules: Array) => { @@ -239,7 +239,7 @@ export const rulesCleanHandler = async ( } } catch (err: any) { if (err.name !== ALREADY_DELETED_ERROR) { - logApp.error(err, { manager: 'RULE_ENGINE' }); + logApp.error('[OPENCTI-MODULE] Rule manager clean error', { cause: err, manager: 'RULE_ENGINE' }); } } } @@ -305,7 +305,7 @@ const initRuleManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Rule engine already started by another API'); } else { - logApp.error(e, { manager: 'RULE_ENGINE' }); + logApp.error('[OPENCTI-MODULE] Rule engine handler error', { cause: e, manager: 'RULE_ENGINE' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/manager/syncManager.js b/opencti-platform/opencti-graphql/src/manager/syncManager.js index 68964a95d260..812832941f77 100644 --- a/opencti-platform/opencti-graphql/src/manager/syncManager.js +++ b/opencti-platform/opencti-graphql/src/manager/syncManager.js @@ -58,7 +58,7 @@ const syncManagerInstance = (syncId) => { logApp.info(`[OPENCTI] Sync ${syncId}: listening ${eventSource.url} with id ${connectionId}`); }); eventSource.on('error', (error) => { - logApp.warn(error, { id: syncId, manager: 'SYNC_MANAGER' }); + logApp.warn('[OPENCTI] Sync stream error', { id: syncId, manager: 'SYNC_MANAGER', cause: error }); }); }; const manageBackPressure = async (httpClient, { uri }, currentDelay) => { @@ -149,7 +149,7 @@ const syncManagerInstance = (syncId) => { await saveCurrentState(context, 'event', sync, eventId); } } catch (e) { - logApp.error(e, { id: syncId, manager: 'SYNC_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Sync manager event handling error', { cause: e, id: syncId, manager: 'SYNC_MANAGER' }); } } await wait(10); @@ -225,7 +225,7 @@ const initSyncManager = () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Sync manager already in progress by another API'); } else { - logApp.error(e, { manager: 'SYNC_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Sync manager handler error', { cause: e, manager: 'SYNC_MANAGER' }); } } finally { managerRunning = false; diff --git a/opencti-platform/opencti-graphql/src/manager/taskManager.js b/opencti-platform/opencti-graphql/src/manager/taskManager.js index 3e5a678445ff..c64f25ba6b6a 100644 --- a/opencti-platform/opencti-graphql/src/manager/taskManager.js +++ b/opencti-platform/opencti-graphql/src/manager/taskManager.js @@ -36,7 +36,7 @@ import { import { now } from '../utils/format'; import { EVENT_TYPE_CREATE, READ_DATA_INDICES, READ_DATA_INDICES_WITHOUT_INFERRED, UPDATE_OPERATION_ADD, UPDATE_OPERATION_REMOVE } from '../database/utils'; import { elPaginate, elUpdate, ES_MAX_CONCURRENCY } from '../database/engine'; -import { ForbiddenAccess, FunctionalError, TYPE_LOCK_ERROR, UnsupportedError, ValidationError } from '../config/errors'; +import { ForbiddenAccess, FunctionalError, TYPE_LOCK_ERROR, ValidationError } from '../config/errors'; import { ABSTRACT_BASIC_RELATIONSHIP, ABSTRACT_STIX_CORE_RELATIONSHIP, @@ -480,7 +480,7 @@ const executeProcessing = async (context, user, job, scope) => { const operations = { [INPUT_OBJECTS]: type.toLowerCase() }; // add, remove, replace await patchAttribute(context, user, value, ENTITY_TYPE_CONTAINER, patch, { operations }); } catch (err) { - logApp.error(err); + logApp.error('[OPENCTI-MODULE] Task manager index processing error', { cause: err, field, index: valueIndex }); if (errors.length < MAX_TASK_ERRORS) { errors.push({ id: value, message: err.message, reason: err.reason }); } @@ -539,7 +539,7 @@ const executeProcessing = async (context, user, job, scope) => { await executeUnshareMultiple(context, user, actionContext, element); } } catch (err) { - logApp.error(err); + logApp.error('[OPENCTI-MODULE] Task manager index processing error', { cause: err, field, index: elementIndex }); if (errors.length < MAX_TASK_ERRORS) { errors.push({ id: element.id, message: `${err.message}${err.data?.reason ? ` - ${err.reason}` : ''}` }); } @@ -570,7 +570,7 @@ export const taskHandler = async () => { const isListTask = task.type === TASK_TYPE_LIST; const isRuleTask = task.type === TASK_TYPE_RULE; if (!isQueryTask && !isListTask && !isRuleTask) { - logApp.error(UnsupportedError('Unsupported task type', { type: task.type })); + logApp.error('[OPENCTI-MODULE] Task manager unsupported type', { type: task.type }); return; } // endregion @@ -614,7 +614,7 @@ export const taskHandler = async () => { if (e.name === TYPE_LOCK_ERROR) { logApp.debug('[OPENCTI-MODULE] Task manager already in progress by another API'); } else { - logApp.error(e, { manager: 'TASK_MANAGER' }); + logApp.error('[OPENCTI-MODULE] Task manager handler error', { cause: e, manager: 'TASK_MANAGER' }); } } finally { running = false; diff --git a/opencti-platform/opencti-graphql/src/modules/xtm/xtm-domain.js b/opencti-platform/opencti-graphql/src/modules/xtm/xtm-domain.js index 09eb7856d1c4..8bdd3c3c9fa5 100644 --- a/opencti-platform/opencti-graphql/src/modules/xtm/xtm-domain.js +++ b/opencti-platform/opencti-graphql/src/modules/xtm/xtm-domain.js @@ -401,7 +401,12 @@ export const generateOpenBasScenario = async (context, user, stixCoreObject, att const endingTime = new Date().getTime(); const totalTime = endingTime - startingTime; if (totalTime > 120000) { - logApp.warn(`[OPENCTI-MODULE][XTM] Long scenario generation time. Generating ${createAndInjectScenarioPromises.length} emails took ${totalTime} ms`, { useAI, simulationType }); + logApp.warn('[OPENCTI-MODULE][XTM] Long scenario generation time', { + size: createAndInjectScenarioPromises.length, + took: totalTime, + useAI, + simulationType + }); } logApp.info(`[OPENCTI-MODULE][XTM] Generating ${createAndInjectScenarioPromises.length} emails took ${totalTime} ms`, { useAI, simulationType }); return `${XTM_OPENBAS_URL}/admin/scenarios/${obasScenario.scenario_id}/injects`; diff --git a/opencti-platform/opencti-graphql/src/parser/csv-bundler.ts b/opencti-platform/opencti-graphql/src/parser/csv-bundler.ts index 06e822dce7bd..5db8def31beb 100644 --- a/opencti-platform/opencti-graphql/src/parser/csv-bundler.ts +++ b/opencti-platform/opencti-graphql/src/parser/csv-bundler.ts @@ -113,7 +113,7 @@ const internalGenerateBundles = async ( } } } catch (e) { - logApp.error(e); + logApp.error('CSV generate handler error', { cause: e }); } } } @@ -272,7 +272,7 @@ export const bundleProcess = async ( const csvData = record.join(sanitizedMapper.separator); bundleBuilder.addObjects(stixObjects, csvData); } catch (e) { - logApp.error(e); + logApp.error('CSV bundle process handler error', { cause: e }); } } }))); diff --git a/opencti-platform/opencti-graphql/src/python/pythonBridge.js b/opencti-platform/opencti-graphql/src/python/pythonBridge.js index 3d65b74ffe44..a63b92613631 100644 --- a/opencti-platform/opencti-graphql/src/python/pythonBridge.js +++ b/opencti-platform/opencti-graphql/src/python/pythonBridge.js @@ -51,7 +51,7 @@ export const execChildPython = async (context, user, scriptPath, scriptName, arg } }); shell.on('stderr', (stderr) => { - logApp.error(`[stderr] ${stderr}`); + logApp.error('[PYTHON BRIDGE] Error executing python', { stderr }); messages.push(stderr); //* v8 ignore if */ if (DEV_MODE && stderr.startsWith('ERROR:')) { @@ -89,7 +89,7 @@ const createChildStixPattern = async (context, user, observableType, observableV ); return result.data; } catch (err) { - logApp.warn(err); + logApp.warn('[BRIDGE] createChildStixPattern', { cause: err }); return null; } }; @@ -104,7 +104,7 @@ const checkChildIndicatorSyntax = async (context, user, patternType, indicatorVa ); return result.data; } catch (err) { - logApp.warn(err); + logApp.warn('[BRIDGE] checkChildIndicatorSyntax', { cause: err }); return null; } }; @@ -129,13 +129,13 @@ const execNativePython = async (context, user, script, ...args) => { }; const createNativeStixPattern = async (context, user, observableType, observableValue) => { return execNativePython(context, user, CREATE_PATTERN_SCRIPT, observableType, observableValue).catch((err) => { - logApp.warn(err); + logApp.warn('[BRIDGE] createNativeStixPattern', { cause: err }); return null; }); }; const checkNativeIndicatorSyntax = async (context, user, patternType, indicatorValue) => { return execNativePython(context, user, CHECK_INDICATOR_SCRIPT, patternType, indicatorValue).catch((err) => { - logApp.warn(err); + logApp.warn('[BRIDGE] checkNativeIndicatorSyntax', { cause: err }); return null; }); }; diff --git a/opencti-platform/opencti-graphql/src/resolvers/user.js b/opencti-platform/opencti-graphql/src/resolvers/user.js index 65a3ab983ede..b2231b4a32f6 100644 --- a/opencti-platform/opencti-graphql/src/resolvers/user.js +++ b/opencti-platform/opencti-graphql/src/resolvers/user.js @@ -156,7 +156,7 @@ const userResolvers = { const { user, provider } = await new Promise((resolve) => { passport.authenticate(auth.provider, {}, (err, authUser, info) => { if (err || info) { - logApp.warn(err, { info, provider: auth.provider }); + logApp.warn('Token authenticate error', { cause: err, info, provider: auth.provider }); } resolve({ user: authUser, provider: auth.provider }); })({ body }); diff --git a/opencti-platform/opencti-graphql/tests/01-unit/utils/logger-test.ts b/opencti-platform/opencti-graphql/tests/01-unit/utils/logger-test.ts new file mode 100644 index 000000000000..ebf8095a2669 --- /dev/null +++ b/opencti-platform/opencti-graphql/tests/01-unit/utils/logger-test.ts @@ -0,0 +1,228 @@ +import * as R from 'ramda'; +import { describe, expect, it } from 'vitest'; +import { appLogLevelMaxArraySize, appLogLevelMaxStringSize, limitMetaErrorComplexity } from '../../../src/config/conf'; + +const CLASSIC_OBJECT = { + category: 'APP', + errors: [ + { + attributes: { + errors: [ + { + index: 'opencti_stix_domain_objects-000001', + index_uuid: 'ntQ2slJaRmWphjOmcls3lA', + reason: '[b2349596-2fa3-4444-842d-effa8b34f267]: version conflict, required seqNo [51514085], primary term [64]. current document has seqNo [51514086] and primary term [64]', + shard: '0', + type: 'version_conflict_engine_exception' + } + ], + genre: 'TECHNICAL', + http_status: 500 + }, + message: 'Bulk indexing fail', + name: 'DATABASE_ERROR', + stack: 'GraphQLError: Bulk indexing fail\\n at error (/opt/opencti/build/src/config/errors.js:7:10)\\n at DatabaseError (/opt/opencti/build/src/config/errors.js:61:48)\\n at /opt/opencti/build/src/database/engine.js:3425:13\\n at processTicksAndRejections (node:internal/process/task_queues:95:5)\\n at elRemoveRelationConnection (/opt/opencti/build/src/database/engine.js:3582:9)\\n at elDeleteElements (/opt/opencti/build/src/database/engine.js:3773:3)\\n at internalDeleteElementById (/opt/opencti/build/src/database/middleware.js:3253:7)\\n at deleteElementById (/opt/opencti/build/src/database/middleware.js:3275:32)\\n at deleteElement (/opt/opencti/build/src/manager/retentionManager.ts:37:5)\\n at deleteFn (/opt/opencti/build/src/manager/retentionManager.ts:83:11)' + } + ], + id: '3f001108-c42c-4131-b3a3-583a98043c15', + level: 'error', + manager: 'RETENTION_MANAGER', + message: 'Bulk indexing fail', + source: 'backend', + timestamp: '2025-01-09T20:57:05.422Z', + version: '6.4.6' +}; + +const TOO_COMPLEX_OBJECT = { + category: 'APP', + errors: [ + { + attributes: { + category_to_limit: [ + 'Item 1', + 'Item 2', + 'Item 3', + 'Item 4', + 'Item 5', + 'Item 6', + 'Item 7', + 'Item 8', + 'Item 9', + 'Item 10', + 'Item 11', + 'Item 12', + 'Item 13', + 'Item 14', + 'Item 15', + 'Item 16', + 'Item 17', + 'Item 18', + 'Item 19', + 'Item 20', + 'Item 21', + 'Item 22', + 'Item 23', + 'Item 24', + 'Item 25', + 'Item 26', + 'Item 27', + 'Item 28', + 'Item 29', + 'Item 30', + 'Item 31', + 'Item 32', + 'Item 33', + 'Item 34', + 'Item 35', + 'Item 36', + 'Item 37', + 'Item 38', + 'Item 39', + 'Item 40', + 'Item 41', + 'Item 42', + 'Item 43', + 'Item 44', + 'Item 45', + 'Item 46', + 'Item 47', + 'Item 48', + 'Item 49', + 'Item 50', + 'Item 51', + 'Item 52', + 'Item 53', + 'Item 54', + 'Item 55', + 'Item 56' + ] + }, + message: 'Bulk indexing fail', + name: 'DATABASE_ERROR', + departments: [ + { + departmentName: 'Research and Development', + teams: [ + { + teamName: 'AI Team', + members: [ + { + name: 'Alice', + role: 'Lead Engineer', + category_to_limit: ['2', '1'] + }, + { + name: 'Bob', + role: 'Data Scientist', + category_to_limit: [ + 'Item 1', + 'Item 2', + 'Item 3', + 'Item 4', + 'Item 5', + 'Item 6', + 'Item 7', + 'Item 8', + 'Item 9', + 'Item 10', + 'Item 11', + 'Item 12', + 'Item 13', + 'Item 14', + 'Item 15', + 'Item 16', + 'Item 17', + 'Item 18', + 'Item 19', + 'Item 20', + 'Item 21', + 'Item 22', + 'Item 23', + 'Item 24', + 'Item 25', + 'Item 26', + 'Item 27', + 'Item 28', + 'Item 29', + 'Item 30', + 'Item 31', + 'Item 32', + 'Item 33', + 'Item 34', + 'Item 35', + 'Item 36', + 'Item 37', + 'Item 38', + 'Item 39', + 'Item 40', + 'Item 41', + 'Item 42', + 'Item 43', + 'Item 44', + 'Item 45', + 'Item 46', + 'Item 47', + 'Item 48', + 'Item 49', + 'Item 50', + 'Item 51', + 'Item 52', + 'Item 53', + 'Item 54', + 'Item 55', + 'Item 56' + ] + } + ] + }, + { + teamName: 'Robotics Team', + members: [ + { + name: 'Charlie', + role: 'Mechanical Engineer', + category_to_limit: ['2', '1', '3'], + } + ] + } + ] + } + ] + } + ], + id: '3f001108-c42c-4131-b3a3-583a98043c15', + level: 'error', + source: R.range(1, 6000).map(() => 'A').join(''), + timestamp: '2025-01-09T20:57:05.422Z' +}; + +describe('Logger test suite', () => { + it('Log object is correctly untouched', () => { + const cleanObject = limitMetaErrorComplexity(CLASSIC_OBJECT); + expect(JSON.stringify(cleanObject)).toEqual(JSON.stringify(CLASSIC_OBJECT)); + }); + + it('Log object is correctly limited', () => { + let initialSize = TOO_COMPLEX_OBJECT.errors[0].attributes.category_to_limit.length; + const start = new Date().getTime(); + const cleanObject = limitMetaErrorComplexity(TOO_COMPLEX_OBJECT); + const parsingTimeMs = new Date().getTime() - start; + expect(parsingTimeMs).to.be.lt(2); + let cleanedSize = cleanObject.errors[0].attributes.category_to_limit.length; + expect(initialSize).not.toEqual(cleanedSize); + expect(initialSize).to.be.gt(appLogLevelMaxArraySize); + expect(cleanedSize).to.be.eq(appLogLevelMaxArraySize); + // check more inside look + initialSize = TOO_COMPLEX_OBJECT.errors[0].departments[0].teams[0].members[1].category_to_limit.length; + cleanedSize = cleanObject.errors[0].departments[0].teams[0].members[1].category_to_limit.length; + expect(initialSize).not.toEqual(cleanedSize); + expect(initialSize).to.be.gt(appLogLevelMaxArraySize); + expect(cleanedSize).to.be.eq(appLogLevelMaxArraySize); + initialSize = TOO_COMPLEX_OBJECT.source.length; + cleanedSize = cleanObject.source.length; + // Check max string + expect(initialSize).not.toEqual(cleanedSize); + expect(initialSize).to.be.gt(appLogLevelMaxStringSize); + expect(cleanedSize).to.be.eq(appLogLevelMaxStringSize); + }); +}); From 3f0d4a64ebfeef8434d83fceb9e4e88a384b832a Mon Sep 17 00:00:00 2001 From: Julien Richard Date: Fri, 10 Jan 2025 00:15:56 +0100 Subject: [PATCH 2/2] [backend] Ensure log lines would be efficiently streamed to log visualization tools (#4199) + rework logging messages --- opencti-platform/opencti-graphql/src/boot.js | 1 - 1 file changed, 1 deletion(-) diff --git a/opencti-platform/opencti-graphql/src/boot.js b/opencti-platform/opencti-graphql/src/boot.js index c7132c5076f1..b6b322ce131b 100644 --- a/opencti-platform/opencti-graphql/src/boot.js +++ b/opencti-platform/opencti-graphql/src/boot.js @@ -2,7 +2,6 @@ import { environment, getStoppingState, logApp, setStoppingState } from './confi import platformInit, { checkFeatureFlags, checkSystemDependencies } from './initialization'; import cacheManager from './manager/cacheManager'; import { shutdownRedisClients } from './database/redis'; -import { UnknownError } from './config/errors'; import { shutdownModules, startModules } from './managers'; // region platform start and stop