Zipkin logs in Slf4j/Lombok

[Tomasz Michnik]

Hi,

io.zipkin.reporter2:zipkin-sender-okhttp3:2.7.13

io.zipkin.reporter2:zipkin-reporter:2.7.13

io.zipkin.finagle2:zipkin-finagle_2.12: 2.0.11

io.zipkin.finagle2:zipkin-finagle-http_2.12:2.0.11

 

When we were trying to use Zipkin, sending spans through http, it turned out that we have no logs regarding Zipkin (on the client side) .

Even extreme situations  as ie. Zipkin server is down, are not mentioned in logs.

We noticed that zipkin-reporter uses java.util.logging whilst we relies on slf4j and logback.

Unfortunately adding jul-to-slf4j (bridge java.util.logging  -> slf4j) to the project does not help a lot.

Probably the catch in zipkin2.reporter.AsyncReporter  suppresses all logs.

// zipkin2.reporter.AsyncReporter

   

     try {

       sender.sendSpans(nextMessage).execute();

     } catch (IOException | RuntimeException | Error t) {

       // In failure case, we increment messages and spans dropped.

       int count = nextMessage.size();

       Call.propagateIfFatal(t);

       metrics.incrementMessagesDropped(t);

       metrics.incrementSpansDropped(count);

       if (logger.isLoggable(FINE)) {

          logger.log(FINE,

             format("Dropped %s spans due to %s(%s)", count, t.getClass().getSimpleName(),

                 t.getMessage() == null ? "" : t.getMessage()), t);

       }

       // Raise in case the sender was closed out-of-band.

       if (t instanceof IllegalStateException) throw (IllegalStateException) t;

     }

   }

Is there a chance to obtain Zipkin logs in sl4j environment? 

In java docs https://www.slf4j.org/api/org/slf4j/bridge/SLF4JBridgeHandler.html I see mapping FINE -> DEBUG. Can you please change this level to SEVERE which maps onto ERROR. 

I think it is more reasonable than forcing users to configure FINE/DEBUG level in order to make errors visible.

Removing condition  if (logger.isLoggable(FINE)) might also help us a bit ,as working with logback we do not have configured java.util.logging levels, the condition is always evaluated to false.

Maybe, it would be  good to consider in the future releases to  replace java.util.logging with widely used standard: sl4j.

Kind Regards,

Tom

[Adrian Cole]

this is not likely to happen as slf4j has multiple versions now etc
and it is a not universal dependency either

You may notice that there is a metrics handler which is the canonical
way to report on availability concerns. you can add your own logging
there if you don't have a metrics system.

> --
>
> ---
> You received this message because you are subscribed to the Google Groups "zipkin-user" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to zipkin-user...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/zipkin-user/57a058c3-48e5-4707-bca7-0537d75e18d8%40googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.

[Tomasz Michnik]

Ok, I understand you want to stick to java.util.logging, but what about removing  if (logger.isLoggable(FINE)) condition and changing FINE to SEVERE?

Tom

> To unsubscribe from this group and stop receiving emails from it, send an email to zipki...@googlegroups.com.

[Adrian Cole]

as this is a core telemetry library we don't log at such a high level,
it could fill up logs at a high rate. The primary mechanism we
advocate for identifying a problem is to watch metrics.

> To unsubscribe from this group and stop receiving emails from it, send an email to zipkin-user...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/zipkin-user/173c5de1-70e3-4c92-a416-ba142dfa93d8%40googlegroups.com.

[Adrian Cole]

in case it wasn't obvious what I meant about making a logging metrics
handler if you don't have a metrics system and really want things at
severe level. It would look like this:

reporter = AsyncReporter.builder(yourSender)
.metrics(new ReporterMetrics() {
@Override public void incrementMessages() {
}

@Override public void incrementMessagesDropped(Throwable cause) {
mylogger.severe("dropped message due to "+ cause.getMessage());
}

@Override public void incrementSpans(int quantity) {
}

@Override public void incrementSpanBytes(int quantity) {
}

@Override public void incrementMessageBytes(int quantity) {
}

@Override public void incrementSpansDropped(int quantity) {
mylogger.severe("dropped "+quantity+" spans");
}

@Override public void updateQueuedSpans(int update) {
}

@Override public void updateQueuedBytes(int update) {
}
})..

[Tomasz Michnik]

Thank you Adrian for your support.

I wonder, why are you afraid of the loads of logs. I was talking about the logging of  exceptional  situations in catch {} clause.

I guess that we are not landing in the catch section too often? 

Do not you think it is better to log errors by default? In some cases when logging level is high, developers might not be aware that their application is not working correctly.

Tom

W dniu czwartek, 18 lipca 2019 09:56:24 UTC+2 użytkownik Adrian Cole napisał:

in case it wasn't obvious what I meant about making a logging metrics
handler if you don't have a metrics system and really want things at
severe level. It would look like this:

reporter = AsyncReporter.builder(yourSender)
    .metrics(new ReporterMetrics() {
      @Override public void incrementMessages() {
      }

      @Override public void incrementMessagesDropped(Throwable cause) {
        mylogger.severe("dropped message due to "+ cause.getMessage());
      }

      @Override public void incrementSpans(int quantity) {
      }

      @Override public void incrementSpanBytes(int quantity) {
      }

      @Override public void incrementMessageBytes(int quantity) {
      }

      @Override public void incrementSpansDropped(int quantity) {
        mylogger.severe("dropped "+quantity+" spans");
      }

      @Override public void updateQueuedSpans(int update) {
      }

      @Override public void updateQueuedBytes(int update) {
      }
    })..

[Adrian Cole]

you are the only person requesting this change and repeatedly asking the same thing isnt likely to change the result. you have options including the ones I mention to take responsibility in your own hands if you dont like the rationale given. you can also use something that properly configures jul like log4j2. I am sorry you dont agree but myself and others have considerations besides you personally and every one of our libraries handles request scoped logging at fine level not just the one you noticed.

To unsubscribe from this group and stop receiving emails from it, send an email to zipkin-user...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/zipkin-user/fb23704d-3065-43e9-b1d1-04177fec098a%40googlegroups.com.

[Tomasz Michnik]

Hi,

I was just curious. I am not trying to change your mind. 

We wanted to go with your solution regarding custom  implementation of ReporterMetrics but we came across another problem.

On the  client side we use :

• zipkin2.finagle.kafka.KafkaZipkinTracer
• zipkin2.finagle.http.HttpZipkinTracer

Unfortunately, only the base class  zipkin2.finagle.ZipkinTracer contains constructors accepting AsyncReporter and none of them is public.

Even  extending ZipkinTracer to create a custom implementation of HttpZipkinTracer is problematic as zipkin2.finagle.http.HttpSender which need to be passed has a default (package) scope.

Any ideas?

[Adrian Cole]

I think you raised the issue about configuration in another thread and there is a pull request pending tests to provide the capability here https://github.com/openzipkin/zipkin-finagle/pull/69

I will rope off time tomorrow morning to write unit tests for this and the other change I wrote for you. then we can cut a release.

cheers,

-A

To unsubscribe from this group and stop receiving emails from it, send an email to zipkin-user...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/zipkin-user/32bc6649-9e34-47ad-8e9f-c86eac6c23fd%40googlegroups.com.

[Tomasz Michnik]

Great!! That will be helpful. 

I remember that we were talking about Kafka client configuration then. 

I need to analyze your PR, however there still might be a problem with a scope of  zipkin2.finagle.http.HttpSender (package).

KafkaTracer is a bit different story because KafkaSender is public so I can built it's instance.

 

[Adrian Cole]

PS I opened this issue with options.. not sure if "any request" would have triggered your concern, or only certain ones.

https://github.com/openzipkin/zipkin-reporter-java/issues/154

> > To unsubscribe from this group and stop receiving emails from it, send an email to zipkin-user+unsubscribe@googlegroups.com.