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

Poor man's profiler on query level #4247

Merged
merged 55 commits into from Jul 23, 2019
Merged

Poor man's profiler on query level #4247

merged 55 commits into from Jul 23, 2019

Conversation

laplab
Copy link
Contributor

@laplab laplab commented Feb 3, 2019

I hereby agree to the terms of the CLA available at: https://yandex.ru/legal/cla/?lang=en

Category: New Feature

Short description: Poor man's profiler for each query being executed

Detailed description:
Poor man's profiler stops a program at random time points to collect current backtrace. After some time a developer can analyze which code points profiler visits most often. Such places probably have some efficiency issues and could be optimized during the performance analysis.
Original: https://poormansprofiler.org

Technically we give each query-related thread a timer and setup signal listener which collects information required for backtrace and passes it to the pipe. Separate thread (TraceCollector) reads information from the pipe and writes it to system table system.trace_log.

ToDo

  1. Refactor and add comments to key places
  2. Add function to demangle trace addresses to readable backtrace
  3. Stop TraceCollector gracefully (current version is killed by the OS after clickhouse server stops)
  4. Add config options to control profiler period

throw Exception("The only argument for function " + getName() + " must be array of UInt64. Found "
+ arguments[0].type->getName() + " instead.", ErrorCodes::ILLEGAL_TYPE_OF_ARGUMENT);

return std::make_shared<DataTypeString>();
Copy link
Member

Choose a reason for hiding this comment

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

If it takes array of addresses - let it return array of strings.

Copy link
Member

Choose a reason for hiding this comment

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

Because otherwise it will be difficult to aggregate.

Copy link
Member

Choose a reason for hiding this comment

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

Even better: let it be a function that will symbolize a single address.
And we will apply it with arrayMap.

@@ -41,6 +42,8 @@ void ThreadStatus::attachQueryContext(Context & query_context_)
if (!thread_group->global_context)
thread_group->global_context = global_context;
}

initQueryProfiler();
Copy link
Member

Choose a reason for hiding this comment

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

It will probably set up query profiler only in first query execution thread.
Look at my recent changes related to setpriority in this file.


using TimerDataType = TraceLogElement::TimerDataType;

const TimerDataType::Values TraceLogElement::timer_values = {
Copy link
Member

Choose a reason for hiding this comment

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

Style.

columns[i++]->insert(event_time);
columns[i++]->insert(static_cast<UInt8>(timer_type));
columns[i++]->insertData(query_id.data(), query_id.size());
columns[i++]->insert(trace);
Copy link
Member

Choose a reason for hiding this comment

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

Let's also add server version info (as in query_log) - because it's crucial for symbolizing traces.

Copy link
Member

Choose a reason for hiding this comment

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

And

    String thread_name;
    UInt32 thread_number{};
    Int32 os_thread_id{};
    UInt32 master_thread_number{};
    Int32 master_os_thread_id{};

as in query_thread_log.


finish_time.tv_sec += (nanoseconds / resolution) + extra_second;

while (clock_nanosleep(clock_type, TIMER_ABSTIME, &finish_time, nullptr) == EINTR);
Copy link
Member

Choose a reason for hiding this comment

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

Please put semicolon on a new line :)

@alexey-milovidov alexey-milovidov merged commit e4ad0da into ClickHouse:master Jul 23, 2019
alexey-milovidov added a commit that referenced this pull request Jul 23, 2019
@alexey-milovidov
Copy link
Member

TODO:

  • change FunctionsIntrospection;
  • enrich trace_log;
  • check that profiler is set up for every query thread;

@akuzm akuzm added the pr-feature Pull request with new product feature label Jul 25, 2019
@laplab laplab changed the title Poor man's profiler on query level [Work in progress] Poor man's profiler on query level Feb 11, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
pr-feature Pull request with new product feature
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants