Skip to content
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

feat(winston-transport): Serialize nested objects passed as additional attributes #2116

Closed
wants to merge 2 commits into from
+23 −4
Closed

feat(winston-transport): Serialize nested objects passed as additional attributes #2116

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
baad9ad
Serialize nested objects properly.
JacksonWeber Apr 18, 2024
c087a2e
Fix lint by including valid instances of any.
JacksonWeber Apr 19, 2024
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
1 change: 1 addition & 0 deletions packages/winston-transport/src/OpenTelemetryTransportV3.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ export class OpenTelemetryTransportV3 extends TransportStream {
this._logger = logs.getLogger('@opentelemetry/winston-transport', VERSION);
}

// eslint-disable-next-line @typescript-eslint/no-explicit-any
public override log(info: any, next: () => void) {
try {
emitLogRecord(info, this._logger);
Expand Down
7 changes: 3 additions & 4 deletions packages/winston-transport/src/utils.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,15 +60,14 @@ function getSeverityNumber(level: string): SeverityNumber | undefined {
}

export function emitLogRecord(
// eslint-disable-next-line @typescript-eslint/no-explicit-any
record: Record<string, any>,
logger: Logger
): void {
const { message, level, ...splat } = record;
const attributes: LogAttributes = {};
for (const key in splat) {
if (Object.prototype.hasOwnProperty.call(splat, key)) {
attributes[key] = splat[key];
}
for (const [key, value] of Object.entries(splat)) {
attributes[key] = typeof value === 'object' ? JSON.stringify(value) : value;
Copy link
Member

Choose a reason for hiding this comment

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

LogAttributes can be nested, right? Could it be that it's just not printed properly by the Log SDK's console exporter (it's depth is 3 - https://github.com/open-telemetry/opentelemetry-js/blob/31eb60dc99dc066cf2085864f2727eb29ee76e91/experimental/packages/sdk-logs/src/export/ConsoleLogRecordExporter.ts#L76) 🤔

Copy link
Contributor Author

@JacksonWeber JacksonWeber Apr 19, 2024 •
edited
Loading

Choose a reason for hiding this comment

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

For my testing I've been using the BatchLogRecordProcessor, and when these logs get to the BatchLogRecordProcessorBase's _export method, the log records still show that nested object attributes have not been serialized and so customers receive an unserialized object on the Azure side.
I'm happy to work on this serialization for nested objects at the LogRecordProcessor level if you believe that's a more appropriate place for it. Original ask for this work was based on customer's inability to receive properly serialized objects from Winston which is why I targeted this transport specifically.

Copy link
Contributor

Choose a reason for hiding this comment

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

I concur with @pichlermarc. I think serialization is working property for nested objects that are logged through the winston-transport.

I tested with this "use-winston.js" script that logs a nest object after setting up new BatchLogRecordProcessor(new OTLPLogExporter()) for log record processing:

/*
cd .../opentelemetry-js-contrib
npm ci --ignore-scripts
npm run compile
cd plugins/node/opentelemetry-instrumentation-winston
npm install --no-save @opentelemetry/exporter-logs-otlp-proto
node use-winston.js
*/

const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node');
const logsAPI = require('@opentelemetry/api-logs');
const {
    LoggerProvider,
    SimpleLogRecordProcessor,
    ConsoleLogRecordExporter,
} = require('@opentelemetry/sdk-logs');
const { WinstonInstrumentation } = require('@opentelemetry/instrumentation-winston');
const { registerInstrumentations } = require('@opentelemetry/instrumentation');
const {BatchLogRecordProcessor} = require('@opentelemetry/sdk-logs');
const {OTLPLogExporter} = require('@opentelemetry/exporter-logs-otlp-proto');

const tracerProvider = new NodeTracerProvider();
tracerProvider.register();
const loggerProvider = new LoggerProvider();
loggerProvider.addLogRecordProcessor(
    // new SimpleLogRecordProcessor(new ConsoleLogRecordExporter())
    new BatchLogRecordProcessor(new OTLPLogExporter())
);
logsAPI.logs.setGlobalLoggerProvider(loggerProvider);
registerInstrumentations({
    instrumentations: [
        new WinstonInstrumentation({
            // See below for Winston instrumentation options.
        }),
    ],
});

const winston = require('winston');

const log = winston.createLogger({
  transports: [new winston.transports.Console()],
})
log.info('hi', {foo: 'bar', deep: {nested: {obj: {spam: 'eggs'}}}});

loggerProvider.forceFlush() // flush before exiting

I sent that via OTLP (admittedly to a personal mock collector implemented in Node.js) and the protobuf request was this:

ExportLogsServiceRequest {
  resourceLogs: [
    ResourceLogs {
      scopeLogs: [
        ScopeLogs {
          logRecords: [
            LogRecord {
              attributes: [
                KeyValue { key: 'foo', value: AnyValue { stringValue: 'bar' } },
                KeyValue {
                  key: 'deep',
                  value: AnyValue {
                    kvlistValue: KeyValueList {
                      values: [
                        KeyValue {
                          key: 'nested',
                          value: AnyValue {
                            kvlistValue: KeyValueList {
                              values: [
                                KeyValue {
                                  key: 'obj',
                                  value: AnyValue {
                                    kvlistValue: KeyValueList {
                                      values: [ KeyValue { key: 'spam', value: AnyValue { stringValue: 'eggs' } } ]
                                    }
                                  }
                                }
                              ]
                            }
                          }
                        }
                      ]
                    }
                  }
                }
              ],
              timeUnixNano: Long { low: -750941568, high: 399051707, unsigned: true },
              severityNumber: 9,
              severityText: 'info',
              body: AnyValue { stringValue: 'hi' },
              droppedAttributesCount: 0,
              observedTimeUnixNano: Long { low: -750941568, high: 399051707, unsigned: true }
            }
          ],
          scope: InstrumentationScope { attributes: [], name: '@opentelemetry/winston-transport', version: '0.2.0' }
        }
      ],
      resource: Resource {
        attributes: [
          KeyValue { key: 'service.name', value: AnyValue { stringValue: 'unknown_service:node' } },
          KeyValue { key: 'telemetry.sdk.language', value: AnyValue { stringValue: 'nodejs' } },
          KeyValue { key: 'telemetry.sdk.name', value: AnyValue { stringValue: 'opentelemetry' } },
          KeyValue { key: 'telemetry.sdk.version', value: AnyValue { stringValue: '1.23.0' } }
        ],
        droppedAttributesCount: 0
      }
    }
  ]
}

I believe that is correct.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Did some further investigation on my part and found that the serialization issue seems to be related to passing/displaying the attribute fields when they're sent to Azure. Making an update on the Azure Monitor side to fix this issue. Thank you both for your review!

}
const logRecord: LogRecord = {
severityNumber: getSeverityNumber(level),
Expand Down
19 changes: 19 additions & 0 deletions packages/winston-transport/test/openTelemetryTransport.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,25 @@ describe('OpenTelemetryTransportV3', () => {
);
});

it('emit LogRecord with nested objects', () => {
const errorMsg = 'test error';
const transport = new OpenTelemetryTransportV3();
const errorEvent = {
message: errorMsg,
meta: { error: 'test error' },
level: 'error',
};
const parameters = Object.assign({ message: kMessage }, errorEvent);
transport.log(parameters, () => {});
const logRecords = memoryLogExporter.getFinishedLogRecords();
assert.strictEqual(logRecords.length, 1);
assert.strictEqual(logRecords[0].body, errorMsg);
assert.strictEqual(
logRecords[0].attributes['meta'],
JSON.stringify(errorEvent.meta)
);
});

describe('emit logRecord severity', () => {
it('npm levels', () => {
const callback = () => {};
Expand Down
Loading