-
Notifications
You must be signed in to change notification settings - Fork 324
Log injection issues in JDBC only once + promote to WARN #10214
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -9,6 +9,7 @@ | |
| import datadog.trace.api.DDSpanId; | ||
| import datadog.trace.api.DDTraceId; | ||
| import datadog.trace.api.naming.SpanNaming; | ||
| import datadog.trace.api.telemetry.LogCollector; | ||
| import datadog.trace.bootstrap.ContextStore; | ||
| import datadog.trace.bootstrap.instrumentation.api.AgentScope; | ||
| import datadog.trace.bootstrap.instrumentation.api.AgentSpan; | ||
|
|
@@ -68,6 +69,7 @@ public class JDBCDecorator extends DatabaseClientDecorator<DBInfo> { | |
| Config.get().isDbMetadataFetchingOnQueryEnabled(); | ||
|
|
||
| private volatile boolean warnedAboutDBMPropagationMode = false; // to log a warning only once | ||
| private volatile boolean loggedInjectionError = false; | ||
|
|
||
| public static void logMissingQueryInfo(Statement statement) throws SQLException { | ||
| if (log.isDebugEnabled()) { | ||
|
|
@@ -298,12 +300,7 @@ public void setAction(AgentSpan span, Connection connection) { | |
|
|
||
| span.setTag("_dd.dbm_trace_injected", true); | ||
| } catch (Throwable e) { | ||
| log.debug( | ||
| "Failed to set extra DBM data in application_name for trace {}. " | ||
| + "To disable this behavior, set trace_prepared_statements to 'false'. " | ||
| + "See https://docs.datadoghq.com/database_monitoring/connect_dbm_and_apm/ for more info. {}", | ||
| span.getTraceId().toHexString(), | ||
| e); | ||
| logInjectionErrorOnce("action", e); | ||
| DECORATE.onError(span, e); | ||
| } | ||
| } | ||
|
|
@@ -358,12 +355,7 @@ public long setContextInfo(Connection connection, DBInfo dbInfo) { | |
| throw e; | ||
| } | ||
| } catch (Exception e) { | ||
| log.debug( | ||
| "Failed to set extra DBM data in context info for trace {}. " | ||
| + "To disable this behavior, set DBM_PROPAGATION_MODE to 'service' mode. " | ||
| + "See https://docs.datadoghq.com/database_monitoring/connect_dbm_and_apm/ for more info.{}", | ||
| instrumentationSpan.getTraceId().toHexString(), | ||
| e); | ||
| logInjectionErrorOnce("context_info", e); | ||
| DECORATE.onError(instrumentationSpan, e); | ||
| } finally { | ||
| instrumentationSpan.finish(); | ||
|
|
@@ -393,14 +385,7 @@ public void setApplicationName(AgentSpan span, Connection connection) { | |
|
|
||
| connection.setClientInfo("ApplicationName", traceContext); | ||
| } catch (Throwable e) { | ||
| if (log.isDebugEnabled()) { | ||
| log.debug( | ||
| "Failed to set extra DBM data in application_name for trace {}. " | ||
| + "To disable this behavior, set trace_prepared_statements to 'false'. " | ||
| + "See https://docs.datadoghq.com/database_monitoring/connect_dbm_and_apm/ for more info.{}", | ||
| span.getTraceId().toHexString(), | ||
| e); | ||
| } | ||
| logInjectionErrorOnce("application_name", e); | ||
| DECORATE.onError(span, e); | ||
| } finally { | ||
| span.setTag(DBM_TRACE_INJECTED, true); | ||
|
|
@@ -436,4 +421,18 @@ public boolean shouldInjectSQLComment() { | |
| return Config.get().getDbmPropagationMode().equals(DBM_PROPAGATION_MODE_FULL) | ||
| || Config.get().getDbmPropagationMode().equals(DBM_PROPAGATION_MODE_STATIC); | ||
| } | ||
|
|
||
| private void logInjectionErrorOnce(String vessel, Throwable t) { | ||
| if (!loggedInjectionError) { | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. A volatile read/write does not make this operation atomic, so concurrent calls may result in the log being emitted more than once. That behavior is acceptable for what we’re trying to achieve.
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. yes, that's what I thought as well, plus we use the same mechanism in several other places in the codebase |
||
| loggedInjectionError = true; | ||
| log.warn( | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. you can also use the maker
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. ah I didn't know about this, I'll add it thanks |
||
| LogCollector.EXCLUDE_TELEMETRY, // nothing we can do on our side about this | ||
| "Failed to set extra DBM data in {}. " | ||
| + "To disable this behavior, set trace_prepared_statements to 'false'. " | ||
| + "See https://docs.datadoghq.com/database_monitoring/connect_dbm_and_apm/ for more info. " | ||
| + "Will not log again for this kind of error.\n{}", | ||
| vessel, | ||
| t); | ||
| } | ||
| } | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
using a single boolean for all 3 places where we log, because they are all for a different DB type (oracle, mssql & postgres), so I think the chances that the same app would use several DB types and injection would fail for each is super super low.