Skip to content

Logging, Tracing and Context Propagation issue #830

Open
@marioskonstantinou12

Description

@marioskonstantinou12

Hello,

I'm trying to get logging to work with context propagation etc. but seems i'm missing something:

I've created a new ExecutionService so i can propagate context as:

  val executor: ScheduledExecutorService = java.util.concurrent.Executors.newScheduledThreadPool(10)
  val instrumented: ExecutorService =
    ExecutorInstrumentation.instrument(executor, "sample-executor", new Settings(true, true))
  implicit val ec: ExecutionContext = ExecutionContext.fromExecutorService(instrumented)

and ec is used in the rest of the app (i even tried using global execution context but with the same result). My logback config is defined as

<configuration>
    <conversionRule conversionWord="traceID" converterClass="kamon.instrumentation.logback.tools.TraceIDConverter" />
    <conversionRule conversionWord="spanID" converterClass="kamon.instrumentation.logback.tools.SpanIDConverter" />

    <statusListener class="ch.qos.logback.core.status.NopStatusListener"/>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%date [%level][%traceID][%spanID] from %logger in %thread - %message%n%xException</pattern>
        </encoder>
    </appender>

    <appender name="ASYNCSTDOUT" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="STDOUT"/>
    </appender>

    <root level="INFO">
        <appender-ref ref="ASYNCSTDOUT"/>
    </root>
</configuration>

When starting up the application, i understand that spanId and traceId should be undefined as in the first log below. When i'm using logger within the app (services, repos etc.) i can see that traceId and spanId are printed as expected (Extending my own trait in services, repos etc.)

import com.typesafe.scalalogging.StrictLogging

trait Loggie extends StrictLogging {}

trait MyService extends Loggie <---
trait MyRepo extends Loggie <---

When doing a full request/response cycle, all other services apart from my own implementations traceId and spanId are undefined which is really strange (logs below)

[info] 2020-08-12 08:13:53,713 [INFO][undefined][undefined] from org.http4s.blaze.channel.nio1.NIO1SocketServerGroup in blaze-selector-1 - Accepted connection from /127.0.0.1:63655
[info] 2020-08-12 08:13:53,765 [INFO][9cff93678beee59c][cc9d8d5e871c9ebc] from com.service.MyService$ in pool-5-thread-1 - MyService.findThis 25ad164b-eac6-4fa0-8dbb-257a30d34a96
[info] 2020-08-12 08:13:53,765 [INFO][9cff93678beee59c][cc9d8d5e871c9ebc] from com.repo.MyRepo$$anon$1 in pool-5-thread-1 - MyRepo.findThis 25ad164b-eac6-4fa0-8dbb-257a30d34a96
[info] 2020-08-12 08:13:54,169 [INFO][undefined][undefined] from org.http4s.server.middleware.Logger in pool-5-thread-8 - HTTP/1.1 GET /v1/thispath/myservice/25ad164b-eac6-4fa0-8dbb-257a30d34a96 Headers(Content-Type: application/json, Host: 0.0.0.0:8080, Accept-Encoding: gzip, deflate, br, Connection: keep-alive, Content-Length: 44) body=""
[info] 2020-08-12 08:13:54,187 [INFO][undefined][undefined] from org.http4s.server.middleware.Logger in pool-5-thread-5 - HTTP/1.1 200 OK Headers(Content-Type: application/json, Content-Length: 22, trace-id: 9cff93678beee59c, span-id: cc9d8d5e871c9ebc) body="{"code":200,"data":[]}"
[info] 2020-08-12 08:13:57,069 [WARN][undefined][undefined] from kamon.jaeger.JaegerSender in Jaeger Reporter - Reporting spans to jaeger failed. 3 spans discarded.

Versions:
kanela-agent: 1.0.6 (added classLoaderLayeringStrategy := ClassLoaderLayeringStrategy.Flat as well)
sbt: 1.3.13
scala: 2.13.3
kamon-core: 2.1.4
kamon-http4s: 2.0.3
kamon-jaeger: 2.1.4
kamon-logback: 2.1.4
kamon-executors: 2.1.4

Any help will be appreciated

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions