Repository: incubator-quickstep Updated Branches: refs/heads/LIP-time-decomposition e92cacd29 -> 12f0a8ec1 (forced update)
Profiling LIP build/probe for execution time decomposition Project: http://git-wip-us.apache.org/repos/asf/incubator-quickstep/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-quickstep/commit/12f0a8ec Tree: http://git-wip-us.apache.org/repos/asf/incubator-quickstep/tree/12f0a8ec Diff: http://git-wip-us.apache.org/repos/asf/incubator-quickstep/diff/12f0a8ec Branch: refs/heads/LIP-time-decomposition Commit: 12f0a8ec1801ed0b671ca4a6a0e96107bf68135f Parents: 3047d89 Author: Jianqiao Zhu <jianq...@cs.wisc.edu> Authored: Tue Nov 22 16:45:25 2016 -0600 Committer: Jianqiao Zhu <jianq...@cs.wisc.edu> Committed: Tue Dec 6 12:52:16 2016 -0600 ---------------------------------------------------------------------- cli/QuickstepCli.cpp | 15 ++ relational_operators/BuildHashOperator.cpp | 9 + relational_operators/CMakeLists.txt | 2 + relational_operators/HashJoinOperator.cpp | 8 +- utility/CMakeLists.txt | 4 + utility/EventProfiler.cpp | 30 ++++ utility/EventProfiler.hpp | 190 ++++++++++++++++++++ utility/lip_filter/LIPFilterAdaptiveProber.hpp | 10 +- 8 files changed, 265 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/cli/QuickstepCli.cpp ---------------------------------------------------------------------- diff --git a/cli/QuickstepCli.cpp b/cli/QuickstepCli.cpp index f4816a8..4082f64 100644 --- a/cli/QuickstepCli.cpp +++ b/cli/QuickstepCli.cpp @@ -23,6 +23,7 @@ #include <cstddef> #include <cstdio> #include <exception> +#include <fstream> #include <memory> #include <string> #include <utility> @@ -68,6 +69,7 @@ typedef quickstep::LineReaderDumb LineReaderImpl; #include "storage/StorageConstants.hpp" #include "storage/StorageManager.hpp" #include "threading/ThreadIDBasedMap.hpp" +#include "utility/EventProfiler.hpp" #include "utility/ExecutionDAGVisualizer.hpp" #include "utility/Macros.hpp" #include "utility/PtrVector.hpp" @@ -155,6 +157,8 @@ DEFINE_string(profile_file_name, "", // To put things in perspective, the first run is, in my experiments, about 5-10 // times more expensive than the average run. That means the query needs to be // run at least a hundred times to make the impact of the first run small (< 5 %). +DEFINE_string(profile_output, "", + "Output file name for dumping the profiled events."); DECLARE_bool(profile_and_report_workorder_perf); DECLARE_bool(visualize_execution_dag); @@ -361,6 +365,9 @@ int main(int argc, char* argv[]) { } start = std::chrono::steady_clock::now(); + quickstep::simple_profiler.clear(); + auto *event_container = quickstep::simple_profiler.getContainer(); + event_container->startEvent("overall"); QueryExecutionUtil::ConstructAndSendAdmitRequestMessage( main_thread_client_id, foreman.getBusClientID(), @@ -370,6 +377,7 @@ int main(int argc, char* argv[]) { try { QueryExecutionUtil::ReceiveQueryCompletionMessage( main_thread_client_id, &bus); + event_container->endEvent("overall"); end = std::chrono::steady_clock::now(); const CatalogRelation *query_result_relation = query_handle->getQueryResultRelation(); @@ -403,6 +411,13 @@ int main(int argc, char* argv[]) { dag_visualizer->bindProfilingStats(profiling_stats); std::cerr << "\n" << dag_visualizer->toDOT() << "\n"; } + if (!quickstep::FLAGS_profile_output.empty()) { + std::ofstream ofs( + quickstep::FLAGS_profile_output + std::to_string(query_processor->query_id()), + std::ios::out); + quickstep::simple_profiler.writeToStream(ofs); + ofs.close(); + } } catch (const std::exception &e) { fprintf(stderr, "QUERY EXECUTION ERROR: %s\n", e.what()); break; http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/relational_operators/BuildHashOperator.cpp ---------------------------------------------------------------------- diff --git a/relational_operators/BuildHashOperator.cpp b/relational_operators/BuildHashOperator.cpp index 60e091f..e76e350 100644 --- a/relational_operators/BuildHashOperator.cpp +++ b/relational_operators/BuildHashOperator.cpp @@ -34,6 +34,7 @@ #include "storage/TupleReference.hpp" #include "storage/TupleStorageSubBlock.hpp" #include "storage/ValueAccessor.hpp" +#include "utility/EventProfiler.hpp" #include "utility/lip_filter/LIPFilterBuilder.hpp" #include "utility/lip_filter/LIPFilterUtil.hpp" @@ -152,12 +153,19 @@ void BuildHashWorkOrder::execute() { TupleReferenceGenerator generator(build_block_id_); std::unique_ptr<ValueAccessor> accessor(block->getTupleStorageSubBlock().createValueAccessor()); + auto *container = simple_profiler.getContainer(); + // Build LIPFilters if enabled. if (lip_filter_builder_ != nullptr) { + auto *event_lip = container->getEventLine("BuildLIP"); + event_lip->emplace_back(); lip_filter_builder_->insertValueAccessor(accessor.get()); accessor->beginIterationVirtual(); + event_lip->back().endEvent(); } + auto *event_hash = container->getEventLine("BuildHash"); + event_hash->emplace_back(); HashTablePutResult result; if (join_key_attributes_.size() == 1) { result = hash_table_->putValueAccessor(accessor.get(), @@ -170,6 +178,7 @@ void BuildHashWorkOrder::execute() { any_join_key_attributes_nullable_, &generator); } + event_hash->back().endEvent(); CHECK(result == HashTablePutResult::kOK) << "Failed to add entries to join hash table."; http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/relational_operators/CMakeLists.txt ---------------------------------------------------------------------- diff --git a/relational_operators/CMakeLists.txt b/relational_operators/CMakeLists.txt index 0735bce..4cfbcd8 100644 --- a/relational_operators/CMakeLists.txt +++ b/relational_operators/CMakeLists.txt @@ -112,6 +112,7 @@ target_link_libraries(quickstep_relationaloperators_BuildHashOperator quickstep_storage_TupleReference quickstep_storage_TupleStorageSubBlock quickstep_storage_ValueAccessor + quickstep_utility_EventProfiler quickstep_utility_Macros quickstep_utility_lipfilter_LIPFilterBuilder quickstep_utility_lipfilter_LIPFilterUtil @@ -226,6 +227,7 @@ target_link_libraries(quickstep_relationaloperators_HashJoinOperator quickstep_types_TypedValue quickstep_types_containers_ColumnVector quickstep_types_containers_ColumnVectorsValueAccessor + quickstep_utility_EventProfiler quickstep_utility_Macros quickstep_utility_lipfilter_LIPFilterAdaptiveProber quickstep_utility_lipfilter_LIPFilterUtil http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/relational_operators/HashJoinOperator.cpp ---------------------------------------------------------------------- diff --git a/relational_operators/HashJoinOperator.cpp b/relational_operators/HashJoinOperator.cpp index 2028046..ef7fbaa 100644 --- a/relational_operators/HashJoinOperator.cpp +++ b/relational_operators/HashJoinOperator.cpp @@ -48,6 +48,7 @@ #include "types/TypedValue.hpp" #include "types/containers/ColumnVector.hpp" #include "types/containers/ColumnVectorsValueAccessor.hpp" +#include "utility/EventProfiler.hpp" #include "utility/lip_filter/LIPFilterAdaptiveProber.hpp" #include "utility/lip_filter/LIPFilterUtil.hpp" @@ -461,6 +462,10 @@ void HashInnerJoinWorkOrder::execute() { base_accessor->createSharedTupleIdSequenceAdapterVirtual(*existence_map)); } + auto *container = simple_profiler.getContainer(); + auto *event_hash = container->getEventLine("ProbeHash"); + event_hash->emplace_back(); + PairsOfVectorsJoinedTuplesCollector collector; if (join_key_attributes_.size() == 1) { hash_table_.getAllFromValueAccessor( @@ -560,7 +565,6 @@ void HashInnerJoinWorkOrder::execute() { }); } - // We also need a temp value accessor to store results of any scalar expressions. ColumnVectorsValueAccessor temp_result; @@ -622,6 +626,8 @@ void HashInnerJoinWorkOrder::execute() { // of this loop, but that would get messy when combined with partitioning. output_destination_->bulkInsertTuplesFromValueAccessors(accessor_attribute_map); } + + event_hash->back().endEvent(); } void HashSemiJoinWorkOrder::execute() { http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/utility/CMakeLists.txt ---------------------------------------------------------------------- diff --git a/utility/CMakeLists.txt b/utility/CMakeLists.txt index 6a656fb..a3b4d3f 100644 --- a/utility/CMakeLists.txt +++ b/utility/CMakeLists.txt @@ -179,6 +179,7 @@ add_library(quickstep_utility_CompositeHash ../empty_src.cpp CompositeHash.hpp) add_library(quickstep_utility_DAG ../empty_src.cpp DAG.hpp) add_library(quickstep_utility_DisjointTreeForest ../empty_src.cpp DisjointTreeForest.hpp) add_library(quickstep_utility_EqualsAnyConstant ../empty_src.cpp EqualsAnyConstant.hpp) +add_library(quickstep_utility_EventProfiler EventProfiler.cpp EventProfiler.hpp) add_library(quickstep_utility_ExecutionDAGVisualizer ExecutionDAGVisualizer.cpp ExecutionDAGVisualizer.hpp) @@ -247,6 +248,8 @@ target_link_libraries(quickstep_utility_DAG quickstep_utility_Macros) target_link_libraries(quickstep_utility_DisjointTreeForest glog) +target_link_libraries(quickstep_utility_EventProfiler + quickstep_threading_Mutex) target_link_libraries(quickstep_utility_ExecutionDAGVisualizer quickstep_catalog_CatalogRelationSchema quickstep_queryexecution_QueryExecutionTypedefs @@ -344,6 +347,7 @@ target_link_libraries(quickstep_utility quickstep_utility_DAG quickstep_utility_DisjointTreeForest quickstep_utility_EqualsAnyConstant + quickstep_utility_EventProfiler quickstep_utility_ExecutionDAGVisualizer quickstep_utility_Glob quickstep_utility_HashPair http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/utility/EventProfiler.cpp ---------------------------------------------------------------------- diff --git a/utility/EventProfiler.cpp b/utility/EventProfiler.cpp new file mode 100644 index 0000000..cf89cb9 --- /dev/null +++ b/utility/EventProfiler.cpp @@ -0,0 +1,30 @@ +/** + * 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. + **/ + +#include "utility/EventProfiler.hpp" + +#include <cstddef> +#include <string> +#include <vector> + +namespace quickstep { + +EventProfiler<std::string> simple_profiler; + +} // namespace quickstep http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/utility/EventProfiler.hpp ---------------------------------------------------------------------- diff --git a/utility/EventProfiler.hpp b/utility/EventProfiler.hpp new file mode 100644 index 0000000..c28f49b --- /dev/null +++ b/utility/EventProfiler.hpp @@ -0,0 +1,190 @@ +/** + * 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. + **/ + +#ifndef QUICKSTEP_UTILITY_EVENT_PROFILER_HPP_ +#define QUICKSTEP_UTILITY_EVENT_PROFILER_HPP_ + +#include <chrono> +#include <cstddef> +#include <cstring> +#include <ctime> +#include <iomanip> +#include <map> +#include <ostream> +#include <thread> +#include <type_traits> +#include <utility> +#include <vector> + +#include "threading/Mutex.hpp" + +#include "glog/logging.h" + +namespace quickstep { + +/** \addtogroup Utility + * @{ + */ + +using clock = std::chrono::steady_clock; + +template <typename TagT, typename ...PayloadT> +class EventProfiler { + + public: + EventProfiler() + : zero_time_(clock::now()) { + } + + struct EventInfo { + clock::time_point start_time; + clock::time_point end_time; + bool is_finished; + std::tuple<PayloadT...> payload; + + explicit EventInfo(const clock::time_point &start_time_in) + : start_time(start_time_in), + is_finished(false) { + } + + EventInfo() + : start_time(clock::now()), + is_finished(false) { + } + + inline void setPayload(PayloadT &&...in_payload) { + payload = std::make_tuple(in_payload...); + } + + inline void endEvent() { + end_time = clock::now(); + is_finished = true; + } + }; + + struct EventContainer { + EventContainer() + : context(0) {} + + inline void startEvent(const TagT &tag) { + events[tag].emplace_back(clock::now()); + } + + inline void endEvent(const TagT &tag) { + auto &event_info = events.at(tag).back(); + event_info.is_finished = true; + event_info.end_time = clock::now(); + } + + inline std::vector<EventInfo> *getEventLine(const TagT &tag) { + return &events[tag]; + } + + inline void setContext(int context_in) { + context = context_in; + } + + inline int getContext() const { + return context; + } + + std::map<TagT, std::vector<EventInfo>> events; + int context; + }; + + EventContainer *getContainer() { + MutexLock lock(mutex_); + return &thread_map_[std::this_thread::get_id()]; + } + + void writeToStream(std::ostream &os) const { + time_t rawtime; + time(&rawtime); + char event_id[32]; + strftime(event_id, sizeof event_id, "%Y-%m-%d %H:%M:%S", localtime(&rawtime)); + + int thread_id = 0; + for (const auto &thread_ctx : thread_map_) { + for (const auto &event_group : thread_ctx.second.events) { + for (const auto &event_info : event_group.second) { + CHECK(event_info.is_finished) + << "Unfinished profiling event at thread " << thread_id + << ": " << event_group.first; + + os << std::setprecision(12) + << event_id << "," + << thread_id << "," << event_group.first << ","; + + PrintTuple(os, event_info.payload, ","); + + os << std::chrono::duration<double>(event_info.start_time - zero_time_).count() + << "," + << std::chrono::duration<double>(event_info.end_time - zero_time_).count() + << "\n"; + } + } + ++thread_id; + } + } + + void clear() { + zero_time_ = clock::now(); + thread_map_.clear(); + } + + const std::map<std::thread::id, EventContainer> &containers() { + return thread_map_; + } + + const clock::time_point &zero_time() { + return zero_time_; + } + + private: + template<class Tuple, std::size_t N> + struct TuplePrinter { + static void Print(std::ostream &os, const Tuple &t, const std::string &sep) { + TuplePrinter<Tuple, N-1>::Print(os, t, sep); + os << std::get<N-1>(t) << sep; + } + }; + + template<class Tuple> + struct TuplePrinter<Tuple, 0> { + static void Print(std::ostream &os, const Tuple &t, const std::string &sep) { + } + }; + + template<class... Args> + static void PrintTuple(std::ostream &os, const std::tuple<Args...>& t, const std::string &sep) { + TuplePrinter<decltype(t), sizeof...(Args)>::Print(os, t, sep); + } + + clock::time_point zero_time_; + std::map<std::thread::id, EventContainer> thread_map_; + Mutex mutex_; +}; + +extern EventProfiler<std::string> simple_profiler; + +/** @} */ + +} // namespace quickstep + +#endif // QUICKSTEP_UTILITY_EVENT_PROFILER_HPP_ http://git-wip-us.apache.org/repos/asf/incubator-quickstep/blob/12f0a8ec/utility/lip_filter/LIPFilterAdaptiveProber.hpp ---------------------------------------------------------------------- diff --git a/utility/lip_filter/LIPFilterAdaptiveProber.hpp b/utility/lip_filter/LIPFilterAdaptiveProber.hpp index e1a75d6..b2f498f 100644 --- a/utility/lip_filter/LIPFilterAdaptiveProber.hpp +++ b/utility/lip_filter/LIPFilterAdaptiveProber.hpp @@ -31,6 +31,7 @@ #include "storage/TupleIdSequence.hpp" #include "storage/ValueAccessor.hpp" #include "types/Type.hpp" +#include "utility/EventProfiler.hpp" #include "utility/Macros.hpp" #include "utility/lip_filter/LIPFilter.hpp" @@ -87,12 +88,17 @@ class LIPFilterAdaptiveProber { * @return A TupleIdSequence for the hit tuples in the ValueAccessor. */ TupleIdSequence* filterValueAccessor(ValueAccessor *accessor) { + TupleIdSequence *matches; const TupleIdSequence *existence_map = accessor->getTupleIdSequenceVirtual(); + auto *event_lip = simple_profiler.getContainer()->getEventLine("ProbeLIP"); + event_lip->emplace_back(); if (existence_map == nullptr) { - return filterValueAccessorNoExistenceMap(accessor); + matches = filterValueAccessorNoExistenceMap(accessor); } else { - return filterValueAccessorWithExistenceMap(accessor, existence_map); + matches = filterValueAccessorWithExistenceMap(accessor, existence_map); } + event_lip->back().endEvent(); + return matches; } private:
