diff --git a/CHANGELOG.md b/CHANGELOG.md index 5d7fe9b..7025bd6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,10 +9,21 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/). ### Added - Predefined kind `telemetry-to-otlp` that creates exporters based on OTLP exporter configuration via environment variables +- If `@opentelemetry/instrumentation-runtime-node` is in the project's dependencies but not in `cds.requires.telemetry.instrumentations`, it is registered automatically + - Disable via `cds.requires.telemetry.instrumentations.instrumentation-runtime-node = false` - Experimental!: Propagate W3C trace context to SAP HANA via session context `SAP_PASSPORT` - Enable via environment variable `SAP_PASSPORT` -- If `@opentelemetry/instrumentation-runtime-node` is in the project's dependencies but not in `cds.env.requires.telemetry.instrumentations`, it is registered automatically - - Disable via `cds.env.requires.telemetry.instrumentations.instrumentation-runtime-node = false` +- Experimental!: Intercept and export application logs (cf. `cds.log()`) via OpenTelemetry + - Enable by adding section `logging` to `cds.requires.telemetry` as follows (using `grpc` as an example): + ```json + "logging": { + "exporter": { + "module": "@opentelemetry/exporter-logs-otlp-grpc", + "class": "OTLPLogExporter" + } + } + ``` + - Requires additional dependencies `@opentelemetry/api-logs`, `@opentelemetry/sdk-logs`, and the configured exporter module (`cds.requires.telemetry.logging.module`) ### Changed @@ -77,7 +88,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/). ### Added - Support for local modules (e.g., exporters) via `[...].module = ''` -- Disable pool metrics via `cds.env.requires.telemetry.metrics._db_pool = false` (beta) +- Disable pool metrics via `cds.requires.telemetry.metrics._db_pool = false` (beta) ### Fixed @@ -90,7 +101,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/). ### Added - Support for own, high resolution timestamps - - Enable via `cds.env.requires.telemetry.tracing.hrtime = true` + - Enable via `cds.requires.telemetry.tracing.hrtime = true` - Enabled by default in development profile ## Version 0.0.5 - 2024-03-11 @@ -107,7 +118,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/). - Disable change via environment variable `HOST_METRICS_RETAIN_SYSTEM=true` - Metric exporter's property `temporalityPreference` always gets defaulted to `DELTA` - Was previously only done for kind `telemetry-to-dynatrace` - - Set custom value via `cds.env.requires.telemetry.metrics.exporter.config.temporalityPreference` + - Set custom value via `cds.requires.telemetry.metrics.exporter.config.temporalityPreference` ### Fixed diff --git a/lib/index.js b/lib/index.js index d9d37f7..0abaf72 100644 --- a/lib/index.js +++ b/lib/index.js @@ -7,6 +7,7 @@ const { ATTR_SERVICE_NAME, ATTR_SERVICE_VERSION } = require('@opentelemetry/sema const tracing = require('./tracing') const metrics = require('./metrics') +const logging = require('./logging') const { getDiagLogLevel, getResource, _require } = require('./utils') function _getInstrumentations() { @@ -63,13 +64,18 @@ module.exports = function () { */ const meterProvider = metrics(resource) + /* + * setup logging + */ + const loggerProvider = logging(resource) + /* * register instrumentations */ registerInstrumentations({ tracerProvider, meterProvider, - // loggerProvider, + loggerProvider, instrumentations: _getInstrumentations() }) } diff --git a/lib/logging/index.js b/lib/logging/index.js new file mode 100644 index 0000000..ca3ccfe --- /dev/null +++ b/lib/logging/index.js @@ -0,0 +1,128 @@ +const cds = require('@sap/cds') +const LOG = cds.log('telemetry') + +const { getEnv, getEnvWithoutDefaults } = require('@opentelemetry/core') + +const { getCredsForCLSAsUPS, augmentCLCreds, _require } = require('../utils') + +const _protocol2module = { + grpc: '@opentelemetry/exporter-logs-otlp-grpc', + 'http/protobuf': '@opentelemetry/exporter-logs-otlp-proto', + 'http/json': '@opentelemetry/exporter-logs-otlp-http' +} + +function _getExporter() { + let { + kind, + logging: { exporter: loggingExporter }, + credentials + } = cds.env.requires.telemetry + + // for kind telemetry-to-otlp based on env vars + if (loggingExporter === 'env') { + const otlp_env = getEnvWithoutDefaults() + const dflt_env = getEnv() + const protocol = + otlp_env.OTEL_EXPORTER_OTLP_LOGS_PROTOCOL ?? + otlp_env.OTEL_EXPORTER_OTLP_PROTOCOL ?? + dflt_env.OTEL_EXPORTER_OTLP_LOGS_PROTOCOL ?? + dflt_env.OTEL_EXPORTER_OTLP_PROTOCOL + loggingExporter = { module: _protocol2module[protocol], class: 'OTLPLogExporter' } + } + + // use _require for better error message + const loggingExporterModule = _require(loggingExporter.module) + if (!loggingExporterModule[loggingExporter.class]) + throw new Error(`Unknown logs exporter "${loggingExporter.class}" in module "${loggingExporter.module}"`) + const config = { ...(loggingExporter.config || {}) } + + if (kind.match(/to-cloud-logging$/)) { + if (!credentials) credentials = getCredsForCLSAsUPS() + if (!credentials) throw new Error('No SAP Cloud Logging credentials found.') + augmentCLCreds(credentials) + config.url ??= credentials.url + config.credentials ??= credentials.credentials + } + + const exporter = new loggingExporterModule[loggingExporter.class](config) + LOG._debug && LOG.debug('Using logs exporter:', exporter) + + return exporter +} + +function _getCustomProcessor(exporter) { + let { + logging: { processor: loggingProcessor } + } = cds.env.requires.telemetry + + if (!loggingProcessor) return + + // use _require for better error message + const loggingProcessorModule = _require(loggingProcessor.module) + if (!loggingProcessorModule[loggingProcessor.class]) + throw new Error(`Unknown logs processor "${loggingProcessor.class}" in module "${loggingProcessor.module}"`) + + const processor = new loggingProcessorModule[loggingProcessor.class](exporter) + LOG._debug && LOG.debug('Using logs processor:', processor) + + return processor +} + +module.exports = resource => { + if (!cds.env.requires.telemetry.logging?.exporter) return + + const { logs, SeverityNumber } = require('@opentelemetry/api-logs') + const { LoggerProvider, BatchLogRecordProcessor, SimpleLogRecordProcessor } = require('@opentelemetry/sdk-logs') + + let loggerProvider = logs.getLoggerProvider() + if (!loggerProvider.getDelegateLogger()) { + loggerProvider = new LoggerProvider({ resource }) + logs.setGlobalLoggerProvider(loggerProvider) + } else { + LOG._warn && LOG.warn('LoggerProvider already initialized by a different module. It will be used as is.') + loggerProvider = loggerProvider.getDelegateLogger() + } + + const exporter = _getExporter() + + const logProcessor = + _getCustomProcessor(exporter) || + (process.env.NODE_ENV === 'production' + ? new BatchLogRecordProcessor(exporter) + : new SimpleLogRecordProcessor(exporter)) + loggerProvider.addLogRecordProcessor(logProcessor) + + const loggers = {} + const l2s = { 1: 'ERROR', 2: 'WARN', 3: 'INFO', 4: 'DEBUG', 5: 'TRACE' } + + // intercept logs via format + const { format } = cds.log + cds.log.format = (module, level, ...args) => { + const res = format(module, level, ...args) + + let log + try { + log = res.length === 1 && res[0].startsWith?.('{"') && JSON.parse(res[0]) + } catch { + // ignore + } + if (log) { + const logger = loggers[module] || (loggers[module] = loggerProvider.getLogger(module)) + const severity = l2s[level] + // TODO: what to log? + logger.emit({ + severityNumber: SeverityNumber[severity], + severityText: severity, + body: log.msg, + attributes: { 'log.type': 'LogRecord' } + }) + } + + return res + } + + // clear cached loggers + cds.log.loggers = {} + + return loggerProvider +} diff --git a/lib/metrics/index.js b/lib/metrics/index.js index ea1a943..09bb635 100644 --- a/lib/metrics/index.js +++ b/lib/metrics/index.js @@ -44,35 +44,36 @@ function _getExporter() { metricsExporter.module === '@cap-js/telemetry' ? require('../exporter') : _require(metricsExporter.module) if (!metricsExporterModule[metricsExporter.class]) throw new Error(`Unknown metrics exporter "${metricsExporter.class}" in module "${metricsExporter.module}"`) - const metricsConfig = { ...(metricsExporter.config || {}) } + const config = { ...(metricsExporter.config || {}) } if (kind.match(/to-dynatrace$/)) { if (!credentials) credentials = getCredsForDTAsUPS() if (!credentials) throw new Error('No Dynatrace credentials found.') - metricsConfig.url ??= `${credentials.apiurl}/v2/otlp/v1/metrics` - metricsConfig.headers ??= {} + config.url ??= `${credentials.apiurl}/v2/otlp/v1/metrics` + config.headers ??= {} // credentials.rest_apitoken?.token is deprecated and only supported for compatibility reasons const { token_name } = cds.env.requires.telemetry // metrics_apitoken for compatibility with previous releases const token = credentials[token_name] || credentials.metrics_apitoken || credentials.rest_apitoken?.token if (!token) throw new Error(`Neither "${token_name}" nor deprecated "rest_apitoken.token" found in Dynatrace credentials`) - metricsConfig.headers.authorization ??= `Api-Token ${token}` + config.headers.authorization ??= `Api-Token ${token}` } if (kind.match(/to-cloud-logging$/)) { if (!credentials) credentials = getCredsForCLSAsUPS() if (!credentials) throw new Error('No SAP Cloud Logging credentials found.') augmentCLCreds(credentials) - metricsConfig.url ??= credentials.url - metricsConfig.credentials ??= credentials.credentials + config.url ??= credentials.url + config.credentials ??= credentials.credentials } // default to DELTA - metricsConfig.temporalityPreference ??= AggregationTemporality.DELTA + config.temporalityPreference ??= AggregationTemporality.DELTA - const exporter = new metricsExporterModule[metricsExporter.class](metricsConfig) + const exporter = new metricsExporterModule[metricsExporter.class](config) LOG._debug && LOG.debug('Using metrics exporter:', exporter) + return exporter } diff --git a/lib/tracing/index.js b/lib/tracing/index.js index 313667b..53cdc23 100644 --- a/lib/tracing/index.js +++ b/lib/tracing/index.js @@ -99,32 +99,33 @@ function _getExporter() { const tracingExporterModule = tracingExporter.module === '@cap-js/telemetry' ? require('../exporter') : _require(tracingExporter.module) if (!tracingExporterModule[tracingExporter.class]) - throw new Error(`Unknown tracing exporter "${tracingExporter.class}" in module "${tracingExporter.module}"`) - const tracingConfig = { ...(tracingExporter.config || {}) } + throw new Error(`Unknown trace exporter "${tracingExporter.class}" in module "${tracingExporter.module}"`) + const config = { ...(tracingExporter.config || {}) } if (kind.match(/to-dynatrace$/)) { if (!credentials) credentials = getCredsForDTAsUPS() if (!credentials) throw new Error('No Dynatrace credentials found') - tracingConfig.url ??= `${credentials.apiurl}/v2/otlp/v1/traces` - tracingConfig.headers ??= {} + config.url ??= `${credentials.apiurl}/v2/otlp/v1/traces` + config.headers ??= {} // credentials.rest_apitoken?.token is deprecated and only supported for compatibility reasons const { token_name } = cds.env.requires.telemetry const token = credentials[token_name] || credentials.rest_apitoken?.token if (!token) throw new Error(`Neither "${token_name}" nor deprecated "rest_apitoken.token" found in Dynatrace credentials`) - tracingConfig.headers.authorization ??= `Api-Token ${token}` + config.headers.authorization ??= `Api-Token ${token}` } if (kind.match(/to-cloud-logging$/)) { if (!credentials) credentials = getCredsForCLSAsUPS() if (!credentials) throw new Error('No SAP Cloud Logging credentials found') augmentCLCreds(credentials) - tracingConfig.url ??= credentials.url - tracingConfig.credentials ??= credentials.credentials + config.url ??= credentials.url + config.credentials ??= credentials.credentials } - const exporter = new tracingExporterModule[tracingExporter.class](tracingConfig) - LOG._debug && LOG.debug('Using tracing exporter:', exporter) + const exporter = new tracingExporterModule[tracingExporter.class](config) + LOG._debug && LOG.debug('Using trace exporter:', exporter) + return exporter } @@ -150,7 +151,7 @@ module.exports = resource => { !hasDependency('@opentelemetry/exporter-trace-otlp-proto') if (via_one_agent) { // if Dynatrace OneAgent is present, no exporter is needed - LOG._info && LOG.info('Dynatrace OneAgent detected, disabling tracing exporter') + LOG._info && LOG.info('Dynatrace OneAgent detected, disabling trace exporter') } else { const exporter = _getExporter() const spanProcessor = diff --git a/lib/tracing/trace.js b/lib/tracing/trace.js index a449a05..fcf0115 100644 --- a/lib/tracing/trace.js +++ b/lib/tracing/trace.js @@ -58,8 +58,7 @@ function _getParentSpan() { // root span gets request attributes _setAttributes(parent, _getRequestAttributes()) if (HRTIME) parent.startTime = cds.context.http?.req?.__hrnow || _hrnow() - if (ADJUST_ROOT_NAME && parent.attributes[ATTR_URL_PATH]) - parent.name += ' ' + parent.attributes[ATTR_URL_PATH] + if (ADJUST_ROOT_NAME && parent.attributes[ATTR_URL_PATH]) parent.name += ' ' + parent.attributes[ATTR_URL_PATH] } if (!parent?._is_async) cds.context._otelctx.setValue(cds.context._otelKey, parent) } diff --git a/test/bookshop/lib/MySimpleLogRecordProcessor.js b/test/bookshop/lib/MySimpleLogRecordProcessor.js new file mode 100644 index 0000000..f274c97 --- /dev/null +++ b/test/bookshop/lib/MySimpleLogRecordProcessor.js @@ -0,0 +1,9 @@ +const { SimpleLogRecordProcessor } = require('@opentelemetry/sdk-logs') + +class MySimpleLogRecordProcessor extends SimpleLogRecordProcessor { + onEmit(logRecord) { + return super.onEmit(logRecord) + } +} + +module.exports = { MySimpleLogRecordProcessor } diff --git a/test/bookshop/srv/admin-service.cds b/test/bookshop/srv/admin-service.cds index 2cacb2b..f3d2064 100644 --- a/test/bookshop/srv/admin-service.cds +++ b/test/bookshop/srv/admin-service.cds @@ -3,6 +3,7 @@ using { sap.capire.bookshop as my } from '../db/schema'; service AdminService @(requires:'admin') { entity Books as projection on my.Books; entity Authors as projection on my.Authors; + entity Genres as projection on my.Genres; action spawn(); } diff --git a/test/bookshop/srv/admin-service.js b/test/bookshop/srv/admin-service.js index 950caef..ea4a3c6 100644 --- a/test/bookshop/srv/admin-service.js +++ b/test/bookshop/srv/admin-service.js @@ -3,6 +3,10 @@ const cds = require('@sap/cds/lib') module.exports = class AdminService extends cds.ApplicationService { init(){ this.before ('NEW','Books.drafts', genid) + this.before('READ', 'Genres', () => { + cds.log('AdminService').info('Hello, World!') + }) + this.on('spawn', () => { cds.spawn({ after: 3 }, async () => { await SELECT.from('sap.capire.bookshop.Books') diff --git a/test/logging.test.js b/test/logging.test.js new file mode 100644 index 0000000..5392c25 --- /dev/null +++ b/test/logging.test.js @@ -0,0 +1,34 @@ +/* eslint-disable no-console */ + +process.env.cds_log_format = 'json' + +process.env.cds_requires_telemetry_logging_exporter_module = '@opentelemetry/sdk-logs' +process.env.cds_requires_telemetry_logging_exporter_class = 'ConsoleLogRecordExporter' + +// experimental feature of the experimental feature!!! +process.env.cds_requires_telemetry_logging_processor_module = './lib/MySimpleLogRecordProcessor.js' +process.env.cds_requires_telemetry_logging_processor_class = 'MySimpleLogRecordProcessor' + +const cds = require('@sap/cds') +const { expect, GET } = cds.test().in(__dirname + '/bookshop') + +describe('logging', () => { + const admin = { auth: { username: 'alice' } } + + const { dir } = console + beforeEach(() => { + console.dir = jest.fn() + }) + afterAll(() => { + console.dir = dir + }) + + test('it works', async () => { + const { status } = await GET('/odata/v4/admin/Genres', admin) + expect(status).to.equal(200) + const logs = console.dir.mock.calls.map(([log]) => log) + expect(logs.length).to.equal(2) + expect(logs[0]).to.include({ body: 'GET /odata/v4/admin/Genres ' }) //> why the trailing space? + expect(logs[1]).to.include({ body: 'Hello, World!' }) + }) +})