2021-05-13 22:56:42 +00:00
|
|
|
#include "ProgressIndication.h"
|
2021-10-13 13:26:54 +00:00
|
|
|
#include <algorithm>
|
2021-09-15 15:45:43 +00:00
|
|
|
#include <cstddef>
|
2021-09-14 13:24:57 +00:00
|
|
|
#include <numeric>
|
|
|
|
#include <cmath>
|
2021-04-15 20:39:39 +00:00
|
|
|
#include <IO/WriteBufferFromFileDescriptor.h>
|
2021-09-14 13:24:57 +00:00
|
|
|
#include <base/types.h>
|
2021-10-13 13:26:54 +00:00
|
|
|
#include "Common/formatReadable.h"
|
2021-04-15 20:39:39 +00:00
|
|
|
#include <Common/TerminalSize.h>
|
|
|
|
#include <Common/UnicodeBar.h>
|
2021-10-12 20:17:15 +00:00
|
|
|
#include "IO/WriteBufferFromString.h"
|
2021-04-15 20:39:39 +00:00
|
|
|
#include <Databases/DatabaseMemory.h>
|
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
|
2021-09-15 15:45:43 +00:00
|
|
|
namespace
|
|
|
|
{
|
2021-10-26 07:00:19 +00:00
|
|
|
constexpr UInt64 ALL_THREADS = 0;
|
2021-09-17 15:00:13 +00:00
|
|
|
|
2021-12-28 22:20:34 +00:00
|
|
|
double calculateCPUUsage(DB::ThreadIdToTimeMap times, UInt64 elapsed)
|
2021-09-17 15:00:13 +00:00
|
|
|
{
|
2021-11-08 13:38:31 +00:00
|
|
|
auto accumulated = std::accumulate(times.begin(), times.end(), 0,
|
|
|
|
[](Int64 acc, const auto & elem)
|
|
|
|
{
|
|
|
|
if (elem.first == ALL_THREADS)
|
|
|
|
return acc;
|
|
|
|
return acc + elem.second.time();
|
|
|
|
});
|
2021-12-28 22:20:34 +00:00
|
|
|
return static_cast<double>(accumulated) / elapsed;
|
2021-09-17 15:00:13 +00:00
|
|
|
}
|
2021-09-15 15:45:43 +00:00
|
|
|
}
|
|
|
|
|
2021-04-17 12:37:48 +00:00
|
|
|
namespace DB
|
|
|
|
{
|
2021-04-17 22:02:06 +00:00
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
bool ProgressIndication::updateProgress(const Progress & value)
|
2021-04-15 20:39:39 +00:00
|
|
|
{
|
2021-04-16 14:37:46 +00:00
|
|
|
return progress.incrementPiecewiseAtomically(value);
|
2021-04-15 20:39:39 +00:00
|
|
|
}
|
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
void ProgressIndication::clearProgressOutput()
|
|
|
|
{
|
|
|
|
if (written_progress_chars)
|
|
|
|
{
|
|
|
|
written_progress_chars = 0;
|
|
|
|
std::cerr << "\r" CLEAR_TO_END_OF_LINE;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
void ProgressIndication::resetProgress()
|
2021-04-17 13:26:58 +00:00
|
|
|
{
|
2021-05-13 22:56:42 +00:00
|
|
|
watch.restart();
|
|
|
|
progress.reset();
|
|
|
|
show_progress_bar = false;
|
|
|
|
written_progress_chars = 0;
|
2021-05-14 08:35:51 +00:00
|
|
|
write_progress_on_update = false;
|
2021-12-28 22:20:34 +00:00
|
|
|
host_cpu_usage.clear();
|
2021-09-17 16:47:54 +00:00
|
|
|
thread_data.clear();
|
2021-05-13 22:56:42 +00:00
|
|
|
}
|
|
|
|
|
2021-06-01 07:56:20 +00:00
|
|
|
void ProgressIndication::setFileProgressCallback(ContextMutablePtr context, bool write_progress_on_update_)
|
2021-05-13 22:56:42 +00:00
|
|
|
{
|
2021-05-14 08:35:51 +00:00
|
|
|
write_progress_on_update = write_progress_on_update_;
|
2021-05-13 22:56:42 +00:00
|
|
|
context->setFileProgressCallback([&](const FileProgress & file_progress)
|
|
|
|
{
|
|
|
|
progress.incrementPiecewiseAtomically(Progress(file_progress));
|
|
|
|
|
|
|
|
if (write_progress_on_update)
|
|
|
|
writeProgress();
|
|
|
|
});
|
|
|
|
}
|
|
|
|
|
2021-09-15 15:45:43 +00:00
|
|
|
void ProgressIndication::addThreadIdToList(String const & host, UInt64 thread_id)
|
2021-09-14 11:06:00 +00:00
|
|
|
{
|
2021-09-17 16:47:54 +00:00
|
|
|
auto & thread_to_times = thread_data[host];
|
2021-09-15 15:45:43 +00:00
|
|
|
if (thread_to_times.contains(thread_id))
|
2021-09-14 13:24:57 +00:00
|
|
|
return;
|
2021-09-15 15:45:43 +00:00
|
|
|
thread_to_times[thread_id] = {};
|
|
|
|
}
|
|
|
|
|
2021-11-08 13:38:31 +00:00
|
|
|
void ProgressIndication::updateThreadEventData(HostToThreadTimesMap & new_thread_data, UInt64 elapsed_time)
|
2021-09-14 13:24:57 +00:00
|
|
|
{
|
2021-09-17 16:47:54 +00:00
|
|
|
for (auto & new_host_map : new_thread_data)
|
2021-09-17 15:00:13 +00:00
|
|
|
{
|
2021-12-28 22:20:34 +00:00
|
|
|
host_cpu_usage[new_host_map.first] = calculateCPUUsage(new_host_map.second, elapsed_time);
|
2021-11-08 13:38:31 +00:00
|
|
|
thread_data[new_host_map.first] = std::move(new_host_map.second);
|
2021-09-17 15:00:13 +00:00
|
|
|
}
|
2021-09-14 13:24:57 +00:00
|
|
|
}
|
|
|
|
|
2021-09-15 15:45:43 +00:00
|
|
|
size_t ProgressIndication::getUsedThreadsCount() const
|
2021-09-14 13:24:57 +00:00
|
|
|
{
|
2021-09-17 16:47:54 +00:00
|
|
|
return std::accumulate(thread_data.cbegin(), thread_data.cend(), 0,
|
2021-09-15 15:45:43 +00:00
|
|
|
[] (size_t acc, auto const & threads)
|
|
|
|
{
|
|
|
|
return acc + threads.second.size();
|
|
|
|
});
|
2021-09-14 13:24:57 +00:00
|
|
|
}
|
|
|
|
|
2021-12-28 22:20:34 +00:00
|
|
|
double ProgressIndication::getCPUUsage() const
|
2021-09-14 13:24:57 +00:00
|
|
|
{
|
2021-12-28 22:20:34 +00:00
|
|
|
double res = 0;
|
|
|
|
for (const auto & elem : host_cpu_usage)
|
|
|
|
res += elem.second;
|
|
|
|
return res;
|
2021-09-14 11:06:00 +00:00
|
|
|
}
|
|
|
|
|
2021-10-13 13:26:54 +00:00
|
|
|
ProgressIndication::MemoryUsage ProgressIndication::getMemoryUsage() const
|
2021-09-17 16:47:54 +00:00
|
|
|
{
|
2021-10-13 13:26:54 +00:00
|
|
|
return std::accumulate(thread_data.cbegin(), thread_data.cend(), MemoryUsage{},
|
|
|
|
[](MemoryUsage const & acc, auto const & host_data)
|
2021-09-17 16:47:54 +00:00
|
|
|
{
|
2021-10-18 14:49:26 +00:00
|
|
|
UInt64 host_usage = 0;
|
2021-10-25 13:53:23 +00:00
|
|
|
// In ProfileEvents packets thread id 0 specifies common profiling information
|
|
|
|
// for all threads executing current query on specific host. So instead of summing per thread
|
|
|
|
// memory consumption it's enough to look for data with thread id 0.
|
2021-10-26 07:00:19 +00:00
|
|
|
if (auto it = host_data.second.find(ALL_THREADS); it != host_data.second.end())
|
2021-10-18 14:49:26 +00:00
|
|
|
host_usage = it->second.memory_usage;
|
2021-12-28 22:20:34 +00:00
|
|
|
|
2021-10-14 15:15:30 +00:00
|
|
|
return MemoryUsage{.total = acc.total + host_usage, .max = std::max(acc.max, host_usage)};
|
2021-09-17 16:47:54 +00:00
|
|
|
});
|
|
|
|
}
|
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
void ProgressIndication::writeFinalProgress()
|
|
|
|
{
|
|
|
|
if (progress.read_rows < 1000)
|
2021-04-15 20:39:39 +00:00
|
|
|
return;
|
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
std::cout << "Processed " << formatReadableQuantity(progress.read_rows) << " rows, "
|
|
|
|
<< formatReadableSizeWithDecimalSuffix(progress.read_bytes);
|
|
|
|
|
2021-05-16 20:47:19 +00:00
|
|
|
size_t elapsed_ns = watch.elapsed();
|
2021-05-13 22:56:42 +00:00
|
|
|
if (elapsed_ns)
|
|
|
|
std::cout << " (" << formatReadableQuantity(progress.read_rows * 1000000000.0 / elapsed_ns) << " rows/s., "
|
2021-05-16 20:47:19 +00:00
|
|
|
<< formatReadableSizeWithDecimalSuffix(progress.read_bytes * 1000000000.0 / elapsed_ns) << "/s.)";
|
2021-05-13 22:56:42 +00:00
|
|
|
else
|
|
|
|
std::cout << ". ";
|
|
|
|
}
|
|
|
|
|
|
|
|
void ProgressIndication::writeProgress()
|
|
|
|
{
|
2021-04-15 20:39:39 +00:00
|
|
|
/// Output all progress bar commands to stderr at once to avoid flicker.
|
|
|
|
WriteBufferFromFileDescriptor message(STDERR_FILENO, 1024);
|
|
|
|
|
|
|
|
static size_t increment = 0;
|
|
|
|
static const char * indicators[8] = {
|
|
|
|
"\033[1;30m→\033[0m",
|
|
|
|
"\033[1;31m↘\033[0m",
|
|
|
|
"\033[1;32m↓\033[0m",
|
|
|
|
"\033[1;33m↙\033[0m",
|
|
|
|
"\033[1;34m←\033[0m",
|
|
|
|
"\033[1;35m↖\033[0m",
|
|
|
|
"\033[1;36m↑\033[0m",
|
|
|
|
"\033[1m↗\033[0m",
|
|
|
|
};
|
|
|
|
|
|
|
|
const char * indicator = indicators[increment % 8];
|
|
|
|
|
|
|
|
size_t terminal_width = getTerminalWidth();
|
|
|
|
|
|
|
|
if (!written_progress_chars)
|
|
|
|
{
|
|
|
|
/// If the current line is not empty, the progress must be output on the next line.
|
|
|
|
/// The trick is found here: https://www.vidarholen.net/contents/blog/?p=878
|
|
|
|
message << std::string(terminal_width, ' ');
|
|
|
|
}
|
|
|
|
message << '\r';
|
|
|
|
|
|
|
|
size_t prefix_size = message.count();
|
2021-05-13 22:56:42 +00:00
|
|
|
size_t read_bytes = progress.read_raw_bytes ? progress.read_raw_bytes : progress.read_bytes;
|
2021-04-15 20:39:39 +00:00
|
|
|
|
|
|
|
message << indicator << " Progress: ";
|
|
|
|
message
|
|
|
|
<< formatReadableQuantity(progress.read_rows) << " rows, "
|
2021-05-13 22:56:42 +00:00
|
|
|
<< formatReadableSizeWithDecimalSuffix(read_bytes);
|
2021-04-15 20:39:39 +00:00
|
|
|
|
2021-05-13 22:56:42 +00:00
|
|
|
auto elapsed_ns = watch.elapsed();
|
2021-04-15 20:39:39 +00:00
|
|
|
if (elapsed_ns)
|
|
|
|
message << " ("
|
|
|
|
<< formatReadableQuantity(progress.read_rows * 1000000000.0 / elapsed_ns) << " rows/s., "
|
2021-05-13 22:56:42 +00:00
|
|
|
<< formatReadableSizeWithDecimalSuffix(read_bytes * 1000000000.0 / elapsed_ns) << "/s.) ";
|
2021-04-15 20:39:39 +00:00
|
|
|
else
|
|
|
|
message << ". ";
|
|
|
|
|
|
|
|
written_progress_chars = message.count() - prefix_size - (strlen(indicator) - 2); /// Don't count invisible output (escape sequences).
|
|
|
|
|
2021-12-28 22:26:58 +00:00
|
|
|
/// Display resource usage if possible.
|
2021-10-12 20:17:15 +00:00
|
|
|
std::string profiling_msg;
|
2021-12-28 22:20:34 +00:00
|
|
|
|
|
|
|
double cpu_usage = getCPUUsage();
|
2021-12-28 22:26:58 +00:00
|
|
|
auto [memory_usage, max_host_usage] = getMemoryUsage();
|
|
|
|
|
|
|
|
if (cpu_usage > 0 || memory_usage > 0)
|
2021-10-12 20:17:15 +00:00
|
|
|
{
|
|
|
|
WriteBufferFromOwnString profiling_msg_builder;
|
2021-12-28 22:20:34 +00:00
|
|
|
|
|
|
|
profiling_msg_builder << "(" << fmt::format("{:.1f}", cpu_usage) << " CPU";
|
2021-10-12 20:17:15 +00:00
|
|
|
|
2021-12-28 22:26:58 +00:00
|
|
|
if (memory_usage > 0)
|
2021-12-28 22:20:34 +00:00
|
|
|
profiling_msg_builder << ", " << formatReadableSizeWithDecimalSuffix(memory_usage) << " RAM";
|
|
|
|
if (max_host_usage < memory_usage)
|
|
|
|
profiling_msg_builder << ", " << formatReadableSizeWithDecimalSuffix(max_host_usage) << " max/host";
|
|
|
|
|
|
|
|
profiling_msg_builder << ")";
|
2021-10-12 20:17:15 +00:00
|
|
|
profiling_msg = profiling_msg_builder.str();
|
|
|
|
}
|
|
|
|
|
2021-12-28 22:20:34 +00:00
|
|
|
int64_t remaining_space = static_cast<int64_t>(terminal_width) - written_progress_chars;
|
|
|
|
|
2021-04-15 20:39:39 +00:00
|
|
|
/// If the approximate number of rows to process is known, we can display a progress bar and percentage.
|
2021-05-13 22:56:42 +00:00
|
|
|
if (progress.total_rows_to_read || progress.total_raw_bytes_to_read)
|
2021-04-15 20:39:39 +00:00
|
|
|
{
|
2021-05-13 22:56:42 +00:00
|
|
|
size_t current_count, max_count;
|
|
|
|
if (progress.total_rows_to_read)
|
|
|
|
{
|
|
|
|
current_count = progress.read_rows;
|
|
|
|
max_count = std::max(progress.read_rows, progress.total_rows_to_read);
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
current_count = progress.read_raw_bytes;
|
|
|
|
max_count = std::max(progress.read_raw_bytes, progress.total_raw_bytes_to_read);
|
|
|
|
}
|
2021-04-15 20:39:39 +00:00
|
|
|
|
|
|
|
/// To avoid flicker, display progress bar only if .5 seconds have passed since query execution start
|
|
|
|
/// and the query is less than halfway done.
|
|
|
|
|
|
|
|
if (elapsed_ns > 500000000)
|
|
|
|
{
|
|
|
|
/// Trigger to start displaying progress bar. If query is mostly done, don't display it.
|
2021-05-13 22:56:42 +00:00
|
|
|
if (current_count * 2 < max_count)
|
2021-04-15 20:39:39 +00:00
|
|
|
show_progress_bar = true;
|
|
|
|
|
|
|
|
if (show_progress_bar)
|
|
|
|
{
|
2021-12-28 22:20:34 +00:00
|
|
|
/// We will display profiling info only if there is enough space for it.
|
|
|
|
int64_t width_of_progress_bar = remaining_space - strlen(" 99%");
|
|
|
|
|
|
|
|
/// We need at least twice the space, because it will be displayed either
|
|
|
|
/// at right after progress bar or at left on top of the progress bar.
|
|
|
|
if (width_of_progress_bar <= 1 + 2 * static_cast<int64_t>(profiling_msg.size()))
|
|
|
|
profiling_msg.clear();
|
|
|
|
|
2021-04-15 20:39:39 +00:00
|
|
|
if (width_of_progress_bar > 0)
|
|
|
|
{
|
2022-02-03 01:48:52 +00:00
|
|
|
double bar_width = UnicodeBar::getWidth(current_count, 0, max_count, width_of_progress_bar);
|
2021-12-28 22:20:34 +00:00
|
|
|
std::string bar = UnicodeBar::render(bar_width);
|
2022-02-22 00:32:23 +00:00
|
|
|
size_t bar_width_in_terminal = bar.size() / UNICODE_BAR_CHAR_SIZE;
|
2022-02-20 23:25:07 +00:00
|
|
|
|
2022-02-20 18:29:09 +00:00
|
|
|
if (profiling_msg.empty())
|
|
|
|
{
|
2022-02-22 00:32:23 +00:00
|
|
|
message << "\033[0;32m" << bar << "\033[0m"
|
|
|
|
<< std::string(width_of_progress_bar - bar_width_in_terminal, ' ');
|
2022-02-20 18:29:09 +00:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
bool render_profiling_msg_at_left = current_count * 2 >= max_count;
|
|
|
|
|
|
|
|
if (render_profiling_msg_at_left)
|
|
|
|
{
|
|
|
|
/// Render profiling_msg at left on top of the progress bar.
|
|
|
|
|
|
|
|
message << "\033[30;42m" << profiling_msg << "\033[0m"
|
2022-02-22 00:32:23 +00:00
|
|
|
<< "\033[0;32m" << bar.substr(profiling_msg.size() * UNICODE_BAR_CHAR_SIZE) << "\033[0m"
|
|
|
|
<< std::string(width_of_progress_bar - bar_width_in_terminal, ' ');
|
2022-02-20 18:29:09 +00:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
/// Render profiling_msg at right after the progress bar.
|
|
|
|
|
2022-02-20 23:25:07 +00:00
|
|
|
message << "\033[0;32m" << bar << "\033[0m"
|
2022-02-22 00:32:23 +00:00
|
|
|
<< std::string(width_of_progress_bar - bar_width_in_terminal - profiling_msg.size(), ' ')
|
|
|
|
<< "\033[2m" << profiling_msg << "\033[0m";
|
2022-02-20 18:29:09 +00:00
|
|
|
}
|
|
|
|
}
|
2021-04-15 20:39:39 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
/// Underestimate percentage a bit to avoid displaying 100%.
|
2021-05-13 22:56:42 +00:00
|
|
|
message << ' ' << (99 * current_count / max_count) << '%';
|
2021-04-15 20:39:39 +00:00
|
|
|
}
|
2021-12-28 22:20:34 +00:00
|
|
|
else
|
|
|
|
{
|
|
|
|
/// We can still display profiling info.
|
|
|
|
if (remaining_space >= static_cast<int64_t>(profiling_msg.size()))
|
|
|
|
{
|
|
|
|
if (remaining_space > static_cast<int64_t>(profiling_msg.size()))
|
|
|
|
message << std::string(remaining_space - profiling_msg.size(), ' ');
|
|
|
|
message << "\033[2m" << profiling_msg << "\033[0m";
|
|
|
|
}
|
|
|
|
}
|
2021-04-15 20:39:39 +00:00
|
|
|
|
|
|
|
message << CLEAR_TO_END_OF_LINE;
|
|
|
|
++increment;
|
|
|
|
|
|
|
|
message.next();
|
|
|
|
}
|
2021-04-17 22:02:06 +00:00
|
|
|
|
2021-04-16 14:12:21 +00:00
|
|
|
}
|