Skip to content

Commit 4bca5c0

Browse files
robot-clickhouserobot-clickhouse
committed
Backport #93345 to 25.12: Improve the UX of SYSTEM INSTRUMENT ADD/REMOVE
1 parent a5a30f0 commit 4bca5c0

15 files changed

+157
-83
lines changed

‎docs/en/sql-reference/statements/system.md‎

Lines changed: 13 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -252,22 +252,22 @@ where `FUNCTION` is any function or substring of a function such as `QueryMetric
252252
Prints the text provided as an argument and the stack trace either on `ENTRY` or `EXIT` of the function.
253253

254254
```sql
255-
SYSTEM INSTRUMENT ADD `QueryMetricLog::startQuery` LOG ENTRY 'this is a log printed at entry'
256-
SYSTEM INSTRUMENT ADD `QueryMetricLog::startQuery` LOG EXIT 'this is a log printed at exit'
255+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG ENTRY 'this is a log printed at entry'
256+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG EXIT 'this is a log printed at exit'
257257
```
258258

259259
#### SLEEP {#instrument-add-sleep}
260260

261261
Sleeps for a number of fix amount of seconds either on `ENTRY` or `EXIT`:
262262

263263
```sql
264-
SYSTEM INSTRUMENT ADD `QueryMetricLog::startQuery` SLEEP ENTRY 0.5
264+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' SLEEP ENTRY 0.5
265265
```
266266

267267
or for a uniformly distributed random amount of seconds providing min and max separated by a whitespace:
268268

269269
```sql
270-
SYSTEM INSTRUMENT ADD `QueryMetricLog::startQuery` SLEEP ENTRY 0 1
270+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' SLEEP ENTRY 0 1
271271
```
272272

273273
#### PROFILE {#instrument-add-profile}
@@ -277,7 +277,7 @@ The result of the profiling is stored in [`system.trace_log`](../../operations/s
277277
to [Chrome Event Trace Format](../../operations/system-tables/trace_log.md#chrome-event-trace-format).
278278

279279
```sql
280-
SYSTEM INSTRUMENT ADD `QueryMetricLog::startQuery` PROFILE
280+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' PROFILE
281281
```
282282

283283
### SYSTEM INSTRUMENT REMOVE {#instrument-remove}
@@ -294,13 +294,19 @@ all of them using the `ALL` parameter:
294294
SYSTEM INSTRUMENT REMOVE ALL
295295
```
296296

297-
or a set of IDs from a subquery:
297+
a set of IDs from a subquery:
298298

299299
```sql
300300
SYSTEM INSTRUMENT REMOVE (SELECT id FROM system.instrumentation WHERE handler = 'log')
301301
```
302302

303-
The instrumentation point ID can be collected from [`system.instrumentation`](../../operations/system-tables/instrumentation.md) system table.
303+
or all instrumentation points that match a given function_name:
304+
305+
```sql
306+
SYSTEM INSTRUMENT REMOVE 'QueryMetricLog::startQuery'
307+
```
308+
309+
The instrumentation point information can be collected from [`system.instrumentation`](../../operations/system-tables/instrumentation.md) system table.
304310

305311
## Managing Distributed Tables {#managing-distributed-tables}
306312

‎src/Interpreters/InstrumentationManager.cpp‎

