Report internal exceptions with telemetry by DDJavierSantos · Pull Request #4521 · DataDog/dd-trace-java

DDJavierSantos · 2023-01-10T19:42:35Z

What Does This Do

Implements exception reporting using the Telemetry API. Implements a marker that can be used to send debug lines to the telemetry API if the marker is used as a parameter in the debug call.

Motivation

To collect reports about exceptions in client's installations. This will make support cycles easier and ensure we know about potentially silent issues in libraries.

Additional Notes

New configuration:

DD_TELEMETRY_LOG_COLLECTION_ENABLED (environment variable) or dd.instrumentation.telemetry.log-collection.enabled (system property): This boolean flag (true, false) enables log collection by telemetry for log lines with level ERROR and WARN. It is disabled by default.
DD_TELEMETRY_DEBUG_ENABLED (environment variable) or dd.instrumentation.telemetry.debug (system property): This boolean flag (true, false) enables log collection for log lines with level DEBUG. It is disabled by default.

Additional conditions for log lines to be sent to telemetry:

The line contains an exception, e.g. logger.error("there was an exception", throwable).
The line doesn't contain an exception but the Logger was called with the marker DDLogger.SEND_TELEMETRY, e.g. logger.error(DDLogger.SEND_TELEMETRY, "message sent to telemetry").

Log lines are de-duplicated during the telemetry heartbeat interval (default: 1 minute).
There is a limit in the number of log lines collected during a telemetry heartbeat interval, currently set to 10000 so we stay bounded. If we hit the limit, any extra lines are dropped silently.

mcculls · 2023-01-18T11:57:03Z

FYI, if you have a new bootstrap class which is referenced during startup and you see this kind of error from the Graal smoke tests:

No instances of SomeClass are allowed in the image heap as this class should be initialized at image runtime

then there are 2 options - one is to use !Platform.isNativeImageBuilder() to guard code we never expect to run during native image. That is useful to eliminate large chunks of code which are inapplicable to native-image, but won't work if the class is still being touched from startup code (in other words it depends how the class is being used).

The other option is to add it to the list of build-time classes in https://github.com/DataDog/dd-trace-java/blob/master/dd-java-agent/instrumentation/graal/native-image/src/main/java/datadog/trace/instrumentation/graal/nativeimage/NativeImageGeneratorRunnerInstrumentation.java#L64 - ideally we want to list as few classes as possible there (especially since you then need to list any classes they depend on, etc...) so this should be a last resort. Excluding the feature via !Platform.isNativeImageBuilder() is preferred.

In this case it's the new reference to LogCollector from DDLogger via the new sendToTelemetry method that is pulling the class in - it might be enough to check !Platform.isNativeImageBuilder() early enough so the native-image builder doesn't see LogCollector.

…rting

dougqh · 2023-01-27T18:22:36Z

I've only skimmed this, but it seems like a reasonable minimally invasive approach.

But as pointed out in conversation, I think there is challenge with cases that use guarded logging today.
By which I mean...
if ( logger.isDebugEnabled() ) { logger.debug("myMessage {} {}", foo.getX(), foo.doExpensiveThing()); }

I'll admit I've never been a huge fan of that idiom because it seems like we shouldn't be doing "doExpensiveThing".

My far more invasive way of solving this is to introduce a helper or event object that does the expensive work.

logger.debug("myMessage {} {}", foo, (foo) -> return new Object[] { foo.getX(), foo.doExpensiveThing() });

The idea here is ti use a non-capturing lambda that is only called when needed. With the hope that calling debug all the time is okay because the passing of format, foo, and the lambda are all by reference and cheap,

Although, that's just my idea for something that kind of fits into standard logging. I have a crazy notion of having some helper event class that handles the details.

The end call would be something like...
logger.on(MY_EVENT, foo)

But I feel creating those Event objects likely requires too much ceremony.

…Code from payload, log confirmation when Log Collection is enabled

manuel-alvarez-alvarez · 2023-02-01T14:38:28Z

