IMPALA-5158: Part 1: include untracked memory in MemTracker dumps
The MemTracker dumps are easier to understand if all children of the
process tracker actually add up to the process consumption. There is
always a discrepancy, which corresponds (mostly) to untracked memory.
This commit adds a new line item in the MemTracker dump which is the
process consumption value minus the sum of all its children.
Here is an example of the new output:
Process: Limit=8.35 GB Total=123.74 MB Peak=219.93 MB
Free Disk IO Buffers: Total=1.37 MB Peak=1.37 MB
RequestPool=default-pool: Total=609.09 KB Peak=10.14 MB
Query(fd40f6b7542f7e7c:4aef272300000000): Total=609.09 KB Peak=1.19 MB
Fragment fd40f6b7542f7e7c:4aef272300000000: Total=609.09 KB Peak=1.19 MB
AGGREGATION_NODE (id=3): Total=24.00 KB Peak=36.00 KB
Exprs: Total=4.00 KB Peak=4.00 KB
NESTED_LOOP_JOIN_NODE (id=2): Total=412.90 KB Peak=412.90 KB
Nested Loop Join Builder: Total=392.00 KB Peak=392.00 KB
HDFS_SCAN_NODE (id=1): Total=160.00 KB Peak=768.00 KB
Exprs: Total=4.00 KB Peak=4.00 KB
HDFS_SCAN_NODE (id=0): Total=0 Peak=344.00 KB
PLAN_ROOT_SINK: Total=0 Peak=0
CodeGen: Total=4.19 KB Peak=267.50 KB
Block Manager: Limit=6.68 GB Total=0 Peak=0
RequestPool=fe-eval-exprs: Total=0 Peak=4.00 KB
Untracked Memory: Total=121.78 MB
Change-Id: I77e5b2ef5f85f82ee0226e4dad638233fec9428f
Reviewed-on: http://gerrit.cloudera.org:8080/6820
Reviewed-by: Tim Armstrong <[email protected]>
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/eb7ee677
Tree: http://git-wip-us.apache.org/repos/asf/incubator-impala/tree/eb7ee677
Diff: http://git-wip-us.apache.org/repos/asf/incubator-impala/diff/eb7ee677
Branch: refs/heads/master
Commit: eb7ee67737288e654b4c291b2d726e2f8bc9f107
Parents: ff5b046
Author: Tim Armstrong <[email protected]>
Authored: Mon May 8 15:16:49 2017 -0700
Committer: Impala Public Jenkins <[email protected]>
Committed: Wed May 10 00:05:48 2017 +0000
----------------------------------------------------------------------
be/src/runtime/mem-tracker.cc | 64 ++++++++++++++++++++++++--------------
be/src/runtime/mem-tracker.h | 8 +++--
2 files changed, 47 insertions(+), 25 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/eb7ee677/be/src/runtime/mem-tracker.cc
----------------------------------------------------------------------
diff --git a/be/src/runtime/mem-tracker.cc b/be/src/runtime/mem-tracker.cc
index 4ad9b26..d2dceb3 100644
--- a/be/src/runtime/mem-tracker.cc
+++ b/be/src/runtime/mem-tracker.cc
@@ -131,15 +131,14 @@ int64_t MemTracker::GetPoolMemReserved() const {
int64_t mem_reserved = 0L;
lock_guard<SpinLock> l(child_trackers_lock_);
- for (list<MemTracker*>::const_iterator it = child_trackers_.begin();
- it != child_trackers_.end(); ++it) {
- int64_t child_limit = (*it)->limit();
+ for (MemTracker* child : child_trackers_) {
+ int64_t child_limit = child->limit();
if (child_limit > 0) {
// Make sure we don't overflow if the query limits are set to ridiculous
values.
mem_reserved += std::min(child_limit, MemInfo::physical_mem());
} else {
- DCHECK_EQ(child_limit, -1) << (*it)->LogUsage("");
- mem_reserved += (*it)->consumption();
+ DCHECK_EQ(child_limit, -1) << child->LogUsage("");
+ mem_reserved += child->consumption();
}
}
return mem_reserved;
@@ -237,17 +236,18 @@ void MemTracker::RefreshConsumptionFromMetric() {
// TrackerName: Limit=5.00 MB BufferPoolUsed/Reservation=0/5.00 MB
OtherMemory=1.04 MB
// Total=6.04 MB Peak=6.45 MB
//
-string MemTracker::LogUsage(const string& prefix) const {
- if (!log_usage_if_zero_ && consumption() == 0) return "";
+string MemTracker::LogUsage(const string& prefix, int64_t* logged_consumption)
const {
+ int64_t curr_consumption = consumption();
+ int64_t peak_consumption = consumption_->value();
+ if (logged_consumption != nullptr) *logged_consumption = curr_consumption;
+
+ if (!log_usage_if_zero_ && curr_consumption == 0) return "";
stringstream ss;
ss << prefix << label_ << ":";
if (CheckLimitExceeded()) ss << " memory limit exceeded.";
if (limit_ > 0) ss << " Limit=" << PrettyPrinter::Print(limit_,
TUnit::BYTES);
- int64_t total = consumption();
- int64_t peak = consumption_->value();
-
ReservationTrackerCounters* reservation_counters =
reservation_counters_.Load();
if (reservation_counters != nullptr) {
int64_t reservation =
reservation_counters->peak_reservation->current_value();
@@ -260,26 +260,44 @@ string MemTracker::LogUsage(const string& prefix) const {
if (reservation_limit != numeric_limits<int64_t>::max()) {
ss << " BufferPoolLimit=" << PrettyPrinter::Print(reservation_limit,
TUnit::BYTES);
}
- ss << " OtherMemory=" << PrettyPrinter::Print(total - reservation,
TUnit::BYTES);
+ ss << " OtherMemory="
+ << PrettyPrinter::Print(curr_consumption - reservation, TUnit::BYTES);
+ }
+ ss << " Total=" << PrettyPrinter::Print(curr_consumption, TUnit::BYTES)
+ << " Peak=" << PrettyPrinter::Print(peak_consumption, TUnit::BYTES);
+
+ string new_prefix = Substitute(" $0", prefix);
+ int64_t child_consumption;
+ string child_trackers_usage;
+ {
+ lock_guard<SpinLock> l(child_trackers_lock_);
+ child_trackers_usage = LogUsage(new_prefix, child_trackers_,
&child_consumption);
}
- ss << " Total=" << PrettyPrinter::Print(total, TUnit::BYTES)
- << " Peak=" << PrettyPrinter::Print(peak, TUnit::BYTES);
-
- stringstream prefix_ss;
- prefix_ss << prefix << " ";
- string new_prefix = prefix_ss.str();
- lock_guard<SpinLock> l(child_trackers_lock_);
- string child_trackers_usage = LogUsage(new_prefix, child_trackers_);
if (!child_trackers_usage.empty()) ss << "\n" << child_trackers_usage;
+
+ if (consumption_metric_ != nullptr) {
+ // Log the difference between the metric value and children as "untracked"
memory so
+ // that the values always add up. This value is not always completely
accurate because
+ // we did not necessarily get a consistent snapshot of the consumption
values for all
+ // children at a single moment in time, but is good enough for our
purposes.
+ int64_t untracked_bytes = curr_consumption - child_consumption;
+ ss << "\n"
+ << new_prefix << "Untracked Memory: Total="
+ << PrettyPrinter::Print(untracked_bytes, TUnit::BYTES);
+ }
+
return ss.str();
}
-string MemTracker::LogUsage(const string& prefix, const list<MemTracker*>&
trackers) {
+string MemTracker::LogUsage(const string& prefix, const list<MemTracker*>&
trackers,
+ int64_t* logged_consumption) {
+ *logged_consumption = 0;
vector<string> usage_strings;
- for (list<MemTracker*>::const_iterator it = trackers.begin();
- it != trackers.end(); ++it) {
- string usage_string = (*it)->LogUsage(prefix);
+ for (MemTracker* tracker : trackers) {
+ int64_t tracker_consumption;
+ string usage_string = tracker->LogUsage(prefix, &tracker_consumption);
if (!usage_string.empty()) usage_strings.push_back(usage_string);
+ *logged_consumption += tracker_consumption;
}
return join(usage_strings, "\n");
}
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/eb7ee677/be/src/runtime/mem-tracker.h
----------------------------------------------------------------------
diff --git a/be/src/runtime/mem-tracker.h b/be/src/runtime/mem-tracker.h
index e3282c7..f962fa0 100644
--- a/be/src/runtime/mem-tracker.h
+++ b/be/src/runtime/mem-tracker.h
@@ -311,9 +311,11 @@ class MemTracker {
void RegisterMetrics(MetricGroup* metrics, const std::string& prefix);
/// Logs the usage of this tracker and all of its children (recursively).
+ /// If 'logged_consumption' is non-NULL, sets the consumption value logged.
/// TODO: once all memory is accounted in ReservationTracker hierarchy, move
/// reporting there.
- std::string LogUsage(const std::string& prefix = "") const;
+ std::string LogUsage(
+ const std::string& prefix = "", int64_t* logged_consumption = nullptr)
const;
/// Log the memory usage when memory limit is exceeded and return a status
object with
/// details of the allocation which caused the limit to be exceeded.
@@ -347,8 +349,10 @@ class MemTracker {
/// Adds tracker to child_trackers_
void AddChildTracker(MemTracker* tracker);
+ /// Log consumption of all the trackers provided. Returns the sum of
consumption in
+ /// 'logged_consumption'.
static std::string LogUsage(const std::string& prefix,
- const std::list<MemTracker*>& trackers);
+ const std::list<MemTracker*>& trackers, int64_t* logged_consumption);
/// Size, in bytes, that is considered a large value for Release() (or
Consume() with
/// a negative value). If tcmalloc is used, this can trigger it to GC.
