launchdarkly / ld-relay

LaunchDarkly Relay Proxy
Other
112 stars 80 forks source link

More verbose logging #51

Closed lukasmrtvy closed 5 years ago

lukasmrtvy commented 5 years ago

Is possible to be more verbose in logging of ldrelay? I would like to see requests from clients. There should be possibility that these requests (or responses) are malformed in my case. Thanks

Currently running in:

HttpEventPublisher: 2018/12/18 10:11:24 Unexpected error while sending events: Post https://events.launchdarkly.com/bulk: EOF
HttpEventPublisher: 2018/12/18 10:11:24 Will retry posting events after 1 second
[LaunchDarkly Relay (SdkKey ending with dfcde)] 2018/12/18 10:16:05 ERROR: Error encountered processing stream: unexpected EOF
[LaunchDarkly Relay (SdkKey ending with dfcde)] 2018/12/18 10:16:05 Reconnecting in 3.0000 secs
HttpEventPublisher: 2018/12/18 10:26:24 Unexpected error while sending events: Post https://events.launchdarkly.com/bulk: EOF

And is not possible to debug what is wrong, specially if I have NO access to client`s (java) logs.

eli-darkly commented 5 years ago

If you mean "Is it possible to tell the current ld-relay to do more logging", the answer is no, unfortunately right now the logging it is doing is the maximum level it knows how to do. It uses the same logging mechanism as the Go SDK, which is less sophisticated than other platforms and does not have any notion of log levels. We are definitely considering changing this.

As for the specific problem you're having: what kind of "requests from clients" are you thinking of? The messages you copied above are not related to requests from clients; they look like network connectivity failures. The "HttpEventPublisher" lines are saying that when it tried to forward some analytics events to LaunchDarkly, the connection was dropped. The "Error encountered processing stream" line is the same thing, but for the streaming connection to LaunchDarkly for delivery of feature flags. Neither of those would be affected by anything the clients are doing.

eli-darkly commented 5 years ago

Actually, what I said in my first paragraph wasn't quite accurate. The internal implementation of logging in ld-relay does support log levels— it's just that 1. we're not really using them (that is, we never log anything at Debug level) and 2. there isn't a way to set the minimum level, unless you're embedding the ld-relay code in another application. It shouldn't be too hard to change both of those things.

I'm still not sure exactly what kind of log output you have in mind though, so it'd be helpful if you could provide some examples.

lukasmrtvy commented 5 years ago

Log from ldrelay:

HttpEventPublisher: 2019/02/04 13:58:11 Unexpected error while sending events: Post https://events.launchdarkly.com/bulk: EOF
HttpEventPublisher: 2019/02/04 13:58:11 Will retry posting events after 1 second

I dont know, where is a problem... At least some info message like "Resend was OK" , or something else should calm me down.

Log from java-client:

2019-02-04T13:48:55.045Z INFO c.l.c.LDClient [traceId:3129443ff0d74126,parentId:3129443ff0d74126,spanId:88d747e1aed49cba] - Unknown feature flag "display-bill-split"; returning default value 

Is this related? 10 minutes difference...

Anyway, its really hard to debug ldrelay, even java-client.

Like Unknown feature flag "display-bill-split"; returning default value what does it mean?

TCP is unavailible? Bad response code from HTTP? SSL cerificate is invalid? I dont know, where is a problem...

eli-darkly commented 5 years ago

Well, I can tell you those two errors are not related. The "sending events" one means that the TCP connection was dropped for some reason (probably a brief network interruption) while it was trying to send analytics events to LaunchDarkly. If it had been a bad HTTP status code, or an invalid SSL certificate, there would've been an error message specifically describing those things. Unfortunately the way it's currently written does not make it clear whether the second attempt succeeded or failed, but unless you're getting errors like this all the time, it probably succeeded.

The second error means that your application tried to evaluate the feature flag "display-bill-split" and the SDK does not know about any flag with that key. Usually this just means that either the flag key isn't what you think it is, or you're using a different environment that doesn't have that flag. If you're sure that the flag does exist, then that's a mystery and I would encourage you to raise a support ticket (since we're no longer talking about ld-relay logging at this point).

lukasmrtvy commented 5 years ago

@eli-darkly https://github.com/launchdarkly/ld-relay/issues/56

eli-darkly commented 5 years ago

As of the 5.7.0 release, there is now support for verbose (debug) logging, as described in the README.

benzhonghai008 commented 3 years ago

Sorry, does this logs means something error or it's just log ? I just deployed ld-relay service with no client cnnected with the ld-relay service, but the logs is keeping refreshing.... 2021/07/27 05:59:20.393416 WARN: [env: ...97f6] (usage metrics) Unexpected error while sending events: Post "https://events.launchdarkly.com/bulk": EOF 2021/07/27 05:59:20.393434 WARN: [env: ...97f6] (usage metrics) Will retry posting events after 1.000000 second 2021/07/27 06:28:22.855190 WARN: [env: ...b768] Unexpected error while sending events: Post "https://events.launchdarkly.com/diagnostic": context deadline exceeded (Client.Timeout exceeded while awaiting headers) 2021/07/27 06:28:22.855215 WARN: [env: ...b768] Will retry posting events after 1.000000 second

eli-darkly commented 3 years ago

@benzhonghai008 There's not enough information to diagnose what's going on there just from what you've written, and an old GitHub issue isn't a good place to follow up on it. Please use support.launchdarkly.com to submit a support request.

All I can say without knowing more about your environment and configuration is:

  1. Even if no clients are connected, Relay may need to send some analytics data to LaunchDarkly, and that is what that seems to be failing.
  2. I don't know why it is failing, it could be a transient outage but if it persists I would suspect some network condition is blocking the request.
  3. If you don't want Relay to be able to send these analytics to LaunchDarkly, set disableInternalUsageMetrics as described here.