Unable to see trace id or transaction info in logs

Elastic Stack Logstash
1

I currently have a NodeJS server passing logs to a Logstash server with a TCP tunnel using a Winston transport. Logs make it through all the way to my Elastic Cloud hosted Elasticsearch and pretty much everything looks good except the logs are missing the trace id and transaction information. When I use a stdout transport with Winston to check the logs I can see the trace and transaction info. Here's an example log:

{"@timestamp":"2023-02-23T21:41:51.479Z","log.level":"info","message":"END: [POST] /api/functions/example-endpoint","ecs":{"version":"1.6.0"},"event":{"dataset":"render-server.log"},"trace":{"id":"35f2bd0ade620fe6613938094020834f"},"transaction":{"id":"074126be6d79359d"},"service":{"name":"render-server"},"path":"/api/functions/example-endpoint"}

I am using the elastic-apm-node package to run APM on the node server and decorate the logs with the transaction data. I then use this Winston Logstash package to transport the data to Logstash. In the Logstash logs, I also don't see the trace id or transaction info. Example Logstash log:

Feb 23 05:09:57 PM  {
Feb 23 05:09:57 PM           "event" => {
Feb 23 05:09:57 PM          "original" => "{\"path\":\"/api/functions/example-endpoint\",\"level\":\"info\",\"message\":\"END: [POST] /api/functions/example-endpoint\"}"
Feb 23 05:09:57 PM      },
Feb 23 05:09:57 PM            "path" => "/api/functions/example-endpoint",
Feb 23 05:09:57 PM      "@timestamp" => 2023-02-23T22:09:57.455923359Z,
Feb 23 05:09:57 PM           "level" => "info",
Feb 23 05:09:57 PM         "message" => "END: [POST] /api/functions/example-endpoint",
Feb 23 05:09:57 PM        "@version" => "1"
Feb 23 05:09:57 PM  }

Any thoughts on what I can test? What might be the issue here?

2

What does your logstash configuration looks like?

3 
input {
    tcp {
        port => "10000"
    }
}

filter {
    json {
        source => "message"
    }
}

output {
    elasticsearch {
        cloud_id => "${CLOUD_ID}"
        cloud_auth => "${CLOUD_AUTH}"
        data_stream => "true"
    }
}
4

Where is this message from? Is this the input for Logstash?

5

Correct. That should be the input for Logstash. I mean I guess the Winston transport that is sending it via TCP could be mutating it but unlikely.

6

The event that arrives at logstash does not contain the

"ecs":{"version":"1.6.0"},"event":{"dataset":"render-server.log"},"trace":{"id":"35f2bd0ade620fe6613938094020834f"},"transaction":{"id":"074126be6d79359d"},"service":{"name":"render-server"},

that you expect.

7

So it seems like you were right Badger. Unfortunately, it looks like that Winston transport package was doing some sort of mutation to the object being sent over and removing the transaction information. I swapped it out for the Pino logger and socket transport and everything is working now. Thanks for your time!

2 Likes
8

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.