Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add high-precision timestamp to trace_log #9696

Merged
merged 1 commit into from
Mar 17, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
24 changes: 23 additions & 1 deletion dbms/programs/server/clickhouse-server.cpp
Original file line number Diff line number Diff line change
@@ -1,2 +1,24 @@
#include <new>

#include <common/phdr_cache.h>


int mainEntryClickHouseServer(int argc, char ** argv);
int main(int argc_, char ** argv_) { return mainEntryClickHouseServer(argc_, argv_); }

/**
* This is the entry-point for the split build server. The initialization
* is copied from single-binary entry point in main.cpp.
*/
int main(int argc_, char ** argv_)
{
/// Reset new handler to default (that throws std::bad_alloc)
/// It is needed because LLVM library clobbers it.
std::set_new_handler(nullptr);

/// PHDR cache is required for query profiler to work reliably
/// It also speed up exception handling, but exceptions from dynamically loaded libraries (dlopen)
/// will work only after additional call of this function.
updatePHDRCache();

return mainEntryClickHouseServer(argc_, argv_);
}
15 changes: 6 additions & 9 deletions dbms/src/Common/Stopwatch.h
Original file line number Diff line number Diff line change
Expand Up @@ -6,14 +6,11 @@
#include <atomic>


namespace StopWatchDetail
inline UInt64 clock_gettime_ns(clockid_t clock_type = CLOCK_MONOTONIC)
{
inline UInt64 nanoseconds(clockid_t clock_type)
{
struct timespec ts;
clock_gettime(clock_type, &ts);
return UInt64(ts.tv_sec * 1000000000LL + ts.tv_nsec);
}
struct timespec ts;
clock_gettime(clock_type, &ts);
return UInt64(ts.tv_sec * 1000000000LL + ts.tv_nsec);
}


Expand Down Expand Up @@ -44,7 +41,7 @@ class Stopwatch
clockid_t clock_type;
bool is_running = false;

UInt64 nanoseconds() const { return StopWatchDetail::nanoseconds(clock_type); }
UInt64 nanoseconds() const { return clock_gettime_ns(clock_type); }
};


Expand Down Expand Up @@ -131,7 +128,7 @@ class AtomicStopwatch
clockid_t clock_type;

/// Most significant bit is a lock. When it is set, compareAndRestartDeferred method will return false.
UInt64 nanoseconds() const { return StopWatchDetail::nanoseconds(clock_type) & 0x7FFFFFFFFFFFFFFFULL; }
UInt64 nanoseconds() const { return clock_gettime_ns(clock_type) & 0x7FFFFFFFFFFFFFFFULL; }
};


Expand Down
2 changes: 1 addition & 1 deletion dbms/src/Common/TraceCollector.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -144,7 +144,7 @@ void TraceCollector::run()

if (trace_log)
{
TraceLogElement element{std::time(nullptr), trace_type, thread_id, query_id, trace, size};
TraceLogElement element{std::time(nullptr), clock_gettime_ns(), trace_type, thread_id, query_id, trace, size};
trace_log->add(element);
}
}
Expand Down
2 changes: 2 additions & 0 deletions dbms/src/Interpreters/TraceLog.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ Block TraceLogElement::createBlock()
{
{std::make_shared<DataTypeDate>(), "event_date"},
{std::make_shared<DataTypeDateTime>(), "event_time"},
{std::make_shared<DataTypeUInt64>(), "timestamp_ns"},
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But in text_log there is a field named microseconds.
For consistency, this field in trace_log should be named nanoseconds and have a type UInt32 and not have the seconds part. But it is still acceptable, so will merge.

{std::make_shared<DataTypeUInt32>(), "revision"},
{std::make_shared<TraceDataType>(trace_values), "trace_type"},
{std::make_shared<DataTypeUInt64>(), "thread_id"},
Expand All @@ -41,6 +42,7 @@ void TraceLogElement::appendToBlock(Block & block) const

columns[i++]->insert(DateLUT::instance().toDayNum(event_time));
columns[i++]->insert(event_time);
columns[i++]->insert(timestamp_ns);
columns[i++]->insert(ClickHouseRevision::get());
columns[i++]->insert(static_cast<UInt8>(trace_type));
columns[i++]->insert(thread_id);
Expand Down
1 change: 1 addition & 0 deletions dbms/src/Interpreters/TraceLog.h
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ struct TraceLogElement
static const TraceDataType::Values trace_values;

time_t event_time{};
UInt64 timestamp_ns{};
TraceType trace_type{};
UInt64 thread_id{};
String query_id{};
Expand Down