Lines changed: 55 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -153,51 +153,55 @@ void InstrumentationManager::patchFunction(ContextPtr context, const String & fu
153153
/// Lazy load the XRay instrumentation map only once we need to set up a handler
154154
ensureInitialization();
155155

156-
Int32 function_id = -1;
157-
String symbol;
156+
struct Function
157+
{
158+
Int32 function_id;
159+
String symbol;
160+
};
161+
162+
std::vector<Function> functions_to_patch;
158163
auto fn_it = functions_container.get<FunctionName>().find(function_name);
159164

160165
/// First, assume the name provided is the full qualified name.
161166
if (fn_it != functions_container.get<FunctionName>().end())
162167
{
163-
function_id = fn_it->function_id;
164-
symbol = fn_it->function_name;
168+
functions_to_patch.emplace_back(fn_it->function_id, fn_it->function_name);
165169
}
166170
else
167171
{
168172
/// Otherwise, search if the provided function_name can be found as a substr of every member.
169173
for (const auto & [id, function] : functions_container)
170174
{
171175
if (function.find(function_name) != std::string::npos)
172-
{
173-
function_id = id;
174-
symbol = function;
175-
break;
176-
}
176+
functions_to_patch.emplace_back(id, function);
177177
}
178178
}
179179

180-
if (function_id < 0 || symbol.empty())
180+
if (functions_to_patch.empty())
181181
throw Exception(ErrorCodes::BAD_ARGUMENTS, "Unknown function to instrument: '{}'. XRay instruments by default only functions of at least 200 instructions. "
182182
"You can change that threshold with '-fxray-instruction-threshold=1'. You can also force the instrumentation of specific functions decorating them with '[[clang::xray_always_instrument]]' "
183183
"and making sure they are not decorated with '[[clang::xray_never_instrument]]'", function_name);
184184

185185
std::lock_guard lock(shared_mutex);
186-
patchFunctionIfNeeded(function_id);
187186

188-
InstrumentedPointInfo info{context, instrumented_point_ids, function_id, function_name, handler_name_lower, entry_type, symbol, parameters};
189-
LOG_INFO(logger, "Adding instrumentation point for {}", info.toString());
190-
instrumented_points.emplace(std::move(info));
191-
instrumented_point_ids++;
187+
for (const auto & [function_id, symbol] : functions_to_patch)
188+
{
189+
patchFunctionIfNeeded(function_id);
190+
191+
InstrumentedPointInfo info{context, instrumented_point_ids, function_id, function_name, handler_name_lower, entry_type, symbol, parameters};
192+
LOG_INFO(logger, "Adding instrumentation point for {}", info.toString());
193+
instrumented_points.emplace(std::move(info));
194+
instrumented_point_ids++;
195+
}
192196
}
193197

194-
void InstrumentationManager::unpatchFunction(std::variant<UInt64, bool> id)
198+
void InstrumentationManager::unpatchFunction(std::variant<UInt64, Instrumentation::All, String> id)
195199
{
196200
std::lock_guard lock(shared_mutex);
197201

198-
if (std::holds_alternative<bool>(id))
202+
if (std::holds_alternative<Instrumentation::All>(id))
199203
{
200-
LOG_INFO(logger, "Removing all instrumented functions");
204+
LOG_INFO(logger, "Removing all instrumentation points");
201205
for (const auto & info : instrumented_points)
202206
{
203207
LOG_INFO(logger, "Removing instrumented function {}", info.toString());
@@ -207,13 +211,40 @@ void InstrumentationManager::unpatchFunction(std::variant<UInt64, bool> id)
207211
}
208212
else
209213
{
210-
const auto it = instrumented_points.get<Id>().find(std::get<UInt64>(id));
211-
if (it == instrumented_points.get<Id>().end())
212-
throw Exception(ErrorCodes::BAD_ARGUMENTS, "Unknown instrumentation point id to remove: ({})", std::get<UInt64>(id));
214+
std::vector<InstrumentedPointInfo> functions_to_unpatch;
215+
if (std::holds_alternative<String>(id))
216+
{
217+
const String name = std::get<String>(id);
218+
LOG_INFO(logger, "Removing all instrumented functions that match the function_name '{}'", name);
213219

214-
LOG_INFO(logger, "Removing instrumented function {}", it->toString());
215-
unpatchFunctionIfNeeded(it->function_id);
216-
instrumented_points.erase(it);
220+
for (const auto & info : instrumented_points)
221+
{
222+
if (info.function_name == std::get<String>(id))
223+
functions_to_unpatch.push_back(info);
224+
}
225+
226+
}
227+
else
228+
{
229+
const auto it = instrumented_points.get<Id>().find(std::get<UInt64>(id));
230+
if (it == instrumented_points.get<Id>().end())
231+
throw Exception(ErrorCodes::BAD_ARGUMENTS, "Unknown instrumentation point id to remove: ({})", std::get<UInt64>(id));
232+
233+
functions_to_unpatch.push_back(*it);
234+
}
235+
236+
if (functions_to_unpatch.empty())
237+
throw Exception(ErrorCodes::BAD_ARGUMENTS, "Not found any instrumentation point that matches");
238+
239+
for (const auto & info : functions_to_unpatch)
240+
{
241+
const auto it = instrumented_points.get<Id>().find(info.id);
242+
if (it == instrumented_points.get<Id>().end())
243+
throw Exception(ErrorCodes::LOGICAL_ERROR, "Instrumentation point {} does not exist", it->toString());
244+
LOG_INFO(logger, "Removing instrumented function {}", it->toString());
245+
unpatchFunctionIfNeeded(it->function_id);
246+
instrumented_points.erase(it);
247+
}
217248
}
218249
}
219250

‎src/Interpreters/InstrumentationManager.h‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,8 @@ namespace Instrumentation
4040
EntryType fromXRayEntryType(XRayEntryType entry_type);
4141
String entryTypeToString(EntryType entry_type);
4242

43+
struct All {};
44+
4345
}
4446

4547
struct TraceLogElement;
@@ -100,7 +102,7 @@ class InstrumentationManager
100102
static InstrumentationManager & instance();
101103

102104
[[clang::xray_never_instrument]] void patchFunction(ContextPtr context, const String & function_name, const String & handler_name, Instrumentation::EntryType entry_type, const std::vector<InstrumentedParameter> & parameters);
103-
[[clang::xray_never_instrument]] void unpatchFunction(std::variant<UInt64, bool> id);
105+
[[clang::xray_never_instrument]] void unpatchFunction(std::variant<UInt64, Instrumentation::All, String> id);
104106

105107
using InstrumentedPoints = std::vector<InstrumentedPointInfo>;
106108
InstrumentedPoints getInstrumentedPoints() const;

‎src/Interpreters/InterpreterSystemQuery.cpp‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1812,19 +1812,21 @@ void InterpreterSystemQuery::instrumentWithXRay(bool add, ASTSystemQuery & query
18121812
}
18131813
else
18141814
{
1815-
InstrumentationManager::instance().unpatchFunction(query.instrumentation_point_id.value());
1815+
InstrumentationManager::instance().unpatchFunction(query.instrumentation_point.value());
18161816
}
18171817
}
18181818
}
18191819
catch (const DB::Exception & e)
18201820
{
18211821
String id;
1822-
if (query.instrumentation_point_id.has_value())
1822+
if (query.instrumentation_point.has_value())
18231823
{
1824-
if (std::holds_alternative<bool>(query.instrumentation_point_id.value()))
1824+
if (std::holds_alternative<Instrumentation::All>(query.instrumentation_point.value()))
18251825
id = " and ALL ids";
1826+
else if (std::holds_alternative<String>(query.instrumentation_point.value()))
1827+
id = fmt::format(" and ids with function_name containing '{}'", std::get<String>(query.instrumentation_point.value()));
18261828
else
1827-
id = fmt::format(" and id '{}'", std::get<UInt64>(query.instrumentation_point_id.value()));
1829+
id = fmt::format(" and id '{}'", std::get<UInt64>(query.instrumentation_point.value()));
18281830
}
18291831

18301832
throw Exception(

‎src/Parsers/ASTSystemQuery.cpp‎

Lines changed: 6 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -484,10 +484,7 @@ void ASTSystemQuery::formatImpl(WriteBuffer & ostr, const FormatSettings & setti
484484
case Type::INSTRUMENT_ADD:
485485
{
486486
if (!instrumentation_function_name.empty())
487-
{
488-
ostr << ' ';
489-
print_identifier(instrumentation_function_name);
490-
}
487+
ostr << ' ' << quoteString(instrumentation_function_name);
491488

492489
if (!instrumentation_handler_name.empty())
493490
{
@@ -527,12 +524,14 @@ void ASTSystemQuery::formatImpl(WriteBuffer & ostr, const FormatSettings & setti
527524
{
528525
if (!instrumentation_subquery.empty())
529526
ostr << " (" << instrumentation_subquery << ')';
530-
else if (instrumentation_point_id)
527+
else if (instrumentation_point)
531528
{
532-
if (std::holds_alternative<bool>(instrumentation_point_id.value()))
529+
if (std::holds_alternative<Instrumentation::All>(instrumentation_point.value()))
533530
ostr << " ALL";
531+
else if (std::holds_alternative<String>(instrumentation_point.value()))
532+
ostr << ' ' << quoteString(std::get<String>(instrumentation_point.value()));
534533
else
535-
ostr << ' ' << std::get<UInt64>(instrumentation_point_id.value());
534+
ostr << ' ' << std::get<UInt64>(instrumentation_point.value());
536535
}
537536
break;
538537
}

‎src/Parsers/ASTSystemQuery.h‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -195,7 +195,7 @@ class ASTSystemQuery : public IAST, public ASTQueryWithOnCluster
195195
String instrumentation_function_name;
196196
String instrumentation_handler_name;
197197
Instrumentation::EntryType instrumentation_entry_type;
198-
std::optional<std::variant<UInt64, bool>> instrumentation_point_id;
198+
std::optional<std::variant<UInt64, Instrumentation::All, String>> instrumentation_point;
199199
std::vector<InstrumentParameter> instrumentation_parameters;
200200
String instrumentation_subquery;
201201
#endif

‎src/Parsers/ParserSystemQuery.cpp‎

Lines changed: 22 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -769,26 +769,37 @@ bool ParserSystemQuery::parseImpl(IParser::Pos & pos, ASTPtr & node, Expected &
769769
break;
770770
}
771771

772-
if (!ParserLiteral{}.parse(pos, temporary_identifier, expected))
772+
if (ParserLiteral{}.parse(pos, temporary_identifier, expected))
773773
{
774-
if (!ParserIdentifier{}.parse(pos, temporary_identifier, expected))
775-
return false;
776-
777-
if (Poco::toLower(temporary_identifier->as<ASTIdentifier &>().name()) != "all")
774+
const auto field = temporary_identifier->as<ASTLiteral &>().value;
775+
switch (field.getType())
776+
{
777+
case Field::Types::Which::String:
778+
res->instrumentation_point = field.safeGet<String>();
779+
break;
780+
case Field::Types::Which::UInt64:
781+
res->instrumentation_point = field.safeGet<UInt64>();
782+
break;
783+
default:
784+
return false;
785+
}
786+
}
787+
else if (ParserIdentifier{}.parse(pos, temporary_identifier, expected))
788+
{
789+
String identifier = temporary_identifier->as<ASTIdentifier &>().name();
790+
if (Poco::toLower(identifier) == "all")
791+
res->instrumentation_point = Instrumentation::All{};
792+
else
778793
return false;
779-
780-
res->instrumentation_point_id = true;
781-
break;
782794
}
783795

784-
res->instrumentation_point_id = temporary_identifier->as<ASTLiteral>()->value.safeGet<UInt64>();
785796
break;
786797
}
787798
case Type::INSTRUMENT_ADD:
788799
{
789800
ASTPtr temporary_identifier;
790-
if (ParserIdentifier{}.parse(pos, temporary_identifier, expected))
791-
res->instrumentation_function_name = temporary_identifier->as<ASTIdentifier &>().name();
801+
if (ParserLiteral{}.parse(pos, temporary_identifier, expected))
802+
res->instrumentation_function_name = temporary_identifier->as<ASTLiteral &>().value.safeGet<String>();
792803
else
793804
return false;
794805

‎tests/queries/0_stateless/03642_system_instrument_add_remove.reference‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,3 +23,9 @@ QueryMetricLog::finishQuery log Entry DB::QueryMetricLog::finishQuery(std::__1::
2323
-- Remove with wrong arguments fails
2424
-- Remove everything
2525
0
26+
-- Add several functions that match
27+
1 executeQuery log Entry
28+
-- Remove functions that match
29+
QueryMetricLog::startQuery log Entry DB::QueryMetricLog::startQuery(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::chrono::time_point<std::__1::chrono::system_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000l>>>, unsigned long) ['my log in startQuery']
30+
-- Remove everything
31+
0

‎tests/queries/0_stateless/03642_system_instrument_add_remove.sh‎

Lines changed: 22 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -21,15 +21,15 @@ $CLICKHOUSE_CLIENT -q "
2121
SELECT count() FROM system.instrumentation;
2222
2323
SELECT '-- Add one';
24-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::finishQuery\` LOG ENTRY 'my log in finishQuery';
24+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::finishQuery' LOG ENTRY 'my log in finishQuery';
2525
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
2626
2727
SELECT '-- Adding the same one again';
28-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::finishQuery\` LOG ENTRY 'another log in finishQuery';
28+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::finishQuery' LOG ENTRY 'another log in finishQuery';
2929
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
3030
3131
SELECT '-- Add another one';
32-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` LOG ENTRY 'my log in startQuery';
32+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG ENTRY 'my log in startQuery';
3333
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
3434
"
3535

@@ -41,8 +41,8 @@ $CLICKHOUSE_CLIENT -q "
4141
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
4242
4343
SELECT '-- Add 2 more';
44-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` LOG EXIT 'my other in startQuery';
45-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::finishQuery\` LOG EXIT 'my other in finishQuery';
44+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG EXIT 'my other in startQuery';
45+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::finishQuery' LOG EXIT 'my other in finishQuery';
4646
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
4747
4848
SELECT '-- Remove the entries with entry_type = Exit';
@@ -52,6 +52,23 @@ $CLICKHOUSE_CLIENT -q "
5252
SELECT '-- Remove with wrong arguments fails';
5353
SYSTEM INSTRUMENT REMOVE (SELECT id, function_id FROM system.instrumentation); -- { serverError BAD_ARGUMENTS }
5454
SYSTEM INSTRUMENT REMOVE (SELECT handler FROM system.instrumentation); -- { serverError BAD_ARGUMENTS }
55+
SYSTEM INSTRUMENT REMOVE 3.2; -- { clientError SYNTAX_ERROR }
56+
57+
SELECT '-- Remove everything';
58+
SYSTEM INSTRUMENT REMOVE ALL;
59+
SELECT count() FROM system.instrumentation;
60+
"
61+
62+
$CLICKHOUSE_CLIENT -q "
63+
SELECT '-- Add several functions that match';
64+
SYSTEM INSTRUMENT ADD 'executeQuery' LOG ENTRY 'my log in executeQuery';
65+
SELECT count() > 10, function_name, handler, entry_type FROM system.instrumentation WHERE symbol ILIKE '%executeQuery%' GROUP BY function_name, handler, entry_type;
66+
67+
SELECT '-- Remove functions that match';
68+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG ENTRY 'my log in startQuery';
69+
SYSTEM INSTRUMENT REMOVE 'unknown'; -- { serverError BAD_ARGUMENTS }
70+
SYSTEM INSTRUMENT REMOVE 'executeQuery';
71+
SELECT function_name, handler, entry_type, symbol, parameters FROM system.instrumentation ORDER BY id ASC;
5572
5673
SELECT '-- Remove everything';
5774
SYSTEM INSTRUMENT REMOVE ALL;

‎tests/queries/0_stateless/03642_system_instrument_entry_exit.sh‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -18,10 +18,10 @@ trap cleanup EXIT
1818
# Execute them in random order (not handler-ordered alphabetically) to make sure they're executed in this same order.
1919
$CLICKHOUSE_CLIENT -q "
2020
SYSTEM INSTRUMENT REMOVE ALL;
21-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` PROFILE;
22-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` LOG ENTRY 'this is an entry log';
23-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` SLEEP ENTRY 3;
24-
SYSTEM INSTRUMENT ADD \`QueryMetricLog::startQuery\` LOG EXIT 'this is an exit log';
21+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' PROFILE;
22+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG ENTRY 'this is an entry log';
23+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' SLEEP ENTRY 3;
24+
SYSTEM INSTRUMENT ADD 'QueryMetricLog::startQuery' LOG EXIT 'this is an exit log';
2525
"
2626

2727
$CLICKHOUSE_CLIENT --query-id=$query_id -q "SELECT 1 FORMAT Null;"

0 commit comments

Comments
 (0)