From commits-return-2130-archive-asf-public=cust-asf.ponee.io@zipkin.apache.org Tue Jun 18 00:13:50 2019 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [207.244.88.153]) by mx-eu-01.ponee.io (Postfix) with SMTP id A859E18062B for ; Tue, 18 Jun 2019 02:13:49 +0200 (CEST) Received: (qmail 22728 invoked by uid 500); 18 Jun 2019 00:13:49 -0000 Mailing-List: contact commits-help@zipkin.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@zipkin.apache.org Delivered-To: mailing list commits@zipkin.apache.org Received: (qmail 22718 invoked by uid 99); 18 Jun 2019 00:13:49 -0000 Received: from ec2-52-202-80-70.compute-1.amazonaws.com (HELO gitbox.apache.org) (52.202.80.70) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 18 Jun 2019 00:13:48 +0000 Received: by gitbox.apache.org (ASF Mail Server at gitbox.apache.org, from userid 33) id 882BC87AD7; Tue, 18 Jun 2019 00:13:48 +0000 (UTC) Date: Tue, 18 Jun 2019 00:13:48 +0000 To: "commits@zipkin.apache.org" Subject: [incubator-zipkin-brave] branch master updated: feat: use p6spy's log filtering settings when tracing MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit Message-ID: <156081682846.4709.8777882609855134925@gitbox.apache.org> From: adriancole@apache.org X-Git-Host: gitbox.apache.org X-Git-Repo: incubator-zipkin-brave X-Git-Refname: refs/heads/master X-Git-Reftype: branch X-Git-Oldrev: df94fd237e2f3958b794957728d7fc2d7828dea5 X-Git-Newrev: d210f0354bc0dc1a43b08246078403bd95c9d78d X-Git-Rev: d210f0354bc0dc1a43b08246078403bd95c9d78d X-Git-NotificationType: ref_changed_plus_diff X-Git-Multimail-Version: 1.5.dev Auto-Submitted: auto-generated This is an automated email from the ASF dual-hosted git repository. adriancole pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/incubator-zipkin-brave.git The following commit(s) were added to refs/heads/master by this push: new d210f03 feat: use p6spy's log filtering settings when tracing d210f03 is described below commit d210f0354bc0dc1a43b08246078403bd95c9d78d Author: high-stakes AuthorDate: Sun Apr 21 17:52:22 2019 +0200 feat: use p6spy's log filtering settings when tracing p6spy provides sql query filtering options which were not used during span creation, added support for them. --- instrumentation/p6spy/README.md | 8 ++++ .../java/brave/p6spy/TracingJdbcEventListener.java | 29 +++++++++-- .../main/java/brave/p6spy/TracingP6Factory.java | 3 +- .../main/java/brave/p6spy/TracingP6SpyOptions.java | 31 ++++++++++-- .../brave/p6spy/TracingJdbcEventListenerTest.java | 56 ++++++++++++++++++---- 5 files changed, 107 insertions(+), 20 deletions(-) diff --git a/instrumentation/p6spy/README.md b/instrumentation/p6spy/README.md index 42a575b..b658134 100644 --- a/instrumentation/p6spy/README.md +++ b/instrumentation/p6spy/README.md @@ -42,3 +42,11 @@ jdbc:mysql://127.0.0.1:3306/mydatabase?zipkinServiceName=myServiceName This will override the `remoteServiceName` set in `spy.properties`. The current tracing component is used at runtime. Until you have instantiated `brave.Tracing`, no traces will appear. + +### Filtering spans + +By default, all statements are recorded as client spans. +You may wish to exclude statements like `set session` from tracing. This library reuses p6spy's log filtering for this purpose. +Filtering options are picked up from `spy.properties`, so you can blacklist/whitelist what type of statements to record as spans. + +For configuration details please see p6spy's log filtering documentation. diff --git a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingJdbcEventListener.java b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingJdbcEventListener.java index dada752..cd92039 100644 --- a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingJdbcEventListener.java +++ b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingJdbcEventListener.java @@ -18,6 +18,8 @@ import brave.internal.Nullable; import brave.propagation.ThreadLocalSpan; import com.p6spy.engine.common.StatementInformation; import com.p6spy.engine.event.SimpleJdbcEventListener; +import com.p6spy.engine.logging.P6LogLoadableOptions; + import java.net.URI; import java.sql.Connection; import java.sql.SQLException; @@ -31,10 +33,13 @@ final class TracingJdbcEventListener extends SimpleJdbcEventListener { @Nullable final String remoteServiceName; final boolean includeParameterValues; + final P6LogLoadableOptions logOptions; - TracingJdbcEventListener(@Nullable String remoteServiceName, boolean includeParameterValues) { + TracingJdbcEventListener(@Nullable String remoteServiceName, boolean includeParameterValues, + P6LogLoadableOptions logOptions) { this.remoteServiceName = remoteServiceName; this.includeParameterValues = includeParameterValues; + this.logOptions = logOptions; } /** @@ -45,8 +50,7 @@ final class TracingJdbcEventListener extends SimpleJdbcEventListener { */ @Override public void onBeforeAnyExecute(StatementInformation info) { String sql = includeParameterValues ? info.getSqlWithValues() : info.getSql(); - // don't start a span unless there is SQL as we cannot choose a relevant name without it - if (sql == null || sql.isEmpty()) return; + if (!isLoggable(sql)) return; // Gets the next span (and places it in scope) so code between here and postProcess can read it Span span = ThreadLocalSpan.CURRENT_TRACER.next(); @@ -68,7 +72,24 @@ final class TracingJdbcEventListener extends SimpleJdbcEventListener { span.finish(); } - /** + boolean isLoggable(String sql) { + // don't start a span unless there is SQL as we cannot choose a relevant name without it + // empty batches and connection commits/rollbacks + if (sql == null || sql.isEmpty()) { + return false; + } + if (!logOptions.getFilter()) { + return true; + } + + final Pattern sqlExpressionPattern = logOptions.getSQLExpressionPattern(); + final Pattern includeExcludePattern = logOptions.getIncludeExcludePattern(); + + return (sqlExpressionPattern == null || sqlExpressionPattern.matcher(sql).matches()) + && (includeExcludePattern == null || includeExcludePattern.matcher(sql).matches()); + } + + /** * This attempts to get the ip and port from the JDBC URL. Ex. localhost and 5555 from {@code * jdbc:mysql://localhost:5555/mydatabase}. */ diff --git a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6Factory.java b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6Factory.java index c41cfc1..4a4b5e4 100644 --- a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6Factory.java +++ b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6Factory.java @@ -28,6 +28,7 @@ public final class TracingP6Factory implements P6Factory { } @Override public JdbcEventListener getJdbcEventListener() { - return new TracingJdbcEventListener(options.remoteServiceName(), options.includeParameterValues()); + return new TracingJdbcEventListener(options.remoteServiceName(), + options.includeParameterValues(), options.getLogOptions()); } } diff --git a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6SpyOptions.java b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6SpyOptions.java index 352ee7c..2d50fdb 100644 --- a/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6SpyOptions.java +++ b/instrumentation/p6spy/src/main/java/brave/p6spy/TracingP6SpyOptions.java @@ -13,25 +13,47 @@ */ package brave.p6spy; +import com.p6spy.engine.logging.P6LogLoadableOptions; +import com.p6spy.engine.logging.P6LogOptions; import com.p6spy.engine.spy.P6SpyOptions; import com.p6spy.engine.spy.option.P6OptionsRepository; + +import java.util.LinkedHashMap; import java.util.Map; final class TracingP6SpyOptions extends P6SpyOptions { + static final String REMOTE_SERVICE_NAME = "remoteServiceName"; static final String INCLUDE_PARAMETER_VALUES = "includeParameterValues"; - final P6OptionsRepository optionsRepository; + private final P6OptionsRepository optionsRepository; + private final P6LogLoadableOptions logLoadableOptions; TracingP6SpyOptions(P6OptionsRepository optionsRepository) { super(optionsRepository); + logLoadableOptions = new P6LogOptions(optionsRepository); this.optionsRepository = optionsRepository; } - @Override public void load(Map options) { + @Override + public void load(Map options) { super.load(options); + logLoadableOptions.load(options); optionsRepository.set(String.class, REMOTE_SERVICE_NAME, options.get(REMOTE_SERVICE_NAME)); - optionsRepository.set(Boolean.class, INCLUDE_PARAMETER_VALUES, options.get(INCLUDE_PARAMETER_VALUES)); + optionsRepository.set(Boolean.class, INCLUDE_PARAMETER_VALUES, + options.get(INCLUDE_PARAMETER_VALUES)); + } + + @Override + public Map getDefaults() { + Map allDefaults = new LinkedHashMap(super.getDefaults()); + allDefaults.putAll(logLoadableOptions.getDefaults()); + allDefaults.put(INCLUDE_PARAMETER_VALUES, Boolean.FALSE.toString()); + return allDefaults; + } + + P6LogLoadableOptions getLogOptions() { + return logLoadableOptions; } String remoteServiceName() { @@ -39,7 +61,6 @@ final class TracingP6SpyOptions extends P6SpyOptions { } Boolean includeParameterValues() { - Boolean logParameterValues = optionsRepository.get(Boolean.class, INCLUDE_PARAMETER_VALUES); - return logParameterValues == null ? false : logParameterValues; + return optionsRepository.get(Boolean.class, INCLUDE_PARAMETER_VALUES); } } diff --git a/instrumentation/p6spy/src/test/java/brave/p6spy/TracingJdbcEventListenerTest.java b/instrumentation/p6spy/src/test/java/brave/p6spy/TracingJdbcEventListenerTest.java index a3faba8..5d4ed8c 100644 --- a/instrumentation/p6spy/src/test/java/brave/p6spy/TracingJdbcEventListenerTest.java +++ b/instrumentation/p6spy/src/test/java/brave/p6spy/TracingJdbcEventListenerTest.java @@ -23,6 +23,10 @@ import java.sql.Connection; import java.sql.DatabaseMetaData; import java.sql.SQLException; import java.util.ArrayList; + +import com.p6spy.engine.logging.P6LogOptions; +import com.p6spy.engine.spy.option.P6OptionsRepository; +import org.junit.Before; import org.junit.Test; import org.junit.runner.RunWith; import org.mockito.Mock; @@ -39,7 +43,7 @@ public class TracingJdbcEventListenerTest { @Mock Connection connection; @Mock DatabaseMetaData metaData; @Mock StatementInformation statementInformation; - @Mock ConnectionInformation ci; + @Mock ConnectionInformation connectionInformation; @Mock Span span; String url = "jdbc:mysql://1.2.3.4:5555/mydatabase"; @@ -47,12 +51,21 @@ public class TracingJdbcEventListenerTest { String urlWithEmptyServiceName = url + "?zipkinServiceName=&foo=bar"; String urlWithWhiteSpace = "jdbc:sqlserver://1.2.3.4;databaseName=mydatabase;applicationName=Microsoft JDBC Driver for SQL Server"; + P6OptionsRepository p6OptionsRepository; + P6LogOptions logOptions; + + @Before public void init() { + p6OptionsRepository = new P6OptionsRepository(); + logOptions = new P6LogOptions(p6OptionsRepository); + logOptions.load(logOptions.getDefaults()); + p6OptionsRepository.initCompleted(); + } @Test public void parseServerIpAndPort_IpAndPortFromUrl() throws SQLException { when(connection.getMetaData()).thenReturn(metaData); when(metaData.getURL()).thenReturn(url); - new TracingJdbcEventListener("", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteIpAndPort("1.2.3.4", 5555); } @@ -62,7 +75,7 @@ public class TracingJdbcEventListenerTest { when(metaData.getURL()).thenReturn(url); when(connection.getCatalog()).thenReturn("mydatabase"); - new TracingJdbcEventListener("", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteServiceName("mydatabase"); verify(span).remoteIpAndPort("1.2.3.4", 5555); @@ -72,7 +85,7 @@ public class TracingJdbcEventListenerTest { when(connection.getMetaData()).thenReturn(metaData); when(metaData.getURL()).thenReturn(urlWithServiceName); - new TracingJdbcEventListener("", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteServiceName("mysql_service"); verify(span).remoteIpAndPort("1.2.3.4", 5555); @@ -83,7 +96,7 @@ public class TracingJdbcEventListenerTest { when(metaData.getURL()).thenReturn(urlWithEmptyServiceName); when(connection.getCatalog()).thenReturn("mydatabase"); - new TracingJdbcEventListener("", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteServiceName("mydatabase"); verify(span).remoteIpAndPort("1.2.3.4", 5555); @@ -93,7 +106,7 @@ public class TracingJdbcEventListenerTest { when(connection.getMetaData()).thenReturn(metaData); when(metaData.getURL()).thenReturn(url); - new TracingJdbcEventListener("foo", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("foo", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteServiceName("foo"); verify(span).remoteIpAndPort("1.2.3.4", 5555); @@ -102,7 +115,7 @@ public class TracingJdbcEventListenerTest { @Test public void parseServerIpAndPort_doesntCrash() throws SQLException { when(connection.getMetaData()).thenThrow(new SQLException()); - new TracingJdbcEventListener("", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("", false, logOptions).parseServerIpAndPort(connection, span); verifyNoMoreInteractions(span); } @@ -111,18 +124,40 @@ public class TracingJdbcEventListenerTest { when(connection.getMetaData()).thenReturn(metaData); when(metaData.getURL()).thenReturn(urlWithWhiteSpace); - new TracingJdbcEventListener("foo", false).parseServerIpAndPort(connection, span); + new TracingJdbcEventListener("foo", false, logOptions).parseServerIpAndPort(connection, span); verify(span).remoteServiceName("foo"); } + @Test public void shouldFilterSqlExclusion() throws SQLException { + ArrayList spans = new ArrayList<>(); + try (Tracing tracing = tracingBuilder(Sampler.ALWAYS_SAMPLE, spans).build()) { + logOptions.setFilter(true); + logOptions.setExclude("set session"); + when(statementInformation.getSql()).thenReturn("set session foo foo;"); + when(statementInformation.getConnectionInformation()).thenReturn(connectionInformation); + when(connectionInformation.getConnection()).thenReturn(connection); + when(connection.getMetaData()).thenReturn(metaData); + + TracingJdbcEventListener listener = new TracingJdbcEventListener("", false, logOptions); + listener.onBeforeAnyExecute(statementInformation); + listener.onAfterAnyExecute(statementInformation, 1, null); + + logOptions.setFilter(false); + listener.onBeforeAnyExecute(statementInformation); + listener.onAfterAnyExecute(statementInformation, 1, null); + + assertThat(spans).size().isEqualTo(1); + } + } + @Test public void nullSqlWontNPE() throws SQLException { ArrayList spans = new ArrayList<>(); try (Tracing tracing = tracingBuilder(Sampler.ALWAYS_SAMPLE, spans).build()) { when(statementInformation.getSql()).thenReturn(null); - TracingJdbcEventListener listener = new TracingJdbcEventListener("", false); + TracingJdbcEventListener listener = new TracingJdbcEventListener("", false, logOptions); listener.onBeforeAnyExecute(statementInformation); listener.onAfterAnyExecute(statementInformation, 1, null); @@ -134,11 +169,12 @@ public class TracingJdbcEventListenerTest { Tracing tracing = tracingBuilder(Sampler.ALWAYS_SAMPLE, new ArrayList<>()).build(); ScopedSpan parent = tracing.tracer().startScopedSpan("test"); try { - TracingJdbcEventListener listener = new TracingJdbcEventListener("", false); + TracingJdbcEventListener listener = new TracingJdbcEventListener("", false, logOptions); listener.onAfterAnyExecute(statementInformation, 1, null); listener.onAfterAnyExecute(statementInformation, 1, null); } finally { parent.finish(); + tracing.close(); } } }