+    return debugEnabled;
+  }
+
+  public synchronized void addLogEntry(


Using synchronized for this method might be too drastic, have you give it a thought about using thread safe data structures like:

int overflowedEntryCount ➡️ AtomicInteger overflowedEntryCount

LinkedHashSet<TelemetryLogEntry> logEntries ➡️ Set<TelemetryLogEntry> logEntries = ConcurrentHashMap.newKeySet();

manuel-alvarez-alvarez · 2023-02-01T14:41:52Z

+    if (null == msg && null == format) {
+      return;
+    }
+    if (logEntries.size() >= MAX_ENTRIES) {


It worries me a bit that there is no priority between log entries, I'll prefer not losing ERROR ones in a very noisy scenario.

manuel-alvarez-alvarez · 2023-02-01T14:48:14Z


  private final boolean iastDeduplicationEnabled;

+  private final boolean telemetryEnabled;


Why the extra field if already present at InstrumenterConfig?

manuel-alvarez-alvarez · 2023-02-01T14:58:36Z

+import org.slf4j.helpers.MessageFormatter;
+
+public class LogCollector {
+  public static final int MAX_ENTRIES = 10000;


Looks weird to me having a collector with room for 10.000 entries that will be capped by the telemetry service which only has room for 1.024 (private final BlockingQueue<TelemetryLogEntry> logEntries = new LinkedBlockingQueue<>(1024);)

iunanua · 2023-02-09T11:23:11Z

+      if (null != t || marker == LogCollector.SEND_TELEMETRY) {
+        if (level == LogLevel.WARN
+            || level == LogLevel.ERROR
+            || (level == LogLevel.DEBUG && LogCollector.get().isDebugEnabled())) {


What about LogLevel.INFO? in Node we are treating them as DEBUG for telemetry purposes

jpbempel · 2023-02-13T17:48:48Z

+    StringBuilder stackTrace = new StringBuilder();
+    stackTrace.append(t.getClass().getCanonicalName());
+
+    String firstStackElementClassName = t.getStackTrace()[0].getClassName();


blocker: it's possible that the stacktrace returned is empty so you should guard aginst this

jpbempel · 2023-02-13T17:49:25Z

+    if (null != msg) {
+      log.setMessage(msg);
+    } else {
+      if (null != format) {


nit: yoda condition, no reason in Java to reversed the condition against null

jpbempel · 2023-02-13T17:50:33Z

+  }
+
+  boolean isDataDogCode(Throwable t) {
+    String firstStackElementClassName = t.getStackTrace()[0].getClassName();


same as above

jpbempel · 2023-02-13T17:59:08Z

+  public static class Holder {
+    public static final LogCollector INSTANCE = new LogCollector();
+  }


nit: I think the Holder pattern here is useless as creating an instance of LogCollector is not expensive

jpbempel · 2023-02-13T17:59:57Z

+  private static int overflowedEntryCount = 0;
+  private static boolean enabled = false;
+  public static boolean debugEnabled = false;
+  private static LinkedHashSet<TelemetryLogEntry> logEntries = new LinkedHashSet<>();
+  private static String[] packageList = {"datadog.", "com.datadog.", "java.", "javax."};


why all the fields are static? as all the methods are instance method and we are creating a singleton?

jpbempel · 2023-02-13T18:31:07Z

+      return true;
+    } else {
+      if (this.hasReferences()) {
+        Iterator var2 = this.referenceList.iterator();


use Iterator<Marker> var2 this will avoid casting below

also use the for each:

for (Marker ref : referenceList) { if (ref.contains(other)) { return true; } }

jpbempel · 2023-02-13T18:35:16Z

+public class TelemetryMarker implements Marker {
+  private static final long serialVersionUID = -2849567615646933777L;
+  private final String name;
+  private List<Marker> referenceList = new CopyOnWriteArrayList();


blocker: why using a list for that instead of a HashSet?
order is important?

jpbempel · 2023-02-13T18:45:06Z

  private final Application application;
  private final Host host;
  private final String runtimeId;
+  private static final Config config = Config.get();


sounds useless, get method just returns the singleton instance

jpbempel · 2023-02-13T18:51:16Z


-  private static <T> List<T> drainOrDefault(BlockingQueue<T> srcQueue, List<T> defaultList) {
+  private static <T> List<T> drainOrDefault(
+      BlockingQueue<T> srcQueue, List<T> defaultList, Integer maxItems) {


can we just use the primitive int for maxItems?

jpbempel · 2023-02-13T18:57:47Z

+    if (!this.hasReferences()) {
+      return this.getName();
+    } else {
+      Iterator<Marker> it = this.iterator();


why not referencing directly referenceList and using a for each?

smola · 2023-03-31T09:34:07Z

Let's try to move this forward. Other than the commands that are still not resolved (and should) and the pending rebase:

Drop dd.instrumentation.telemetry.debug and its associated logic. I think the subset we should start with is: either has an exception attached, or it has a SEND_TELEMETRY marker.
dd.instrumentation.telemetry.log-collection.enabled -> dd.telemetry.log-collection.enabled

smola · 2023-10-25T09:29:20Z

Superseded by #6057

smola added comp: telemetry Telemetry tag: do not merge Do not merge changes labels Jan 11, 2023

manuel-alvarez-alvarez added the comp: asm iast Application Security Management (IAST) label Jan 11, 2023

DDJavierSantos changed the title ~~Implementation of Telemetry API Exception reporting~~ Implementation of Telemetry API Exception and log reporting Jan 11, 2023

DDJavierSantos changed the title ~~Implementation of Telemetry API Exception and log reporting~~ Implementation of Telemetry API Exception and Log reporting Jan 11, 2023

DDJavierSantos force-pushed the jsantos/telemetry_error_reporting branch from 7d1c198 to acf6ffb Compare January 12, 2023 11:53

smola changed the title ~~Implementation of Telemetry API Exception and Log reporting~~ Report internal exceptions with telemetry Jan 18, 2023

smola removed the comp: asm iast Application Security Management (IAST) label Jan 18, 2023

DDJavierSantos force-pushed the jsantos/telemetry_error_reporting branch from 3b52aa6 to 15e8ed0 Compare January 19, 2023 11:56

smola requested changes Jan 19, 2023

View reviewed changes

Comment thread telemetry/src/main/java/datadog/telemetry/TelemetrySystem.java Outdated

Comment thread telemetry/src/main/java/datadog/telemetry/api/LogTelemetry.java Outdated

DDJavierSantos requested a review from smola January 19, 2023 17:05

DDJavierSantos marked this pull request as ready for review January 19, 2023 20:17

DDJavierSantos requested a review from a team as a code owner January 19, 2023 20:17

DDJavierSantos requested review from ValentinZakharov, jandro996 and manuel-alvarez-alvarez January 19, 2023 21:10

smola requested changes Jan 20, 2023

View reviewed changes

DDJavierSantos requested a review from smola January 20, 2023 11:45

DDJavierSantos force-pushed the jsantos/telemetry_error_reporting branch from 24ee061 to 23d455e Compare January 24, 2023 11:19

aazurill and others added 2 commits January 25, 2023 17:50

implementation of Telemetry API modification to enable Exception repo…

8d2de86

…rting

remove placeholder substitution so we don't risk leaking PII

3795fe4

DDJavierSantos force-pushed the jsantos/telemetry_error_reporting branch from 23d455e to 3795fe4 Compare January 25, 2023 16:55

DDJavierSantos added 2 commits January 25, 2023 18:26

Test adjusted

b110d7a

changing flag to instrumentation.telemetry.log-collection.enabled

ffc0f53

DDJavierSantos mentioned this pull request Jan 30, 2023

Improved logging using placeholders #4619

Merged

Better location for marker so it can be accessed widely, removed hash…

04536a8

…Code from payload, log confirmation when Log Collection is enabled

manuel-alvarez-alvarez reviewed Feb 1, 2023

View reviewed changes

iunanua reviewed Feb 9, 2023

View reviewed changes

jpbempel requested changes Feb 13, 2023

View reviewed changes

andrewlock mentioned this pull request Feb 17, 2023

Update telemetry-logs implementation DataDog/dd-trace-dotnet#3807

Closed

jandro996 removed their request for review July 7, 2023 10:20

smola closed this Oct 25, 2023

smola deleted the jsantos/telemetry_error_reporting branch October 25, 2023 09:29


		private final boolean iastDeduplicationEnabled;

		private final boolean telemetryEnabled;

Uh oh!

Conversation

DDJavierSantos commented Jan 10, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What Does This Do

Motivation

Additional Notes

Uh oh!

mcculls commented Jan 18, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

dougqh commented Jan 27, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

manuel-alvarez-alvarez Feb 1, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

manuel-alvarez-alvarez Feb 1, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

smola commented Mar 31, 2023

Uh oh!

smola commented Oct 25, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

8 participants

DDJavierSantos commented Jan 10, 2023 •

edited

Loading

mcculls commented Jan 18, 2023 •

edited

Loading

dougqh commented Jan 27, 2023 •

edited

Loading

manuel-alvarez-alvarez Feb 1, 2023 •

edited

Loading

manuel-alvarez-alvarez Feb 1, 2023 •

edited

Loading