This is an automated email from the ASF dual-hosted git repository.
stigahuang pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/impala.git
The following commit(s) were added to refs/heads/master by this push:
new 8d4497be0 IMPALA-13252: Consistently use PrintId to print TUniqueId
8d4497be0 is described below
commit 8d4497be0947e7552e0e9e2c15b9b08566aad148
Author: Michael Smith <[email protected]>
AuthorDate: Tue Jul 23 13:11:30 2024 -0700
IMPALA-13252: Consistently use PrintId to print TUniqueId
Some logging formats TUniqueId inconsistently by relying on the Thrift
to_string/toString generated printers. This makes it difficult to track
a specific query through logs.
Adds operator<<(ostream, TUniqueId) to simplify logging TUniqueId
correctly, uses PrintId instead of toString in Java, and adds a verifier
to test_banned_log_messages to ensure TUniqueId is not printed in logs.
Change-Id: If01bf20a240debbbd4c0a22798045ea03f17b28e
Reviewed-on: http://gerrit.cloudera.org:8080/21606
Reviewed-by: Yida Wu <[email protected]>
Tested-by: Impala Public Jenkins <[email protected]>
---
be/src/util/debug-util.h | 4 ++++
.../org/apache/impala/catalog/local/CatalogdMetaProvider.java | 4 +++-
.../java/org/apache/impala/common/KuduTransactionManager.java | 11 +++++++----
fe/src/main/java/org/apache/impala/service/Frontend.java | 11 ++++++-----
tests/common/patterns.py | 7 +++++++
tests/custom_cluster/test_custom_statestore.py | 5 +++--
tests/verifiers/test_banned_log_messages.py | 5 +++++
7 files changed, 35 insertions(+), 12 deletions(-)
diff --git a/be/src/util/debug-util.h b/be/src/util/debug-util.h
index 4d7255e45..fcec0e7dc 100644
--- a/be/src/util/debug-util.h
+++ b/be/src/util/debug-util.h
@@ -74,6 +74,10 @@ constexpr int TUniqueIdBufferSize = 33;
void PrintIdCompromised(const TUniqueId& id, char out[TUniqueIdBufferSize],
const char separator = ':');
+inline ostream& operator<<(ostream& os, const TUniqueId& id) {
+ return os << PrintId(id);
+}
+
inline ostream& operator<<(ostream& os, const UniqueIdPB& id) {
return os << PrintId(id);
}
diff --git
a/fe/src/main/java/org/apache/impala/catalog/local/CatalogdMetaProvider.java
b/fe/src/main/java/org/apache/impala/catalog/local/CatalogdMetaProvider.java
index 5d1834793..8c702c305 100644
--- a/fe/src/main/java/org/apache/impala/catalog/local/CatalogdMetaProvider.java
+++ b/fe/src/main/java/org/apache/impala/catalog/local/CatalogdMetaProvider.java
@@ -17,6 +17,8 @@
package org.apache.impala.catalog.local;
+import static org.apache.impala.util.TUniqueIdUtil.PrintId;
+
import java.lang.management.ManagementFactory;
import java.nio.ByteBuffer;
import java.util.ArrayList;
@@ -1571,7 +1573,7 @@ public class CatalogdMetaProvider implements MetaProvider
{
if (!catalogServiceId_.equals(Catalog.INITIAL_CATALOG_SERVICE_ID)) {
LOG.warn("Detected catalog service restart: service ID changed from
" +
"{} to {}. Invalidating all cached metadata on this
coordinator.",
- catalogServiceId_, serviceId);
+ PrintId(catalogServiceId_), PrintId(serviceId));
}
catalogServiceId_ = serviceId;
cache_.invalidateAll();
diff --git
a/fe/src/main/java/org/apache/impala/common/KuduTransactionManager.java
b/fe/src/main/java/org/apache/impala/common/KuduTransactionManager.java
index e31ab0b57..77305b3a2 100644
--- a/fe/src/main/java/org/apache/impala/common/KuduTransactionManager.java
+++ b/fe/src/main/java/org/apache/impala/common/KuduTransactionManager.java
@@ -17,11 +17,14 @@
package org.apache.impala.common;
+import static org.apache.impala.util.TUniqueIdUtil.PrintId;
+
import java.util.concurrent.ConcurrentHashMap;
import org.apache.impala.thrift.TUniqueId;
import org.apache.kudu.client.KuduTransaction;
-import org.apache.log4j.Logger;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
import com.google.common.base.Preconditions;
@@ -33,7 +36,7 @@ import com.google.common.base.Preconditions;
* to commit or rollback the transaction.
*/
public class KuduTransactionManager {
- public static final Logger LOG =
Logger.getLogger(KuduTransactionManager.class);
+ public static final Logger LOG =
LoggerFactory.getLogger(KuduTransactionManager.class);
// Map of Kudu transactions.
// It's thread safe.
@@ -62,8 +65,8 @@ public class KuduTransactionManager {
Preconditions.checkNotNull(queryId);
KuduTransaction txn = transactions_.remove(queryId);
if (txn == null) {
- LOG.info("Kudu transaction with query-id " + queryId + " was already
removed "
- + "from KuduTransactionManager object or never existed.");
+ LOG.info("Kudu transaction with query-id {} was already removed "
+ + "from KuduTransactionManager object or never existed.",
PrintId(queryId));
};
return txn;
}
diff --git a/fe/src/main/java/org/apache/impala/service/Frontend.java
b/fe/src/main/java/org/apache/impala/service/Frontend.java
index 266b3c88b..b53dca08c 100644
--- a/fe/src/main/java/org/apache/impala/service/Frontend.java
+++ b/fe/src/main/java/org/apache/impala/service/Frontend.java
@@ -18,6 +18,7 @@
package org.apache.impala.service;
import static org.apache.impala.common.ByteUnits.MEGABYTE;
+import static org.apache.impala.util.TUniqueIdUtil.PrintId;
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.MoreObjects;
@@ -2775,7 +2776,7 @@ public class Frontend {
planCtx.compilationState_.setKuduTransactionToken(null);
abortKuduTransaction(queryCtx.getQuery_id());
timeline.markEvent(
- "Kudu transaction aborted: " +
queryCtx.getQuery_id().toString());
+ "Kudu transaction aborted: " + PrintId(queryCtx.getQuery_id()));
} catch (TransactionException te) {
LOG.error("Could not abort transaction because: " + te.getMessage());
}
@@ -3250,10 +3251,10 @@ public class Frontend {
KuduTransaction txn = null;
try {
// Open Kudu transaction.
- LOG.info("Open Kudu transaction: " + queryCtx.getQuery_id().toString());
+ LOG.info("Open Kudu transaction: {}", PrintId(queryCtx.getQuery_id()));
txn = client.newTransaction();
timeline.markEvent(
- "Kudu transaction opened with query id: " +
queryCtx.getQuery_id().toString());
+ "Kudu transaction opened with query id: " +
PrintId(queryCtx.getQuery_id()));
token = txn.serialize();
if (analysisResult.isUpdateStmt()) {
analysisResult.getUpdateStmt().setKuduTransactionToken(token);
@@ -3278,7 +3279,7 @@ public class Frontend {
* @param queryId is the id of the query.
*/
public void abortKuduTransaction(TUniqueId queryId) throws
TransactionException {
- LOG.info("Abort Kudu transaction: " + queryId.toString());
+ LOG.info("Abort Kudu transaction: {}", PrintId(queryId));
KuduTransaction txn = kuduTxnManager_.deleteTransaction(queryId);
Preconditions.checkNotNull(txn);
if (txn != null) {
@@ -3299,7 +3300,7 @@ public class Frontend {
* @param queryId is the id of the query.
*/
public void commitKuduTransaction(TUniqueId queryId) throws
TransactionException {
- LOG.info("Commit Kudu transaction: " + queryId.toString());
+ LOG.info("Commit Kudu transaction: {}", PrintId(queryId));
KuduTransaction txn = kuduTxnManager_.deleteTransaction(queryId);
Preconditions.checkNotNull(txn);
if (txn != null) {
diff --git a/tests/common/patterns.py b/tests/common/patterns.py
index 1214e5e37..850feb541 100644
--- a/tests/common/patterns.py
+++ b/tests/common/patterns.py
@@ -24,7 +24,14 @@ import re
#
http://www.cloudera.com/content/www/en-us/documentation/enterprise/latest/topics/impala_identifiers.html
VALID_IMPALA_IDENTIFIER_REGEX = re.compile(r'^[a-zA-Z][a-zA-Z0-9_]{,127}$')
+INT64_MASK = (1 << 64) - 1
+
def is_valid_impala_identifier(identifier):
"""Return True if identifier is a valid Impala identifier, False
otherwise."""
return VALID_IMPALA_IDENTIFIER_REGEX.match(identifier) is not None
+
+
+def print_id(id):
+ """Stringify a TUniqueId as e.g. 8a4673c8fbe83a74:309751e900000000"""
+ return '{:016x}:{:016x}'.format(id.hi & INT64_MASK, id.lo & INT64_MASK)
diff --git a/tests/custom_cluster/test_custom_statestore.py
b/tests/custom_cluster/test_custom_statestore.py
index 8693b9834..ef0dbd817 100644
--- a/tests/custom_cluster/test_custom_statestore.py
+++ b/tests/custom_cluster/test_custom_statestore.py
@@ -32,6 +32,7 @@ from tests.common.custom_cluster_test_suite import
CustomClusterTestSuite
from tests.common.environ import build_flavor_timeout
from tests.common.skip import SkipIfBuildType
from tests.common.impala_test_suite import ImpalaTestSuite
+from tests.common.patterns import print_id
from time import sleep
from Types.ttypes import TNetworkAddress
@@ -118,8 +119,8 @@ class TestCustomStatestore(CustomClusterTestSuite):
for x in range(20):
response = self.__register_subscriber()
if response.status.status_code == TErrorCode.OK:
- self.registration_id = response.registration_id
- LOG.log(logging.INFO, "Registration id %s, x=%d" %
(response.registration_id, x))
+ LOG.log(logging.INFO, "Registration id %s, x=%d" % (
+ print_id(response.registration_id), x))
else:
assert 'Maximum subscriber limit reached:' in
''.join(response.status.error_msgs)
return
diff --git a/tests/verifiers/test_banned_log_messages.py
b/tests/verifiers/test_banned_log_messages.py
index 6a5cf483b..2b70f45a0 100644
--- a/tests/verifiers/test_banned_log_messages.py
+++ b/tests/verifiers/test_banned_log_messages.py
@@ -42,3 +42,8 @@ class TestBannedLogMessages:
def test_no_unsupported_operations(self):
"""Test that cluster logs do not contain jamm.CannotAccessFieldException"""
self.assert_message_absent('CannotAccessFieldException')
+
+ def test_no_tuniqueid(self):
+ """Test that cluster logs do not contain TUniqueId. They should instead
print
+ IDs with the format 8a4673c8fbe83a74:309751e900000000."""
+ self.assert_message_absent('[^a-zA-Z]TUniqueId(')
