You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@impala.apache.org by jr...@apache.org on 2017/01/18 19:46:22 UTC
[2/6] incubator-impala git commit: IMPALA-4768: Improve logging of
table loading.
IMPALA-4768: Improve logging of table loading.
- Improves the logging for several important events,
in particular, during table loading.
- Uses LOG.info() for such messages to clarify their
intent.
The goal is to improve supportability without having
to turn on trace debugging which can generate a
significant log volume.
Change-Id: I8de96d0cb6d09b2272b1925d42cb059367fe7196
Reviewed-on: http://gerrit.cloudera.org:8080/5709
Reviewed-by: Alex Behm <al...@cloudera.com>
Tested-by: Impala Public Jenkins
Project: http://git-wip-us.apache.org/repos/asf/incubator-impala/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-impala/commit/3b7a1791
Tree: http://git-wip-us.apache.org/repos/asf/incubator-impala/tree/3b7a1791
Diff: http://git-wip-us.apache.org/repos/asf/incubator-impala/diff/3b7a1791
Branch: refs/heads/master
Commit: 3b7a179197bccdebf9c8492477f0cf88c6df0e18
Parents: fa4a054
Author: Alex Behm <al...@cloudera.com>
Authored: Thu Jan 12 16:54:31 2017 -0800
Committer: Impala Public Jenkins <im...@gerrit.cloudera.org>
Committed: Tue Jan 17 02:25:11 2017 +0000
----------------------------------------------------------------------
.../impala/catalog/CatalogServiceCatalog.java | 37 +++++++++-----------
.../org/apache/impala/catalog/HdfsTable.java | 27 +++++++-------
.../org/apache/impala/catalog/TableLoader.java | 5 +--
.../impala/service/CatalogOpExecutor.java | 2 +-
.../org/apache/impala/service/Frontend.java | 7 ++--
5 files changed, 39 insertions(+), 39 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/3b7a1791/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java b/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java
index b51c9aa..31001a2 100644
--- a/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java
+++ b/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java
@@ -194,9 +194,8 @@ public class CatalogServiceCatalog extends Catalog {
}
public void run() {
- if (LOG.isTraceEnabled()) {
- LOG.trace("Reloading cache pool names from HDFS");
- }
+ if (LOG.isTraceEnabled()) LOG.trace("Reloading cache pool names from HDFS");
+
// Map of cache pool name to CachePoolInfo. Stored in a map to allow Set operations
// to be performed on the keys.
Map<String, CachePoolInfo> currentCachePools = Maps.newHashMap();
@@ -523,9 +522,7 @@ public class CatalogServiceCatalog extends Catalog {
private void loadFunctionsFromDbParams(Db db,
org.apache.hadoop.hive.metastore.api.Database msDb) {
if (msDb == null || msDb.getParameters() == null) return;
- if (LOG.isTraceEnabled()) {
- LOG.trace("Loading native functions for database: " + db.getName());
- }
+ LOG.info("Loading native functions for database: " + db.getName());
TCompactProtocol.Factory protocolFactory = new TCompactProtocol.Factory();
for (String key: msDb.getParameters().keySet()) {
if (!key.startsWith(Db.FUNCTION_INDEX_PREFIX)) continue;
@@ -541,6 +538,7 @@ public class CatalogServiceCatalog extends Catalog {
+ ",continuing", e);
}
}
+ LOG.info("Loaded native functions for database: " + db.getName());
}
/**
@@ -551,9 +549,7 @@ public class CatalogServiceCatalog extends Catalog {
private void loadJavaFunctions(Db db,
List<org.apache.hadoop.hive.metastore.api.Function> functions) {
Preconditions.checkNotNull(functions);
- if (LOG.isTraceEnabled()) {
- LOG.trace("Loading Java functions for database: " + db.getName());
- }
+ LOG.info("Loading Java functions for database: " + db.getName());
for (org.apache.hadoop.hive.metastore.api.Function function: functions) {
try {
for (Function fn: extractFunctions(db.getName(), function)) {
@@ -564,6 +560,7 @@ public class CatalogServiceCatalog extends Catalog {
LOG.error("Skipping function load: " + function.getFunctionName(), e);
}
}
+ LOG.info("Loaded Java functions for database: " + db.getName());
}
/**
@@ -622,6 +619,8 @@ public class CatalogServiceCatalog extends Catalog {
* Resets this catalog instance by clearing all cached table and database metadata.
*/
public void reset() throws CatalogException {
+ LOG.info("Invalidating all metadata.");
+
// First update the policy metadata.
if (sentryProxy_ != null) {
// Sentry Service is enabled.
@@ -665,6 +664,7 @@ public class CatalogServiceCatalog extends Catalog {
} finally {
catalogLock_.writeLock().unlock();
}
+ LOG.info("Invalidated all metadata.");
}
/**
@@ -893,9 +893,7 @@ public class CatalogServiceCatalog extends Catalog {
* Throws a CatalogException if there is an error loading table metadata.
*/
public Table reloadTable(Table tbl) throws CatalogException {
- if (LOG.isTraceEnabled()) {
- LOG.trace(String.format("Refreshing table metadata: %s", tbl.getFullName()));
- }
+ LOG.info(String.format("Refreshing table metadata: %s", tbl.getFullName()));
TTableName tblName = new TTableName(tbl.getDb().getName().toLowerCase(),
tbl.getName().toLowerCase());
Db db = tbl.getDb();
@@ -917,6 +915,7 @@ public class CatalogServiceCatalog extends Catalog {
return replaceTableIfUnchanged(loadReq.get(), previousCatalogVersion);
} finally {
loadReq.close();
+ LOG.info(String.format("Refreshed table metadata: %s", tbl.getFullName()));
}
}
@@ -936,6 +935,7 @@ public class CatalogServiceCatalog extends Catalog {
tbl.load(false, msClient.getHiveClient(), msTbl);
}
tbl.setCatalogVersion(newCatalogVersion);
+ LOG.info(String.format("Refreshed table metadata: %s", tbl.getFullName()));
return tbl;
}
}
@@ -1024,12 +1024,9 @@ public class CatalogServiceCatalog extends Catalog {
Preconditions.checkNotNull(updatedObjects);
updatedObjects.first = null;
updatedObjects.second = null;
- if (LOG.isTraceEnabled()) {
- LOG.trace(String.format("Invalidating table metadata: %s.%s",
- tableName.getDb_name(), tableName.getTable_name()));
- }
String dbName = tableName.getDb_name();
String tblName = tableName.getTable_name();
+ LOG.info(String.format("Invalidating table metadata: %s.%s", dbName, tblName));
// Stores whether the table exists in the metastore. Can have three states:
// 1) true - Table exists in metastore.
@@ -1266,10 +1263,8 @@ public class CatalogServiceCatalog extends Catalog {
String partitionName = hdfsPartition == null
? HdfsTable.constructPartitionName(partitionSpec)
: hdfsPartition.getPartitionName();
- if (LOG.isTraceEnabled()) {
- LOG.trace(String.format("Refreshing Partition metadata: %s %s",
- hdfsTable.getFullName(), partitionName));
- }
+ LOG.info(String.format("Refreshing partition metadata: %s %s",
+ hdfsTable.getFullName(), partitionName));
try (MetaStoreClient msClient = getMetaStoreClient()) {
org.apache.hadoop.hive.metastore.api.Partition hmsPartition = null;
try {
@@ -1290,6 +1285,8 @@ public class CatalogServiceCatalog extends Catalog {
hdfsTable.reloadPartition(hdfsPartition, hmsPartition);
}
hdfsTable.setCatalogVersion(newCatalogVersion);
+ LOG.info(String.format("Refreshed partition metadata: %s %s",
+ hdfsTable.getFullName(), partitionName));
return hdfsTable;
}
}
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/3b7a1791/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java b/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java
index 8fa4f21..857216f 100644
--- a/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java
+++ b/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java
@@ -272,6 +272,7 @@ public class HdfsTable extends Table {
synthesizeBlockMetadata(fs, dirPath, partsByPath);
return;
}
+
int unknownDiskIdCount = 0;
RemoteIterator<LocatedFileStatus> fileStatusIter = fs.listFiles(dirPath, true);
while (fileStatusIter.hasNext()) {
@@ -728,7 +729,7 @@ public class HdfsTable extends Table {
}
}
}
- if (LOG.isTraceEnabled()) LOG.trace("partsByPath size: " + partsByPath.size());
+
loadMetadataAndDiskIds(dirsToLoad, partsByPath);
}
@@ -746,8 +747,13 @@ public class HdfsTable extends Table {
*/
private void loadMetadataAndDiskIds(List<Path> locations,
HashMap<Path, List<HdfsPartition>> partsByPath) {
+ LOG.info(String.format("Loading file and block metadata for %s partitions: %s",
+ partsByPath.size(), getFullName()));
for (Path location: locations) { loadBlockMetadata(location, partsByPath); }
+ LOG.info(String.format("Loaded file and block metadata for %s partitions: %s",
+ partsByPath.size(), getFullName()));
}
+
/**
* Gets the AccessLevel that is available for Impala for this table based on the
* permissions Impala has on the given path. If the path does not exist, recurses up
@@ -1029,9 +1035,7 @@ public class HdfsTable extends Table {
// Load partition and file metadata
if (reuseMetadata) {
// Incrementally update this table's partitions and file metadata
- if (LOG.isTraceEnabled()) {
- LOG.trace("incremental update for table: " + db_.getName() + "." + name_);
- }
+ LOG.info("Incrementally loading table metadata for: " + getFullName());
Preconditions.checkState(partitionsToUpdate == null || loadFileMetadata);
updateMdFromHmsTable(msTbl);
if (msTbl.getPartitionKeysSize() == 0) {
@@ -1039,15 +1043,14 @@ public class HdfsTable extends Table {
} else {
updatePartitionsFromHms(client, partitionsToUpdate, loadFileMetadata);
}
+ LOG.info("Incrementally loaded table metadata for: " + getFullName());
} else {
// Load all partitions from Hive Metastore, including file metadata.
- if (LOG.isTraceEnabled()) {
- LOG.trace("load table from Hive Metastore: " + db_.getName() + "." + name_);
- }
+ LOG.info("Fetching partition metadata from the Metastore: " + getFullName());
List<org.apache.hadoop.hive.metastore.api.Partition> msPartitions =
- Lists.newArrayList();
- msPartitions.addAll(MetaStoreUtil.fetchAllPartitions(
- client, db_.getName(), name_, NUM_PARTITION_FETCH_RETRIES));
+ MetaStoreUtil.fetchAllPartitions(
+ client, db_.getName(), name_, NUM_PARTITION_FETCH_RETRIES);
+ LOG.info("Fetched partition metadata from the Metastore: " + getFullName());
loadAllPartitions(msPartitions, msTbl);
}
if (loadTableSchema) setAvroSchema(client, msTbl);
@@ -1107,9 +1110,7 @@ public class HdfsTable extends Table {
*/
private void updatePartitionsFromHms(IMetaStoreClient client,
Set<String> partitionsToUpdate, boolean loadFileMetadata) throws Exception {
- if (LOG.isTraceEnabled()) {
- LOG.trace("sync table partitions: " + name_);
- }
+ if (LOG.isTraceEnabled()) LOG.trace("Sync table partitions: " + name_);
org.apache.hadoop.hive.metastore.api.Table msTbl = getMetaStoreTable();
Preconditions.checkNotNull(msTbl);
Preconditions.checkState(msTbl.getPartitionKeysSize() != 0);
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/3b7a1791/fe/src/main/java/org/apache/impala/catalog/TableLoader.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/catalog/TableLoader.java b/fe/src/main/java/org/apache/impala/catalog/TableLoader.java
index 7f17a5c..2a1ee15 100644
--- a/fe/src/main/java/org/apache/impala/catalog/TableLoader.java
+++ b/fe/src/main/java/org/apache/impala/catalog/TableLoader.java
@@ -55,7 +55,7 @@ public class TableLoader {
*/
public Table load(Db db, String tblName) {
String fullTblName = db.getName() + "." + tblName;
- if (LOG.isTraceEnabled()) LOG.trace("Loading metadata for: " + fullTblName);
+ LOG.info("Loading metadata for: " + fullTblName);
Table table;
// turn all exceptions into TableLoadingException
try (MetaStoreClient msClient = catalog_.getMetaStoreClient()) {
@@ -88,12 +88,13 @@ public class TableLoader {
"catalog.");
table = IncompleteTable.createFailedMetadataLoadTable(
db, tblName, tableDoesNotExist);
- } catch (Exception e) {
+ } catch (Throwable e) {
table = IncompleteTable.createFailedMetadataLoadTable(
db, tblName, new TableLoadingException(
"Failed to load metadata for table: " + fullTblName + ". Running " +
"'invalidate metadata " + fullTblName + "' may resolve this problem.", e));
}
+ LOG.info("Loaded metadata for: " + fullTblName);
return table;
}
}
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/3b7a1791/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java b/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java
index d9448b3..208ff2b 100644
--- a/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java
+++ b/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java
@@ -559,7 +559,7 @@ public class CatalogOpExecutor {
/**
* Loads the metadata of a table 'tbl' and assigns a new catalog version.
- * reloadFileMetadata', 'reloadTableSchema', and 'partitionsToUpdate'
+ * 'reloadFileMetadata', 'reloadTableSchema', and 'partitionsToUpdate'
* are used only for HdfsTables and control which metadata to reload.
* Throws a CatalogException if there is an error loading table metadata.
*/
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/3b7a1791/fe/src/main/java/org/apache/impala/service/Frontend.java
----------------------------------------------------------------------
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 eca8d65..1030111 100644
--- a/fe/src/main/java/org/apache/impala/service/Frontend.java
+++ b/fe/src/main/java/org/apache/impala/service/Frontend.java
@@ -887,7 +887,7 @@ public class Frontend {
AnalysisContext analysisCtx = new AnalysisContext(impaladCatalog_, queryCtx,
authzConfig_);
- if (LOG.isTraceEnabled()) LOG.trace("analyze query " + queryCtx.client_request.stmt);
+ LOG.info("Compiling query: " + queryCtx.client_request.stmt);
// Run analysis in a loop until it any of the following events occur:
// 1) Analysis completes successfully.
@@ -909,8 +909,8 @@ public class Frontend {
// Some tables/views were missing, request and wait for them to load.
if (!requestTblLoadAndWait(missingTbls, MISSING_TBL_LOAD_WAIT_TIMEOUT_MS)) {
- if (LOG.isTraceEnabled()) {
- LOG.trace(String.format("Missing tables were not received in %dms. Load " +
+ if (LOG.isWarnEnabled()) {
+ LOG.warn(String.format("Missing tables were not received in %dms. Load " +
"request will be retried.", MISSING_TBL_LOAD_WAIT_TIMEOUT_MS));
}
analysisCtx.getTimeline().markEvent("Metadata load timeout");
@@ -924,6 +924,7 @@ public class Frontend {
// AuthorizationExceptions must take precedence over any AnalysisException
// that has been thrown, so perform the authorization first.
analysisCtx.authorize(getAuthzChecker());
+ LOG.info("Compiled query.");
}
}