Repository: phoenix Updated Branches: refs/heads/master 797af91a6 -> f4ef42d69
Custom tracing annotations PHOENIX-1196 Project: http://git-wip-us.apache.org/repos/asf/phoenix/repo Commit: http://git-wip-us.apache.org/repos/asf/phoenix/commit/f4ef42d6 Tree: http://git-wip-us.apache.org/repos/asf/phoenix/tree/f4ef42d6 Diff: http://git-wip-us.apache.org/repos/asf/phoenix/diff/f4ef42d6 Branch: refs/heads/master Commit: f4ef42d6902b8edf8aa88dd81756300f6071d34d Parents: 797af91 Author: Eli Levine <elilev...@apache.org> Authored: Thu Sep 18 20:31:19 2014 -0700 Committer: Eli Levine <elilev...@apache.org> Committed: Thu Sep 18 20:32:13 2014 -0700 ---------------------------------------------------------------------- .../apache/phoenix/trace/BaseTracingTestIT.java | 16 ++++- .../phoenix/trace/PhoenixTracingEndToEndIT.java | 61 ++++++++++++++++++++ .../apache/phoenix/jdbc/PhoenixConnection.java | 22 +++++++ .../org/apache/phoenix/trace/util/Tracing.java | 21 +++++++ .../java/org/apache/phoenix/util/JDBCUtil.java | 45 ++++++++++++++- .../org/apache/phoenix/util/PhoenixRuntime.java | 7 +++ .../org/apache/phoenix/util/JDBCUtilTest.java | 59 +++++++++++++++++++ 7 files changed, 228 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/it/java/org/apache/phoenix/trace/BaseTracingTestIT.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/it/java/org/apache/phoenix/trace/BaseTracingTestIT.java b/phoenix-core/src/it/java/org/apache/phoenix/trace/BaseTracingTestIT.java index 1f4990b..92b2250 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/trace/BaseTracingTestIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/trace/BaseTracingTestIT.java @@ -17,11 +17,14 @@ */ package org.apache.phoenix.trace; +import static org.apache.phoenix.util.PhoenixRuntime.ANNOTATION_ATTRIB_PREFIX; import static org.apache.phoenix.util.TestUtil.TEST_PROPERTIES; import java.sql.Connection; import java.sql.DriverManager; import java.sql.SQLException; +import java.util.Collections; +import java.util.Map; import java.util.Properties; import org.apache.commons.logging.Log; @@ -36,6 +39,7 @@ import org.apache.phoenix.query.QueryServicesOptions; import org.apache.phoenix.schema.TableNotFoundException; import org.apache.phoenix.trace.util.Tracing; import org.apache.phoenix.trace.util.Tracing.Frequency; +import org.apache.phoenix.util.PhoenixRuntime; import org.apache.phoenix.util.PropertiesUtil; import org.junit.Before; @@ -86,9 +90,19 @@ public class BaseTracingTestIT extends BaseHBaseManagedTimeIT { conn.setAutoCommit(false); return conn; } + + public static Connection getTracingConnection() throws Exception { + return getTracingConnection(Collections.<String, String>emptyMap(), null); + } - public static Connection getTracingConnection() throws Exception { + public static Connection getTracingConnection(Map<String, String> customAnnotations, String tenantId) throws Exception { Properties props = PropertiesUtil.deepCopy(TEST_PROPERTIES); + for (Map.Entry<String, String> annot : customAnnotations.entrySet()) { + props.put(ANNOTATION_ATTRIB_PREFIX + annot.getKey(), annot.getValue()); + } + if (tenantId != null) { + props.put(PhoenixRuntime.TENANT_ID_ATTRIB, tenantId); + } return getConnectionWithTracingFrequency(props, Tracing.Frequency.ALWAYS); } http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/it/java/org/apache/phoenix/trace/PhoenixTracingEndToEndIT.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/it/java/org/apache/phoenix/trace/PhoenixTracingEndToEndIT.java b/phoenix-core/src/it/java/org/apache/phoenix/trace/PhoenixTracingEndToEndIT.java index 6742f9e..0fc80ed 100644 --- a/phoenix-core/src/it/java/org/apache/phoenix/trace/PhoenixTracingEndToEndIT.java +++ b/phoenix-core/src/it/java/org/apache/phoenix/trace/PhoenixTracingEndToEndIT.java @@ -17,6 +17,7 @@ */ package org.apache.phoenix.trace; +import static org.apache.phoenix.util.PhoenixRuntime.TENANT_ID_ATTRIB; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertTrue; @@ -49,6 +50,8 @@ import org.junit.Test; import org.junit.experimental.categories.Category; import org.junit.runner.RunWith; +import com.google.common.collect.ImmutableMap; + /** * Test that the logging sink stores the expected metrics/stats */ @@ -353,7 +356,65 @@ public class PhoenixTracingEndToEndIT extends BaseTracingTestIT { }); assertTrue("Didn't find the parallel scanner in the tracing", found); } + + @Test + public void testCustomAnnotationTracing() throws Exception { + final String customAnnotationKey = "myannot"; + final String customAnnotationValue = "a1"; + final String tenantId = "tenant1"; + // separate connections to minimize amount of traces that are generated + Connection traceable = getTracingConnection(ImmutableMap.of(customAnnotationKey, customAnnotationValue), tenantId); + Connection conn = getConnectionWithoutTracing(); + + // one call for client side, one call for server side + CountDownLatch updated = new CountDownLatch(2); + waitForCommit(updated); + + // create a dummy table + createTestTable(conn, false); + // update the table, but don't trace these, to simplify the traces we read + LOG.debug("Doing dummy the writes to the tracked table"); + String insert = "UPSERT INTO " + table + " VALUES (?, ?)"; + PreparedStatement stmt = conn.prepareStatement(insert); + stmt.setString(1, "key1"); + stmt.setLong(2, 1); + stmt.execute(); + conn.commit(); + conn.rollback(); + + // setup for next set of updates + stmt.setString(1, "key2"); + stmt.setLong(2, 2); + stmt.execute(); + conn.commit(); + conn.rollback(); + + // do a scan of the table + String read = "SELECT * FROM " + table; + ResultSet results = traceable.createStatement().executeQuery(read); + assertTrue("Didn't get first result", results.next()); + assertTrue("Didn't get second result", results.next()); + results.close(); + + assertTrue("Get expected updates to trace table", updated.await(200, TimeUnit.SECONDS)); + + assertAnnotationPresent(customAnnotationKey, customAnnotationValue, conn); + assertAnnotationPresent(TENANT_ID_ATTRIB, tenantId, conn); + // CurrentSCN is also added as an annotation. Not tested here because it screws up test setup. + } + + private void assertAnnotationPresent(final String annotationKey, final String annotationValue, Connection conn) throws Exception { + boolean tracingComplete = checkStoredTraces(conn, new TraceChecker(){ + @Override + public boolean foundTrace(TraceHolder currentTrace) { + return currentTrace.toString().contains(annotationKey + " - " + annotationValue); + } + }); + + assertTrue("Didn't find the custom annotation in the tracing", tracingComplete); + } + private boolean checkStoredTraces(Connection conn, TraceChecker checker) throws Exception { TraceReader reader = new TraceReader(conn); int retries = 0; http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java index 622fc8a..9a01018 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixConnection.java @@ -17,6 +17,8 @@ */ package org.apache.phoenix.jdbc; +import static java.util.Collections.emptyMap; + import java.io.EOFException; import java.io.IOException; import java.io.PrintStream; @@ -86,6 +88,8 @@ import org.cloudera.htrace.Sampler; import com.google.common.base.Objects; import com.google.common.base.Strings; +import com.google.common.collect.ImmutableMap; +import com.google.common.collect.ImmutableMap.Builder; import com.google.common.collect.Lists; import com.google.common.collect.Maps; @@ -120,6 +124,7 @@ public class PhoenixConnection implements Connection, org.apache.phoenix.jdbc.Jd private boolean isClosed = false; private Sampler<?> sampler; private boolean readOnly = false; + private Map<String, String> customTracingAnnotations = emptyMap(); static { Tracing.addTraceMetricsSource(); @@ -214,11 +219,28 @@ public class PhoenixConnection implements Connection, org.apache.phoenix.jdbc.Jd // setup tracing, if its enabled this.sampler = Tracing.getConfiguredSampler(this); + this.customTracingAnnotations = getImmutableCustomTracingAnnotations(); + } + + private ImmutableMap<String, String> getImmutableCustomTracingAnnotations() { + Builder<String, String> result = ImmutableMap.builder(); + result.putAll(JDBCUtil.getAnnotations(url, info)); + if (getSCN() != null) { + result.put(PhoenixRuntime.CURRENT_SCN_ATTRIB, getSCN().toString()); + } + if (getTenantId() != null) { + result.put(PhoenixRuntime.TENANT_ID_ATTRIB, getTenantId().getString()); + } + return result.build(); } public Sampler<?> getSampler() { return this.sampler; } + + public Map<String, String> getCustomTracingAnnotations() { + return customTracingAnnotations; + } public int executeStatements(Reader reader, List<Object> binds, PrintStream out) throws IOException, SQLException { int bindsOffset = 0; http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/main/java/org/apache/phoenix/trace/util/Tracing.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/main/java/org/apache/phoenix/trace/util/Tracing.java b/phoenix-core/src/main/java/org/apache/phoenix/trace/util/Tracing.java index f1926f8..c7c381e 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/trace/util/Tracing.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/trace/util/Tracing.java @@ -17,9 +17,14 @@ */ package org.apache.phoenix.trace.util; +import static org.apache.phoenix.util.StringUtil.toBytes; + +import java.util.Map; import java.util.Properties; import java.util.concurrent.Callable; +import javax.annotation.Nullable; + import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import org.apache.hadoop.conf.Configuration; @@ -43,6 +48,8 @@ import org.cloudera.htrace.wrappers.TraceCallable; import org.cloudera.htrace.wrappers.TraceRunnable; import com.google.common.base.Function; +import com.google.common.base.Preconditions; +import com.sun.istack.NotNull; /** * Helper class to manage using the {@link Tracer} within Phoenix @@ -153,6 +160,7 @@ public class Tracing { public static TraceScope startNewSpan(PhoenixConnection connection, String string) { Sampler<?> sampler = connection.getSampler(); TraceScope scope = Trace.startSpan(string, sampler); + addCustomAnnotationsToSpan(scope.getSpan(), connection); return scope; } @@ -257,6 +265,19 @@ public class Tracing { public static CallWrapper withTracing(PhoenixConnection conn, String desc) { return new TracingWrapper(conn, desc); } + + private static void addCustomAnnotationsToSpan(@Nullable Span span, @NotNull PhoenixConnection conn) { + Preconditions.checkNotNull(conn); + + if (span == null) { + return; + } + Map<String, String> annotations = conn.getCustomTracingAnnotations(); + // copy over the annotations as bytes + for (Map.Entry<String, String> annotation : annotations.entrySet()) { + span.addKVAnnotation(toBytes(annotation.getKey()), toBytes(annotation.getValue())); + } + } private static class TracingWrapper implements CallWrapper { private TraceScope scope; http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/main/java/org/apache/phoenix/util/JDBCUtil.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/main/java/org/apache/phoenix/util/JDBCUtil.java b/phoenix-core/src/main/java/org/apache/phoenix/util/JDBCUtil.java index 6148417..4e9f01b 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/util/JDBCUtil.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/util/JDBCUtil.java @@ -17,7 +17,11 @@ */ package org.apache.phoenix.util; +import static com.google.common.collect.Maps.newHashMapWithExpectedSize; +import static org.apache.phoenix.util.PhoenixRuntime.ANNOTATION_ATTRIB_PREFIX; + import java.sql.SQLException; +import java.util.Map; import java.util.Properties; import javax.annotation.Nullable; @@ -27,13 +31,14 @@ import org.apache.phoenix.query.QueryServicesOptions; import org.apache.phoenix.schema.PName; import org.apache.phoenix.schema.PNameFactory; +import com.google.common.base.Preconditions; +import com.sun.istack.NotNull; + /** * Utilities for JDBC * - * - * @since 178 */ public class JDBCUtil { @@ -63,6 +68,42 @@ public class JDBCUtil { } return propValue; } + + /** + * Returns a map that contains connection properties from both <code>info</code> and <code>url</code>. + */ + private static Map<String, String> getCombinedConnectionProperties(String url, Properties info) { + Map<String, String> result = newHashMapWithExpectedSize(info.size()); + for (String propName : info.stringPropertyNames()) { + result.put(propName, info.getProperty(propName)); + } + String[] urlPropNameValues = url.split(";"); + if (urlPropNameValues.length > 1) { + for (int i = 1; i < urlPropNameValues.length; i++) { + String[] urlPropNameValue = urlPropNameValues[i].split("="); + if (urlPropNameValue.length == 2) { + result.put(urlPropNameValue[0], urlPropNameValue[1]); + } + } + } + + return result; + } + + public static Map<String, String> getAnnotations(@NotNull String url, @NotNull Properties info) { + Preconditions.checkNotNull(url); + Preconditions.checkNotNull(info); + + Map<String, String> combinedProperties = getCombinedConnectionProperties(url, info); + Map<String, String> result = newHashMapWithExpectedSize(combinedProperties.size()); + for (Map.Entry<String, String> prop : combinedProperties.entrySet()) { + if (prop.getKey().startsWith(ANNOTATION_ATTRIB_PREFIX) && + prop.getKey().length() > ANNOTATION_ATTRIB_PREFIX.length()) { + result.put(prop.getKey().substring(ANNOTATION_ATTRIB_PREFIX.length()), prop.getValue()); + } + } + return result; + } public static Long getCurrentSCN(String url, Properties info) throws SQLException { String scnStr = findProperty(url, info, PhoenixRuntime.CURRENT_SCN_ATTRIB); http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/main/java/org/apache/phoenix/util/PhoenixRuntime.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/main/java/org/apache/phoenix/util/PhoenixRuntime.java b/phoenix-core/src/main/java/org/apache/phoenix/util/PhoenixRuntime.java index af4c9e0..7de27c2 100644 --- a/phoenix-core/src/main/java/org/apache/phoenix/util/PhoenixRuntime.java +++ b/phoenix-core/src/main/java/org/apache/phoenix/util/PhoenixRuntime.java @@ -105,6 +105,13 @@ public class PhoenixRuntime { * configuration properties */ public static final String TENANT_ID_ATTRIB = "TenantId"; + + /** + * Use this connection property prefix for annotations that you want to show up in traces and log lines emitted by Phoenix. + * This is useful for annotating connections with information available on the client (e.g. user or session identifier) and + * having these annotation automatically passed into log lines and traces by Phoenix. + */ + public static final String ANNOTATION_ATTRIB_PREFIX = "phoenix.annotation."; /** * Use this as the zookeeper quorum name to have a connection-less connection. This enables http://git-wip-us.apache.org/repos/asf/phoenix/blob/f4ef42d6/phoenix-core/src/test/java/org/apache/phoenix/util/JDBCUtilTest.java ---------------------------------------------------------------------- diff --git a/phoenix-core/src/test/java/org/apache/phoenix/util/JDBCUtilTest.java b/phoenix-core/src/test/java/org/apache/phoenix/util/JDBCUtilTest.java new file mode 100644 index 0000000..e138806 --- /dev/null +++ b/phoenix-core/src/test/java/org/apache/phoenix/util/JDBCUtilTest.java @@ -0,0 +1,59 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.phoenix.util; + +import static org.apache.phoenix.util.PhoenixRuntime.ANNOTATION_ATTRIB_PREFIX; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertTrue; + +import java.util.Map; +import java.util.Properties; + +import org.junit.Test; + +public class JDBCUtilTest { + + @Test + public void testGetCustomTracingAnnotationsWithNone() { + String url = "localhost;TenantId=abc;"; + Map<String, String> customAnnotations = JDBCUtil.getAnnotations(url, new Properties()); + assertTrue(customAnnotations.isEmpty()); + } + + @Test + public void testGetCustomTracingAnnotationInBothPropertiesAndURL() { + String annotKey1 = "key1"; + String annotVal1 = "val1"; + String annotKey2 = "key2"; + String annotVal2 = "val2"; + String annotKey3 = "key3"; + String annotVal3 = "val3"; + + String url= "localhost;" + ANNOTATION_ATTRIB_PREFIX + annotKey1 + '=' + annotVal1; + + Properties prop = new Properties(); + prop.put(ANNOTATION_ATTRIB_PREFIX + annotKey2, annotVal2); + prop.put(ANNOTATION_ATTRIB_PREFIX + annotKey3, annotVal3); + + Map<String, String> customAnnotations = JDBCUtil.getAnnotations(url, prop); + assertEquals(3, customAnnotations.size()); + assertEquals(annotVal1, customAnnotations.get(annotKey1)); + assertEquals(annotVal2, customAnnotations.get(annotKey2)); + assertEquals(annotVal3, customAnnotations.get(annotKey3)); + } +}