1	//===-- StructuredDataDarwinLog.cpp ---------------------------------------===//
2	//
3	// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4	// See https://llvm.org/LICENSE.txt for license information.
5	// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6	//
7	//===----------------------------------------------------------------------===//
8
9	#include "StructuredDataDarwinLog.h"
10
11	#include <cstring>
12
13	#include <memory>
14	#include <sstream>
15
16	#include "lldb/Breakpoint/StoppointCallbackContext.h"
17	#include "lldb/Core/Debugger.h"
18	#include "lldb/Core/Module.h"
19	#include "lldb/Core/PluginManager.h"
20	#include "lldb/Host/OptionParser.h"
21	#include "lldb/Interpreter/CommandInterpreter.h"
22	#include "lldb/Interpreter/CommandObjectMultiword.h"
23	#include "lldb/Interpreter/CommandReturnObject.h"
24	#include "lldb/Interpreter/OptionArgParser.h"
25	#include "lldb/Interpreter/OptionValueProperties.h"
26	#include "lldb/Interpreter/OptionValueString.h"
27	#include "lldb/Interpreter/Property.h"
28	#include "lldb/Target/Process.h"
29	#include "lldb/Target/Target.h"
30	#include "lldb/Target/ThreadPlanCallOnFunctionExit.h"
31	#include "lldb/Utility/LLDBLog.h"
32	#include "lldb/Utility/Log.h"
33	#include "lldb/Utility/RegularExpression.h"
34
35	#include "llvm/ADT/StringMap.h"
36
37	#define DARWIN_LOG_TYPE_VALUE "DarwinLog"
38
39	using namespace lldb;
40	using namespace lldb_private;
41
42	LLDB_PLUGIN_DEFINE(StructuredDataDarwinLog)
43
44	#pragma mark -
45	#pragma mark Anonymous Namespace
46
47	// Anonymous namespace
48
49	namespace sddarwinlog_private {
50	const uint64_t NANOS_PER_MICRO = 1000;
51	const uint64_t NANOS_PER_MILLI = NANOS_PER_MICRO * 1000;
52	const uint64_t NANOS_PER_SECOND = NANOS_PER_MILLI * 1000;
53	const uint64_t NANOS_PER_MINUTE = NANOS_PER_SECOND * 60;
54	const uint64_t NANOS_PER_HOUR = NANOS_PER_MINUTE * 60;
55
56	static bool DEFAULT_FILTER_FALLTHROUGH_ACCEPTS = true;
57
58	/// Global, sticky enable switch. If true, the user has explicitly
59	/// run the enable command. When a process launches or is attached to,
60	/// we will enable DarwinLog if either the settings for auto-enable is
61	/// on, or if the user had explicitly run enable at some point prior
62	/// to the launch/attach.
63	static bool s_is_explicitly_enabled;
64
65	class EnableOptions;
66	using EnableOptionsSP = std::shared_ptr<EnableOptions>;
67
68	using OptionsMap =
69	std::map<DebuggerWP, EnableOptionsSP, std::owner_less<DebuggerWP>>;
70
71	static OptionsMap &GetGlobalOptionsMap() {
72	static OptionsMap s_options_map;
73	return s_options_map;
74	}
75
76	static std::mutex &GetGlobalOptionsMapLock() {
77	static std::mutex s_options_map_lock;
78	return s_options_map_lock;
79	}
80
81	EnableOptionsSP GetGlobalEnableOptions(const DebuggerSP &debugger_sp) {
82	if (!debugger_sp)
83	return EnableOptionsSP();
84
85	std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());
86	OptionsMap &options_map = GetGlobalOptionsMap();
87	DebuggerWP debugger_wp(debugger_sp);
88	auto find_it = options_map.find(x: debugger_wp);
89	if (find_it != options_map.end())
90	return find_it->second;
91	else
92	return EnableOptionsSP();
93	}
94
95	void SetGlobalEnableOptions(const DebuggerSP &debugger_sp,
96	const EnableOptionsSP &options_sp) {
97	std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());
98	OptionsMap &options_map = GetGlobalOptionsMap();
99	DebuggerWP debugger_wp(debugger_sp);
100	auto find_it = options_map.find(x: debugger_wp);
101	if (find_it != options_map.end())
102	find_it->second = options_sp;
103	else
104	options_map.insert(x: std::make_pair(x&: debugger_wp, y: options_sp));
105	}
106
107	#pragma mark -
108	#pragma mark Settings Handling
109
110	/// Code to handle the StructuredDataDarwinLog settings
111
112	#define LLDB_PROPERTIES_darwinlog
113	#include "StructuredDataDarwinLogProperties.inc"
114
115	enum {
116	#define LLDB_PROPERTIES_darwinlog
117	#include "StructuredDataDarwinLogPropertiesEnum.inc"
118	};
119
120	class StructuredDataDarwinLogProperties : public Properties {
121	public:
122	static llvm::StringRef GetSettingName() {
123	static constexpr llvm::StringLiteral g_setting_name("darwin-log");
124	return g_setting_name;
125	}
126
127	StructuredDataDarwinLogProperties() : Properties() {
128	m_collection_sp = std::make_shared<OptionValueProperties>(GetSettingName());
129	m_collection_sp->Initialize(g_darwinlog_properties);
130	}
131
132	~StructuredDataDarwinLogProperties() override = default;
133
134	bool GetEnableOnStartup() const {
135	const uint32_t idx = ePropertyEnableOnStartup;
136	return GetPropertyAtIndexAs<bool>(
137	idx, g_darwinlog_properties[idx].default_uint_value != 0);
138	}
139
140	llvm::StringRef GetAutoEnableOptions() const {
141	const uint32_t idx = ePropertyAutoEnableOptions;
142	return GetPropertyAtIndexAs<llvm::StringRef>(
143	idx, g_darwinlog_properties[idx].default_cstr_value);
144	}
145
146	const char *GetLoggingModuleName() const { return "libsystem_trace.dylib"; }
147	};
148
149	static StructuredDataDarwinLogProperties &GetGlobalProperties() {
150	static StructuredDataDarwinLogProperties g_settings;
151	return g_settings;
152	}
153
154	const char *const s_filter_attributes[] = {
155	"activity", // current activity
156	"activity-chain", // entire activity chain, each level separated by ':'
157	"category", // category of the log message
158	"message", // message contents, fully expanded
159	"subsystem" // subsystem of the log message
160
161	// Consider implementing this action as it would be cheaper to filter.
162	// "message" requires always formatting the message, which is a waste of
163	// cycles if it ends up being rejected. "format", // format string
164	// used to format message text
165	};
166
167	static llvm::StringRef GetDarwinLogTypeName() {
168	static constexpr llvm::StringLiteral s_key_name("DarwinLog");
169	return s_key_name;
170	}
171
172	static llvm::StringRef GetLogEventType() {
173	static constexpr llvm::StringLiteral s_event_type("log");
174	return s_event_type;
175	}
176
177	class FilterRule;
178	using FilterRuleSP = std::shared_ptr<FilterRule>;
179
180	class FilterRule {
181	public:
182	virtual ~FilterRule() = default;
183
184	using OperationCreationFunc =
185	std::function<FilterRuleSP(bool accept, size_t attribute_index,
186	const std::string &op_arg, Status &error)>;
187
188	static void RegisterOperation(llvm::StringRef operation,
189	const OperationCreationFunc &creation_func) {
190	GetCreationFuncMap().insert(std::make_pair(operation, creation_func));
191	}
192
193	static FilterRuleSP CreateRule(bool match_accepts, size_t attribute,
194	llvm::StringRef operation,
195	const std::string &op_arg, Status &error) {
196	// Find the creation func for this type of filter rule.
197	auto map = GetCreationFuncMap();
198	auto find_it = map.find(operation);
199	if (find_it == map.end()) {
200	error.SetErrorStringWithFormatv("unknown filter operation \"{0}\"",
201	operation);
202	return FilterRuleSP();
203	}
204
205	return find_it->second(match_accepts, attribute, op_arg, error);
206	}
207
208	StructuredData::ObjectSP Serialize() const {
209	StructuredData::Dictionary *dict_p = new StructuredData::Dictionary();
210
211	// Indicate whether this is an accept or reject rule.
212	dict_p->AddBooleanItem(key: "accept", value: m_accept);
213
214	// Indicate which attribute of the message this filter references. This can
215	// drop into the rule-specific DoSerialization if we get to the point where
216	// not all FilterRule derived classes work on an attribute. (e.g. logical
217	// and/or and other compound operations).
218	dict_p->AddStringItem(key: "attribute", value: s_filter_attributes[m_attribute_index]);
219
220	// Indicate the type of the rule.
221	dict_p->AddStringItem(key: "type", value: GetOperationType());
222
223	// Let the rule add its own specific details here.
224	DoSerialization(dict&: *dict_p);
225
226	return StructuredData::ObjectSP(dict_p);
227	}
228
229	virtual void Dump(Stream &stream) const = 0;
230
231	llvm::StringRef GetOperationType() const { return m_operation; }
232
233	protected:
234	FilterRule(bool accept, size_t attribute_index, llvm::StringRef operation)
235	: m_accept(accept), m_attribute_index(attribute_index),
236	m_operation(operation) {}
237
238	virtual void DoSerialization(StructuredData::Dictionary &dict) const = 0;
239
240	bool GetMatchAccepts() const { return m_accept; }
241
242	const char *GetFilterAttribute() const {
243	return s_filter_attributes[m_attribute_index];
244	}
245
246	private:
247	using CreationFuncMap = llvm::StringMap<OperationCreationFunc>;
248
249	static CreationFuncMap &GetCreationFuncMap() {
250	static CreationFuncMap s_map;
251	return s_map;
252	}
253
254	const bool m_accept;
255	const size_t m_attribute_index;
256	// The lifetime of m_operation should be static.
257	const llvm::StringRef m_operation;
258	};
259
260	using FilterRules = std::vector<FilterRuleSP>;
261
262	class RegexFilterRule : public FilterRule {
263	public:
264	static void RegisterOperation() {
265	FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);
266	}
267
268	void Dump(Stream &stream) const override {
269	stream.Printf(format: "%s %s regex %s", GetMatchAccepts() ? "accept" : "reject",
270	GetFilterAttribute(), m_regex_text.c_str());
271	}
272
273	protected:
274	void DoSerialization(StructuredData::Dictionary &dict) const override {
275	dict.AddStringItem(key: "regex", value: m_regex_text);
276	}
277
278	private:
279	static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,
280	const std::string &op_arg,
281	Status &error) {
282	// We treat the op_arg as a regex. Validate it.
283	if (op_arg.empty()) {
284	error.SetErrorString("regex filter type requires a regex "
285	"argument");
286	return FilterRuleSP();
287	}
288
289	// Instantiate the regex so we can report any errors.
290	auto regex = RegularExpression(op_arg);
291	if (llvm::Error err = regex.GetError()) {
292	error.SetErrorString(llvm::toString(std::move(err)));
293	return FilterRuleSP();
294	}
295
296	// We passed all our checks, this appears fine.
297	error.Clear();
298	return FilterRuleSP(new RegexFilterRule(accept, attribute_index, op_arg));
299	}
300
301	static llvm::StringRef StaticGetOperation() {
302	static constexpr llvm::StringLiteral s_operation("regex");
303	return s_operation;
304	}
305
306	RegexFilterRule(bool accept, size_t attribute_index,
307	const std::string &regex_text)
308	: FilterRule(accept, attribute_index, StaticGetOperation()),
309	m_regex_text(regex_text) {}
310
311	const std::string m_regex_text;
312	};
313
314	class ExactMatchFilterRule : public FilterRule {
315	public:
316	static void RegisterOperation() {
317	FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);
318	}
319
320	void Dump(Stream &stream) const override {
321	stream.Printf(format: "%s %s match %s", GetMatchAccepts() ? "accept" : "reject",
322	GetFilterAttribute(), m_match_text.c_str());
323	}
324
325	protected:
326	void DoSerialization(StructuredData::Dictionary &dict) const override {
327	dict.AddStringItem(key: "exact_text", value: m_match_text);
328	}
329
330	private:
331	static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,
332	const std::string &op_arg,
333	Status &error) {
334	if (op_arg.empty()) {
335	error.SetErrorString("exact match filter type requires an "
336	"argument containing the text that must "
337	"match the specified message attribute.");
338	return FilterRuleSP();
339	}
340
341	error.Clear();
342	return FilterRuleSP(
343	new ExactMatchFilterRule(accept, attribute_index, op_arg));
344	}
345
346	static llvm::StringRef StaticGetOperation() {
347	static constexpr llvm::StringLiteral s_operation("match");
348	return s_operation;
349	}
350
351	ExactMatchFilterRule(bool accept, size_t attribute_index,
352	const std::string &match_text)
353	: FilterRule(accept, attribute_index, StaticGetOperation()),
354	m_match_text(match_text) {}
355
356	const std::string m_match_text;
357	};
358
359	static void RegisterFilterOperations() {
360	ExactMatchFilterRule::RegisterOperation();
361	RegexFilterRule::RegisterOperation();
362	}
363
364	// =========================================================================
365	// Commands
366	// =========================================================================
367
368	/// Provides the main on-off switch for enabling darwin logging.
369	///
370	/// It is valid to run the enable command when logging is already enabled.
371	/// This resets the logging with whatever settings are currently set.
372
373	static constexpr OptionDefinition g_enable_option_table[] = {
374	// Source stream include/exclude options (the first-level filter). This one
375	// should be made as small as possible as everything that goes through here
376	// must be processed by the process monitor.
377	{LLDB_OPT_SET_ALL, .required: false, .long_option: "any-process", .short_option: 'a', .option_has_arg: OptionParser::eNoArgument,
378	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
379	.usage_text: "Specifies log messages from other related processes should be "
380	"included."},
381	{LLDB_OPT_SET_ALL, .required: false, .long_option: "debug", .short_option: 'd', .option_has_arg: OptionParser::eNoArgument, .validator: nullptr,
382	.enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
383	.usage_text: "Specifies debug-level log messages should be included. Specifying"
384	" --debug implies --info."},
385	{LLDB_OPT_SET_ALL, .required: false, .long_option: "info", .short_option: 'i', .option_has_arg: OptionParser::eNoArgument, .validator: nullptr,
386	.enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
387	.usage_text: "Specifies info-level log messages should be included."},
388	{LLDB_OPT_SET_ALL, .required: false, .long_option: "filter", .short_option: 'f', .option_has_arg: OptionParser::eRequiredArgument,
389	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgRawInput,
390	// There doesn't appear to be a great way for me to have these multi-line,
391	// formatted tables in help. This looks mostly right but there are extra
392	// linefeeds added at seemingly random spots, and indentation isn't
393	// handled properly on those lines.
394	.usage_text: "Appends a filter rule to the log message filter chain. Multiple "
395	"rules may be added by specifying this option multiple times, "
396	"once per filter rule. Filter rules are processed in the order "
397	"they are specified, with the --no-match-accepts setting used "
398	"for any message that doesn't match one of the rules.\n"
399	"\n"
400	" Filter spec format:\n"
401	"\n"
402	" --filter \"{action} {attribute} {op}\"\n"
403	"\n"
404	" {action} :=\n"
405	" accept |\n"
406	" reject\n"
407	"\n"
408	" {attribute} :=\n"
409	" activity | // message's most-derived activity\n"
410	" activity-chain | // message's {parent}:{child} activity\n"
411	" category | // message's category\n"
412	" message | // message's expanded contents\n"
413	" subsystem | // message's subsystem\n"
414	"\n"
415	" {op} :=\n"
416	" match {exact-match-text} |\n"
417	" regex {search-regex}\n"
418	"\n"
419	"The regex flavor used is the C++ std::regex ECMAScript format. "
420	"Prefer character classes like [[:digit:]] to \\d and the like, as "
421	"getting the backslashes escaped through properly is error-prone."},
422	{LLDB_OPT_SET_ALL, .required: false, .long_option: "live-stream", .short_option: 'l',
423	.option_has_arg: OptionParser::eRequiredArgument, .validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeBoolean,
424	.usage_text: "Specify whether logging events are live-streamed or buffered. "
425	"True indicates live streaming, false indicates buffered. The "
426	"default is true (live streaming). Live streaming will deliver "
427	"log messages with less delay, but buffered capture mode has less "
428	"of an observer effect."},
429	{LLDB_OPT_SET_ALL, .required: false, .long_option: "no-match-accepts", .short_option: 'n',
430	.option_has_arg: OptionParser::eRequiredArgument, .validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeBoolean,
431	.usage_text: "Specify whether a log message that doesn't match any filter rule "
432	"is accepted or rejected, where true indicates accept. The "
433	"default is true."},
434	{LLDB_OPT_SET_ALL, .required: false, .long_option: "echo-to-stderr", .short_option: 'e',
435	.option_has_arg: OptionParser::eRequiredArgument, .validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeBoolean,
436	.usage_text: "Specify whether os_log()/NSLog() messages are echoed to the "
437	"target program's stderr. When DarwinLog is enabled, we shut off "
438	"the mirroring of os_log()/NSLog() to the program's stderr. "
439	"Setting this flag to true will restore the stderr mirroring."
440	"The default is false."},
441	{LLDB_OPT_SET_ALL, .required: false, .long_option: "broadcast-events", .short_option: 'b',
442	.option_has_arg: OptionParser::eRequiredArgument, .validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeBoolean,
443	.usage_text: "Specify if the plugin should broadcast events. Broadcasting "
444	"log events is a requirement for displaying the log entries in "
445	"LLDB command-line. It is also required if LLDB clients want to "
446	"process log events. The default is true."},
447	// Message formatting options
448	{LLDB_OPT_SET_ALL, .required: false, .long_option: "timestamp-relative", .short_option: 'r',
449	.option_has_arg: OptionParser::eNoArgument, .validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
450	.usage_text: "Include timestamp in the message header when printing a log "
451	"message. The timestamp is relative to the first displayed "
452	"message."},
453	{LLDB_OPT_SET_ALL, .required: false, .long_option: "subsystem", .short_option: 's', .option_has_arg: OptionParser::eNoArgument,
454	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
455	.usage_text: "Include the subsystem in the message header when displaying "
456	"a log message."},
457	{LLDB_OPT_SET_ALL, .required: false, .long_option: "category", .short_option: 'c', .option_has_arg: OptionParser::eNoArgument,
458	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
459	.usage_text: "Include the category in the message header when displaying "
460	"a log message."},
461	{LLDB_OPT_SET_ALL, .required: false, .long_option: "activity-chain", .short_option: 'C', .option_has_arg: OptionParser::eNoArgument,
462	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
463	.usage_text: "Include the activity parent-child chain in the message header "
464	"when displaying a log message. The activity hierarchy is "
465	"displayed as {grandparent-activity}:"
466	"{parent-activity}:{activity}[:...]."},
467	{LLDB_OPT_SET_ALL, .required: false, .long_option: "all-fields", .short_option: 'A', .option_has_arg: OptionParser::eNoArgument,
468	.validator: nullptr, .enum_values: {}, .completion_type: 0, .argument_type: eArgTypeNone,
469	.usage_text: "Shortcut to specify that all header fields should be displayed."}};
470
471	class EnableOptions : public Options {
472	public:
473	EnableOptions()
474	: Options(),
475	m_filter_fall_through_accepts(DEFAULT_FILTER_FALLTHROUGH_ACCEPTS),
476	m_filter_rules() {}
477
478	void OptionParsingStarting(ExecutionContext *execution_context) override {
479	m_include_debug_level = false;
480	m_include_info_level = false;
481	m_include_any_process = false;
482	m_filter_fall_through_accepts = DEFAULT_FILTER_FALLTHROUGH_ACCEPTS;
483	m_echo_to_stderr = false;
484	m_display_timestamp_relative = false;
485	m_display_subsystem = false;
486	m_display_category = false;
487	m_display_activity_chain = false;
488	m_broadcast_events = true;
489	m_live_stream = true;
490	m_filter_rules.clear();
491	}
492
493	Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,
494	ExecutionContext *execution_context) override {
495	Status error;
496
497	const int short_option = m_getopt_table[option_idx].val;
498	switch (short_option) {
499	case 'a':
500	m_include_any_process = true;
501	break;
502
503	case 'A':
504	m_display_timestamp_relative = true;
505	m_display_category = true;
506	m_display_subsystem = true;
507	m_display_activity_chain = true;
508	break;
509
510	case 'b':
511	m_broadcast_events =
512	OptionArgParser::ToBoolean(s: option_arg, fail_value: true, success_ptr: nullptr);
513	break;
514
515	case 'c':
516	m_display_category = true;
517	break;
518
519	case 'C':
520	m_display_activity_chain = true;
521	break;
522
523	case 'd':
524	m_include_debug_level = true;
525	break;
526
527	case 'e':
528	m_echo_to_stderr = OptionArgParser::ToBoolean(s: option_arg, fail_value: false, success_ptr: nullptr);
529	break;
530
531	case 'f':
532	return ParseFilterRule(rule_text: option_arg);
533
534	case 'i':
535	m_include_info_level = true;
536	break;
537
538	case 'l':
539	m_live_stream = OptionArgParser::ToBoolean(s: option_arg, fail_value: false, success_ptr: nullptr);
540	break;
541
542	case 'n':
543	m_filter_fall_through_accepts =
544	OptionArgParser::ToBoolean(s: option_arg, fail_value: true, success_ptr: nullptr);
545	break;
546
547	case 'r':
548	m_display_timestamp_relative = true;
549	break;
550
551	case 's':
552	m_display_subsystem = true;
553	break;
554
555	default:
556	error.SetErrorStringWithFormat("unsupported option '%c'", short_option);
557	}
558	return error;
559	}
560
561	llvm::ArrayRef<OptionDefinition> GetDefinitions() override {
562	return llvm::ArrayRef(g_enable_option_table);
563	}
564
565	StructuredData::DictionarySP BuildConfigurationData(bool enabled) {
566	StructuredData::DictionarySP config_sp(new StructuredData::Dictionary());
567
568	// Set the basic enabled state.
569	config_sp->AddBooleanItem("enabled", enabled);
570
571	// If we're disabled, there's nothing more to add.
572	if (!enabled)
573	return config_sp;
574
575	// Handle source stream flags.
576	auto source_flags_sp =
577	StructuredData::DictionarySP(new StructuredData::Dictionary());
578	config_sp->AddItem("source-flags", source_flags_sp);
579
580	source_flags_sp->AddBooleanItem("any-process", m_include_any_process);
581	source_flags_sp->AddBooleanItem("debug-level", m_include_debug_level);
582	// The debug-level flag, if set, implies info-level.
583	source_flags_sp->AddBooleanItem("info-level", m_include_info_level ||
584	m_include_debug_level);
585	source_flags_sp->AddBooleanItem("live-stream", m_live_stream);
586
587	// Specify default filter rule (the fall-through)
588	config_sp->AddBooleanItem("filter-fall-through-accepts",
589	m_filter_fall_through_accepts);
590
591	// Handle filter rules
592	if (!m_filter_rules.empty()) {
593	auto json_filter_rules_sp =
594	StructuredData::ArraySP(new StructuredData::Array);
595	config_sp->AddItem("filter-rules", json_filter_rules_sp);
596	for (auto &rule_sp : m_filter_rules) {
597	if (!rule_sp)
598	continue;
599	json_filter_rules_sp->AddItem(rule_sp->Serialize());
600	}
601	}
602	return config_sp;
603	}
604
605	bool GetIncludeDebugLevel() const { return m_include_debug_level; }
606
607	bool GetIncludeInfoLevel() const {
608	// Specifying debug level implies info level.
609	return m_include_info_level || m_include_debug_level;
610	}
611
612	const FilterRules &GetFilterRules() const { return m_filter_rules; }
613
614	bool GetFallthroughAccepts() const { return m_filter_fall_through_accepts; }
615
616	bool GetEchoToStdErr() const { return m_echo_to_stderr; }
617
618	bool GetDisplayTimestampRelative() const {
619	return m_display_timestamp_relative;
620	}
621
622	bool GetDisplaySubsystem() const { return m_display_subsystem; }
623	bool GetDisplayCategory() const { return m_display_category; }
624	bool GetDisplayActivityChain() const { return m_display_activity_chain; }
625
626	bool GetDisplayAnyHeaderFields() const {
627	return m_display_timestamp_relative || m_display_activity_chain ||
628	m_display_subsystem || m_display_category;
629	}
630
631	bool GetBroadcastEvents() const { return m_broadcast_events; }
632
633	private:
634	Status ParseFilterRule(llvm::StringRef rule_text) {
635	Status error;
636
637	if (rule_text.empty()) {
638	error.SetErrorString("invalid rule_text");
639	return error;
640	}
641
642	// filter spec format:
643	//
644	// {action} {attribute} {op}
645	//
646	// {action} :=
647	// accept |
648	// reject
649	//
650	// {attribute} :=
651	// category |
652	// subsystem |
653	// activity |
654	// activity-chain |
655	// message |
656	// format
657	//
658	// {op} :=
659	// match {exact-match-text} |
660	// regex {search-regex}
661
662	// Parse action.
663	auto action_end_pos = rule_text.find(C: ' ');
664	if (action_end_pos == std::string::npos) {
665	error.SetErrorStringWithFormat("could not parse filter rule "
666	"action from \"%s\"",
667	rule_text.str().c_str());
668	return error;
669	}
670	auto action = rule_text.substr(Start: 0, N: action_end_pos);
671	bool accept;
672	if (action == "accept")
673	accept = true;
674	else if (action == "reject")
675	accept = false;
676	else {
677	error.SetErrorString("filter action must be \"accept\" or \"deny\"");
678	return error;
679	}
680
681	// parse attribute
682	auto attribute_end_pos = rule_text.find(Str: " ", From: action_end_pos + 1);
683	if (attribute_end_pos == std::string::npos) {
684	error.SetErrorStringWithFormat("could not parse filter rule "
685	"attribute from \"%s\"",
686	rule_text.str().c_str());
687	return error;
688	}
689	auto attribute = rule_text.substr(Start: action_end_pos + 1,
690	N: attribute_end_pos - (action_end_pos + 1));
691	auto attribute_index = MatchAttributeIndex(attribute_name: attribute);
692	if (attribute_index < 0) {
693	error.SetErrorStringWithFormat("filter rule attribute unknown: "
694	"%s",
695	attribute.str().c_str());
696	return error;
697	}
698
699	// parse operation
700	auto operation_end_pos = rule_text.find(Str: " ", From: attribute_end_pos + 1);
701	auto operation = rule_text.substr(
702	Start: attribute_end_pos + 1, N: operation_end_pos - (attribute_end_pos + 1));
703
704	// add filter spec
705	auto rule_sp = FilterRule::CreateRule(
706	accept, attribute_index, operation,
707	std::string(rule_text.substr(Start: operation_end_pos + 1)), error);
708
709	if (rule_sp && error.Success())
710	m_filter_rules.push_back(rule_sp);
711
712	return error;
713	}
714
715	int MatchAttributeIndex(llvm::StringRef attribute_name) const {
716	for (const auto &Item : llvm::enumerate(s_filter_attributes)) {
717	if (attribute_name == Item.value())
718	return Item.index();
719	}
720
721	// We didn't match anything.
722	return -1;
723	}
724
725	bool m_include_debug_level = false;
726	bool m_include_info_level = false;
727	bool m_include_any_process = false;
728	bool m_filter_fall_through_accepts;
729	bool m_echo_to_stderr = false;
730	bool m_display_timestamp_relative = false;
731	bool m_display_subsystem = false;
732	bool m_display_category = false;
733	bool m_display_activity_chain = false;
734	bool m_broadcast_events = true;
735	bool m_live_stream = true;
736	FilterRules m_filter_rules;
737	};
738
739	class EnableCommand : public CommandObjectParsed {
740	public:
741	EnableCommand(CommandInterpreter &interpreter, bool enable, const char *name,
742	const char *help, const char *syntax)
743	: CommandObjectParsed(interpreter, name, help, syntax), m_enable(enable),
744	m_options_sp(enable ? new EnableOptions() : nullptr) {}
745
746	protected:
747	void AppendStrictSourcesWarning(CommandReturnObject &result,
748	const char *source_name) {
749	if (!source_name)
750	return;
751
752	// Check if we're *not* using strict sources. If not, then the user is
753	// going to get debug-level info anyways, probably not what they're
754	// expecting. Unfortunately we can only fix this by adding an env var,
755	// which would have had to have happened already. Thus, a warning is the
756	// best we can do here.
757	StreamString stream;
758	stream.Printf(format: "darwin-log source settings specify to exclude "
759	"%s messages, but setting "
760	"'plugin.structured-data.darwin-log."
761	"strict-sources' is disabled. This process will "
762	"automatically have %s messages included. Enable"
763	" the property and relaunch the target binary to have"
764	" these messages excluded.",
765	source_name, source_name);
766	result.AppendWarning(in_string: stream.GetString());
767	}
768
769	void DoExecute(Args &command, CommandReturnObject &result) override {
770	// First off, set the global sticky state of enable/disable based on this
771	// command execution.
772	s_is_explicitly_enabled = m_enable;
773
774	// Next, if this is an enable, save off the option data. We will need it
775	// later if a process hasn't been launched or attached yet.
776	if (m_enable) {
777	// Save off enabled configuration so we can apply these parsed options
778	// the next time an attach or launch occurs.
779	DebuggerSP debugger_sp =
780	GetCommandInterpreter().GetDebugger().shared_from_this();
781	SetGlobalEnableOptions(debugger_sp, options_sp: m_options_sp);
782	}
783
784	// Now check if we have a running process. If so, we should instruct the
785	// process monitor to enable/disable DarwinLog support now.
786	Target &target = GetSelectedOrDummyTarget();
787
788	// Grab the active process.
789	auto process_sp = target.GetProcessSP();
790	if (!process_sp) {
791	// No active process, so there is nothing more to do right now.
792	result.SetStatus(eReturnStatusSuccessFinishNoResult);
793	return;
794	}
795
796	// If the process is no longer alive, we can't do this now. We'll catch it
797	// the next time the process is started up.
798	if (!process_sp->IsAlive()) {
799	result.SetStatus(eReturnStatusSuccessFinishNoResult);
800	return;
801	}
802
803	// Get the plugin for the process.
804	auto plugin_sp =
805	process_sp->GetStructuredDataPlugin(type_name: GetDarwinLogTypeName());
806	if (!plugin_sp || (plugin_sp->GetPluginName() !=
807	StructuredDataDarwinLog::GetStaticPluginName())) {
808	result.AppendError(in_string: "failed to get StructuredDataPlugin for "
809	"the process");
810	}
811	StructuredDataDarwinLog &plugin =
812	*static_cast<StructuredDataDarwinLog *>(plugin_sp.get());
813
814	if (m_enable) {
815	// Hook up the breakpoint for the process that detects when libtrace has
816	// been sufficiently initialized to really start the os_log stream. This
817	// is insurance to assure us that logging is really enabled. Requesting
818	// that logging be enabled for a process before libtrace is initialized
819	// results in a scenario where no errors occur, but no logging is
820	// captured, either. This step is to eliminate that possibility.
821	plugin.AddInitCompletionHook(process&: *process_sp);
822	}
823
824	// Send configuration to the feature by way of the process. Construct the
825	// options we will use.
826	auto config_sp = m_options_sp->BuildConfigurationData(m_enable);
827	const Status error =
828	process_sp->ConfigureStructuredData(type_name: GetDarwinLogTypeName(), config_sp: config_sp);
829
830	// Report results.
831	if (!error.Success()) {
832	result.AppendError(in_string: error.AsCString());
833	// Our configuration failed, so we're definitely disabled.
834	plugin.SetEnabled(false);
835	} else {
836	result.SetStatus(eReturnStatusSuccessFinishNoResult);
837	// Our configuration succeeded, so we're enabled/disabled per whichever
838	// one this command is setup to do.
839	plugin.SetEnabled(m_enable);
840	}
841	}
842
843	Options *GetOptions() override {
844	// We don't have options when this represents disable.
845	return m_enable ? m_options_sp.get() : nullptr;
846	}
847
848	private:
849	const bool m_enable;
850	EnableOptionsSP m_options_sp;
851	};
852
853	/// Provides the status command.
854	class StatusCommand : public CommandObjectParsed {
855	public:
856	StatusCommand(CommandInterpreter &interpreter)
857	: CommandObjectParsed(interpreter, "status",
858	"Show whether Darwin log supported is available"
859	" and enabled.",
860	"plugin structured-data darwin-log status") {}
861
862	protected:
863	void DoExecute(Args &command, CommandReturnObject &result) override {
864	auto &stream = result.GetOutputStream();
865
866	// Figure out if we've got a process. If so, we can tell if DarwinLog is
867	// available for that process.
868	Target &target = GetSelectedOrDummyTarget();
869	auto process_sp = target.GetProcessSP();
870	if (!process_sp) {
871	stream.PutCString(cstr: "Availability: unknown (requires process)\n");
872	stream.PutCString(cstr: "Enabled: not applicable "
873	"(requires process)\n");
874	} else {
875	auto plugin_sp =
876	process_sp->GetStructuredDataPlugin(type_name: GetDarwinLogTypeName());
877	stream.Printf(format: "Availability: %s\n",
878	plugin_sp ? "available" : "unavailable");
879	const bool enabled =
880	plugin_sp ? plugin_sp->GetEnabled(
881	type_name: StructuredDataDarwinLog::GetStaticPluginName())
882	: false;
883	stream.Printf(format: "Enabled: %s\n", enabled ? "true" : "false");
884	}
885
886	// Display filter settings.
887	DebuggerSP debugger_sp =
888	GetCommandInterpreter().GetDebugger().shared_from_this();
889	auto options_sp = GetGlobalEnableOptions(debugger_sp);
890	if (!options_sp) {
891	// Nothing more to do.
892	result.SetStatus(eReturnStatusSuccessFinishResult);
893	return;
894	}
895
896	// Print filter rules
897	stream.PutCString(cstr: "DarwinLog filter rules:\n");
898
899	stream.IndentMore();
900
901	if (options_sp->GetFilterRules().empty()) {
902	stream.Indent();
903	stream.PutCString(cstr: "none\n");
904	} else {
905	// Print each of the filter rules.
906	int rule_number = 0;
907	for (auto rule_sp : options_sp->GetFilterRules()) {
908	++rule_number;
909	if (!rule_sp)
910	continue;
911
912	stream.Indent();
913	stream.Printf("%02d: ", rule_number);
914	rule_sp->Dump(stream);
915	stream.PutChar('\n');
916	}
917	}
918	stream.IndentLess();
919
920	// Print no-match handling.
921	stream.Indent();
922	stream.Printf(format: "no-match behavior: %s\n",
923	options_sp->GetFallthroughAccepts() ? "accept" : "reject");
924
925	result.SetStatus(eReturnStatusSuccessFinishResult);
926	}
927	};
928
929	/// Provides the darwin-log base command
930	class BaseCommand : public CommandObjectMultiword {
931	public:
932	BaseCommand(CommandInterpreter &interpreter)
933	: CommandObjectMultiword(interpreter, "plugin structured-data darwin-log",
934	"Commands for configuring Darwin os_log "
935	"support.",
936	"") {
937	// enable
938	auto enable_help = "Enable Darwin log collection, or re-enable "
939	"with modified configuration.";
940	auto enable_syntax = "plugin structured-data darwin-log enable";
941	auto enable_cmd_sp = CommandObjectSP(
942	new EnableCommand(interpreter,
943	true, // enable
944	"enable", enable_help, enable_syntax));
945	LoadSubCommand(cmd_name: "enable", command_obj: enable_cmd_sp);
946
947	// disable
948	auto disable_help = "Disable Darwin log collection.";
949	auto disable_syntax = "plugin structured-data darwin-log disable";
950	auto disable_cmd_sp = CommandObjectSP(
951	new EnableCommand(interpreter,
952	false, // disable
953	"disable", disable_help, disable_syntax));
954	LoadSubCommand(cmd_name: "disable", command_obj: disable_cmd_sp);
955
956	// status
957	auto status_cmd_sp = CommandObjectSP(new StatusCommand(interpreter));
958	LoadSubCommand(cmd_name: "status", command_obj: status_cmd_sp);
959	}
960	};
961
962	EnableOptionsSP ParseAutoEnableOptions(Status &error, Debugger &debugger) {
963	Log *log = GetLog(LLDBLog::Process);
964	// We are abusing the options data model here so that we can parse options
965	// without requiring the Debugger instance.
966
967	// We have an empty execution context at this point. We only want to parse
968	// options, and we don't need any context to do this here. In fact, we want
969	// to be able to parse the enable options before having any context.
970	ExecutionContext exe_ctx;
971
972	EnableOptionsSP options_sp(new EnableOptions());
973	options_sp->NotifyOptionParsingStarting(&exe_ctx);
974
975	CommandReturnObject result(debugger.GetUseColor());
976
977	// Parse the arguments.
978	auto options_property_sp =
979	debugger.GetPropertyValue(exe_ctx: nullptr,
980	property_path: "plugin.structured-data.darwin-log."
981	"auto-enable-options",
982	error);
983	if (!error.Success())
984	return EnableOptionsSP();
985	if (!options_property_sp) {
986	error.SetErrorString("failed to find option setting for "
987	"plugin.structured-data.darwin-log.");
988	return EnableOptionsSP();
989	}
990
991	const char *enable_options =
992	options_property_sp->GetAsString()->GetCurrentValue();
993	Args args(enable_options);
994	if (args.GetArgumentCount() > 0) {
995	// Eliminate the initial '--' that would be required to set the settings
996	// that themselves include '-' and/or '--'.
997	const char *first_arg = args.GetArgumentAtIndex(idx: 0);
998	if (first_arg && (strcmp(s1: first_arg, s2: "--") == 0))
999	args.Shift();
1000	}
1001
1002	bool require_validation = false;
1003	llvm::Expected<Args> args_or =
1004	options_sp->Parse(args, &exe_ctx, PlatformSP(), require_validation);
1005	if (!args_or) {
1006	LLDB_LOG_ERROR(
1007	log, args_or.takeError(),
1008	"Parsing plugin.structured-data.darwin-log.auto-enable-options value "
1009	"failed: {0}");
1010	return EnableOptionsSP();
1011	}
1012
1013	if (!options_sp->VerifyOptions(result))
1014	return EnableOptionsSP();
1015
1016	// We successfully parsed and validated the options.
1017	return options_sp;
1018	}
1019
1020	bool RunEnableCommand(CommandInterpreter &interpreter) {
1021	StreamString command_stream;
1022
1023	command_stream << "plugin structured-data darwin-log enable";
1024	auto enable_options = GetGlobalProperties().GetAutoEnableOptions();
1025	if (!enable_options.empty()) {
1026	command_stream << ' ';
1027	command_stream << enable_options;
1028	}
1029
1030	// Run the command.
1031	CommandReturnObject return_object(interpreter.GetDebugger().GetUseColor());
1032	interpreter.HandleCommand(command_line: command_stream.GetData(), add_to_history: eLazyBoolNo,
1033	result&: return_object);
1034	return return_object.Succeeded();
1035	}
1036	}
1037	using namespace sddarwinlog_private;
1038
1039	#pragma mark -
1040	#pragma mark Public static API
1041
1042	// Public static API
1043
1044	void StructuredDataDarwinLog::Initialize() {
1045	RegisterFilterOperations();
1046	PluginManager::RegisterPlugin(
1047	name: GetStaticPluginName(), description: "Darwin os_log() and os_activity() support",
1048	create_callback: &CreateInstance, debugger_init_callback: &DebuggerInitialize, filter_callback: &FilterLaunchInfo);
1049	}
1050
1051	void StructuredDataDarwinLog::Terminate() {
1052	PluginManager::UnregisterPlugin(create_callback: &CreateInstance);
1053	}
1054
1055	#pragma mark -
1056	#pragma mark StructuredDataPlugin API
1057
1058	// StructuredDataPlugin API
1059
1060	bool StructuredDataDarwinLog::SupportsStructuredDataType(
1061	llvm::StringRef type_name) {
1062	return type_name == GetDarwinLogTypeName();
1063	}
1064
1065	void StructuredDataDarwinLog::HandleArrivalOfStructuredData(
1066	Process &process, llvm::StringRef type_name,
1067	const StructuredData::ObjectSP &object_sp) {
1068	Log *log = GetLog(mask: LLDBLog::Process);
1069	if (log) {
1070	StreamString json_stream;
1071	if (object_sp)
1072	object_sp->Dump(s&: json_stream);
1073	else
1074	json_stream.PutCString(cstr: "<null>");
1075	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called with json: %s",
1076	__FUNCTION__, json_stream.GetData());
1077	}
1078
1079	// Ignore empty structured data.
1080	if (!object_sp) {
1081	LLDB_LOGF(log,
1082	"StructuredDataDarwinLog::%s() StructuredData object "
1083	"is null",
1084	__FUNCTION__);
1085	return;
1086	}
1087
1088	// Ignore any data that isn't for us.
1089	if (type_name != GetDarwinLogTypeName()) {
1090	LLDB_LOG(log,
1091	"StructuredData type expected to be {0} but was {1}, ignoring",
1092	GetDarwinLogTypeName(), type_name);
1093	return;
1094	}
1095
1096	// Broadcast the structured data event if we have that enabled. This is the
1097	// way that the outside world (all clients) get access to this data. This
1098	// plugin sets policy as to whether we do that.
1099	DebuggerSP debugger_sp = process.GetTarget().GetDebugger().shared_from_this();
1100	auto options_sp = GetGlobalEnableOptions(debugger_sp);
1101	if (options_sp && options_sp->GetBroadcastEvents()) {
1102	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() broadcasting event",
1103	__FUNCTION__);
1104	process.BroadcastStructuredData(object_sp, plugin_sp: shared_from_this());
1105	}
1106
1107	// Later, hang on to a configurable amount of these and allow commands to
1108	// inspect, including showing backtraces.
1109	}
1110
1111	static void SetErrorWithJSON(Status &error, const char *message,
1112	StructuredData::Object &object) {
1113	if (!message) {
1114	error.SetErrorString("Internal error: message not set.");
1115	return;
1116	}
1117
1118	StreamString object_stream;
1119	object.Dump(s&: object_stream);
1120	object_stream.Flush();
1121
1122	error.SetErrorStringWithFormat("%s: %s", message, object_stream.GetData());
1123	}
1124
1125	Status StructuredDataDarwinLog::GetDescription(
1126	const StructuredData::ObjectSP &object_sp, lldb_private::Stream &stream) {
1127	Status error;
1128
1129	if (!object_sp) {
1130	error.SetErrorString("No structured data.");
1131	return error;
1132	}
1133
1134	// Log message payload objects will be dictionaries.
1135	const StructuredData::Dictionary *dictionary = object_sp->GetAsDictionary();
1136	if (!dictionary) {
1137	SetErrorWithJSON(error, message: "Structured data should have been a dictionary "
1138	"but wasn't",
1139	object&: *object_sp);
1140	return error;
1141	}
1142
1143	// Validate this is really a message for our plugin.
1144	llvm::StringRef type_name;
1145	if (!dictionary->GetValueForKeyAsString(key: "type", result&: type_name)) {
1146	SetErrorWithJSON(error, message: "Structured data doesn't contain mandatory "
1147	"type field",
1148	object&: *object_sp);
1149	return error;
1150	}
1151
1152	if (type_name != GetDarwinLogTypeName()) {
1153	// This is okay - it simply means the data we received is not a log
1154	// message. We'll just format it as is.
1155	object_sp->Dump(s&: stream);
1156	return error;
1157	}
1158
1159	// DarwinLog dictionaries store their data
1160	// in an array with key name "events".
1161	StructuredData::Array *events = nullptr;
1162	if (!dictionary->GetValueForKeyAsArray(key: "events", result&: events) || !events) {
1163	SetErrorWithJSON(error, message: "Log structured data is missing mandatory "
1164	"'events' field, expected to be an array",
1165	object&: *object_sp);
1166	return error;
1167	}
1168
1169	events->ForEach(
1170	foreach_callback: [&stream, &error, &object_sp, this](StructuredData::Object *object) {
1171	if (!object) {
1172	// Invalid. Stop iterating.
1173	SetErrorWithJSON(error, message: "Log event entry is null", object&: *object_sp);
1174	return false;
1175	}
1176
1177	auto event = object->GetAsDictionary();
1178	if (!event) {
1179	// Invalid, stop iterating.
1180	SetErrorWithJSON(error, message: "Log event is not a dictionary", object&: *object_sp);
1181	return false;
1182	}
1183
1184	// If we haven't already grabbed the first timestamp value, do that
1185	// now.
1186	if (!m_recorded_first_timestamp) {
1187	uint64_t timestamp = 0;
1188	if (event->GetValueForKeyAsInteger(key: "timestamp", result&: timestamp)) {
1189	m_first_timestamp_seen = timestamp;
1190	m_recorded_first_timestamp = true;
1191	}
1192	}
1193
1194	HandleDisplayOfEvent(event: *event, stream);
1195	return true;
1196	});
1197
1198	stream.Flush();
1199	return error;
1200	}
1201
1202	bool StructuredDataDarwinLog::GetEnabled(llvm::StringRef type_name) const {
1203	if (type_name == GetStaticPluginName())
1204	return m_is_enabled;
1205	return false;
1206	}
1207
1208	void StructuredDataDarwinLog::SetEnabled(bool enabled) {
1209	m_is_enabled = enabled;
1210	}
1211
1212	void StructuredDataDarwinLog::ModulesDidLoad(Process &process,
1213	ModuleList &module_list) {
1214	Log *log = GetLog(mask: LLDBLog::Process);
1215	LLDB_LOGF(log, "StructuredDataDarwinLog::%s called (process uid %u)",
1216	__FUNCTION__, process.GetUniqueID());
1217
1218	// Check if we should enable the darwin log support on startup/attach.
1219	if (!GetGlobalProperties().GetEnableOnStartup() &&
1220	!s_is_explicitly_enabled) {
1221	// We're neither auto-enabled or explicitly enabled, so we shouldn't try to
1222	// enable here.
1223	LLDB_LOGF(log,
1224	"StructuredDataDarwinLog::%s not applicable, we're not "
1225	"enabled (process uid %u)",
1226	__FUNCTION__, process.GetUniqueID());
1227	return;
1228	}
1229
1230	// If we already added the breakpoint, we've got nothing left to do.
1231	{
1232	std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);
1233	if (m_added_breakpoint) {
1234	LLDB_LOGF(log,
1235	"StructuredDataDarwinLog::%s process uid %u's "
1236	"post-libtrace-init breakpoint is already set",
1237	__FUNCTION__, process.GetUniqueID());
1238	return;
1239	}
1240	}
1241
1242	// The logging support module name, specifies the name of the image name that
1243	// must be loaded into the debugged process before we can try to enable
1244	// logging.
1245	const char *logging_module_cstr =
1246	GetGlobalProperties().GetLoggingModuleName();
1247	if (!logging_module_cstr || (logging_module_cstr[0] == 0)) {
1248	// We need this. Bail.
1249	LLDB_LOGF(log,
1250	"StructuredDataDarwinLog::%s no logging module name "
1251	"specified, we don't know where to set a breakpoint "
1252	"(process uid %u)",
1253	__FUNCTION__, process.GetUniqueID());
1254	return;
1255	}
1256
1257	// We need to see libtrace in the list of modules before we can enable
1258	// tracing for the target process.
1259	bool found_logging_support_module = false;
1260	for (size_t i = 0; i < module_list.GetSize(); ++i) {
1261	auto module_sp = module_list.GetModuleAtIndex(idx: i);
1262	if (!module_sp)
1263	continue;
1264
1265	auto &file_spec = module_sp->GetFileSpec();
1266	found_logging_support_module =
1267	(file_spec.GetFilename() == logging_module_cstr);
1268	if (found_logging_support_module)
1269	break;
1270	}
1271
1272	if (!found_logging_support_module) {
1273	LLDB_LOGF(log,
1274	"StructuredDataDarwinLog::%s logging module %s "
1275	"has not yet been loaded, can't set a breakpoint "
1276	"yet (process uid %u)",
1277	__FUNCTION__, logging_module_cstr, process.GetUniqueID());
1278	return;
1279	}
1280
1281	// Time to enqueue the breakpoint so we can wait for logging support to be
1282	// initialized before we try to tap the libtrace stream.
1283	AddInitCompletionHook(process);
1284	LLDB_LOGF(log,
1285	"StructuredDataDarwinLog::%s post-init hook breakpoint "
1286	"set for logging module %s (process uid %u)",
1287	__FUNCTION__, logging_module_cstr, process.GetUniqueID());
1288
1289	// We need to try the enable here as well, which will succeed in the event
1290	// that we're attaching to (rather than launching) the process and the
1291	// process is already past initialization time. In that case, the completion
1292	// breakpoint will never get hit and therefore won't start that way. It
1293	// doesn't hurt much beyond a bit of bandwidth if we end up doing this twice.
1294	// It hurts much more if we don't get the logging enabled when the user
1295	// expects it.
1296	EnableNow();
1297	}
1298
1299	// public destructor
1300
1301	StructuredDataDarwinLog::~StructuredDataDarwinLog() {
1302	if (m_breakpoint_id != LLDB_INVALID_BREAK_ID) {
1303	ProcessSP process_sp(GetProcess());
1304	if (process_sp) {
1305	process_sp->GetTarget().RemoveBreakpointByID(break_id: m_breakpoint_id);
1306	m_breakpoint_id = LLDB_INVALID_BREAK_ID;
1307	}
1308	}
1309	}
1310
1311	#pragma mark -
1312	#pragma mark Private instance methods
1313
1314	// Private constructors
1315
1316	StructuredDataDarwinLog::StructuredDataDarwinLog(const ProcessWP &process_wp)
1317	: StructuredDataPlugin(process_wp), m_recorded_first_timestamp(false),
1318	m_first_timestamp_seen(0), m_is_enabled(false),
1319	m_added_breakpoint_mutex(), m_added_breakpoint(),
1320	m_breakpoint_id(LLDB_INVALID_BREAK_ID) {}
1321
1322	// Private static methods
1323
1324	StructuredDataPluginSP
1325	StructuredDataDarwinLog::CreateInstance(Process &process) {
1326	// Currently only Apple targets support the os_log/os_activity protocol.
1327	if (process.GetTarget().GetArchitecture().GetTriple().getVendor() ==
1328	llvm::Triple::VendorType::Apple) {
1329	auto process_wp = ProcessWP(process.shared_from_this());
1330	return StructuredDataPluginSP(new StructuredDataDarwinLog(process_wp));
1331	} else {
1332	return StructuredDataPluginSP();
1333	}
1334	}
1335
1336	void StructuredDataDarwinLog::DebuggerInitialize(Debugger &debugger) {
1337	// Setup parent class first.
1338	StructuredDataPlugin::InitializeBasePluginForDebugger(debugger);
1339
1340	// Get parent command.
1341	auto &interpreter = debugger.GetCommandInterpreter();
1342	llvm::StringRef parent_command_text = "plugin structured-data";
1343	auto parent_command =
1344	interpreter.GetCommandObjectForCommand(command_line&: parent_command_text);
1345	if (!parent_command) {
1346	// Ut oh, parent failed to create parent command.
1347	// TODO log
1348	return;
1349	}
1350
1351	auto command_name = "darwin-log";
1352	auto command_sp = CommandObjectSP(new BaseCommand(interpreter));
1353	bool result = parent_command->LoadSubCommand(cmd_name: command_name, command_obj: command_sp);
1354	if (!result) {
1355	// TODO log it once we setup structured data logging
1356	}
1357
1358	if (!PluginManager::GetSettingForPlatformPlugin(
1359	debugger, setting_name: StructuredDataDarwinLogProperties::GetSettingName())) {
1360	const bool is_global_setting = true;
1361	PluginManager::CreateSettingForStructuredDataPlugin(
1362	debugger, properties_sp: GetGlobalProperties().GetValueProperties(),
1363	description: "Properties for the darwin-log plug-in.", is_global_property: is_global_setting);
1364	}
1365	}
1366
1367	Status StructuredDataDarwinLog::FilterLaunchInfo(ProcessLaunchInfo &launch_info,
1368	Target *target) {
1369	Status error;
1370
1371	// If we're not debugging this launched process, there's nothing for us to do
1372	// here.
1373	if (!launch_info.GetFlags().AnySet(mask: eLaunchFlagDebug))
1374	return error;
1375
1376	// Darwin os_log() support automatically adds debug-level and info-level
1377	// messages when a debugger is attached to a process. However, with
1378	// integrated support for debugging built into the command-line LLDB, the
1379	// user may specifically set to *not* include debug-level and info-level
1380	// content. When the user is using the integrated log support, we want to
1381	// put the kabosh on that automatic adding of info and debug level. This is
1382	// done by adding an environment variable to the process on launch. (This
1383	// also means it is not possible to suppress this behavior if attaching to an
1384	// already-running app).
1385	// Log *log = GetLog(LLDBLog::Platform);
1386
1387	// If the target architecture is not one that supports DarwinLog, we have
1388	// nothing to do here.
1389	auto &triple = target ? target->GetArchitecture().GetTriple()
1390	: launch_info.GetArchitecture().GetTriple();
1391	if (triple.getVendor() != llvm::Triple::Apple) {
1392	return error;
1393	}
1394
1395	// If DarwinLog is not enabled (either by explicit user command or via the
1396	// auto-enable option), then we have nothing to do.
1397	if (!GetGlobalProperties().GetEnableOnStartup() &&
1398	!s_is_explicitly_enabled) {
1399	// Nothing to do, DarwinLog is not enabled.
1400	return error;
1401	}
1402
1403	// If we don't have parsed configuration info, that implies we have enable-
1404	// on-startup set up, but we haven't yet attempted to run the enable command.
1405	if (!target) {
1406	// We really can't do this without a target. We need to be able to get to
1407	// the debugger to get the proper options to do this right.
1408	// TODO log.
1409	error.SetErrorString("requires a target to auto-enable DarwinLog.");
1410	return error;
1411	}
1412
1413	DebuggerSP debugger_sp = target->GetDebugger().shared_from_this();
1414	auto options_sp = GetGlobalEnableOptions(debugger_sp);
1415	if (!options_sp && debugger_sp) {
1416	options_sp = ParseAutoEnableOptions(error, debugger&: *debugger_sp.get());
1417	if (!options_sp || !error.Success())
1418	return error;
1419
1420	// We already parsed the options, save them now so we don't generate them
1421	// again until the user runs the command manually.
1422	SetGlobalEnableOptions(debugger_sp, options_sp);
1423	}
1424
1425	if (!options_sp->GetEchoToStdErr()) {
1426	// The user doesn't want to see os_log/NSLog messages echo to stderr. That
1427	// mechanism is entirely separate from the DarwinLog support. By default we
1428	// don't want to get it via stderr, because that would be in duplicate of
1429	// the explicit log support here.
1430
1431	// Here we need to strip out any OS_ACTIVITY_DT_MODE setting to prevent
1432	// echoing of os_log()/NSLog() to stderr in the target program.
1433	launch_info.GetEnvironment().erase(Key: "OS_ACTIVITY_DT_MODE");
1434
1435	// We will also set the env var that tells any downstream launcher from
1436	// adding OS_ACTIVITY_DT_MODE.
1437	launch_info.GetEnvironment()["IDE_DISABLED_OS_ACTIVITY_DT_MODE"] = "1";
1438	}
1439
1440	// Set the OS_ACTIVITY_MODE env var appropriately to enable/disable debug and
1441	// info level messages.
1442	const char *env_var_value;
1443	if (options_sp->GetIncludeDebugLevel())
1444	env_var_value = "debug";
1445	else if (options_sp->GetIncludeInfoLevel())
1446	env_var_value = "info";
1447	else
1448	env_var_value = "default";
1449
1450	launch_info.GetEnvironment()["OS_ACTIVITY_MODE"] = env_var_value;
1451
1452	return error;
1453	}
1454
1455	bool StructuredDataDarwinLog::InitCompletionHookCallback(
1456	void *baton, StoppointCallbackContext *context, lldb::user_id_t break_id,
1457	lldb::user_id_t break_loc_id) {
1458	// We hit the init function. We now want to enqueue our new thread plan,
1459	// which will in turn enqueue a StepOut thread plan. When the StepOut
1460	// finishes and control returns to our new thread plan, that is the time when
1461	// we can execute our logic to enable the logging support.
1462
1463	Log *log = GetLog(mask: LLDBLog::Process);
1464	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called", __FUNCTION__);
1465
1466	// Get the current thread.
1467	if (!context) {
1468	LLDB_LOGF(log,
1469	"StructuredDataDarwinLog::%s() warning: no context, "
1470	"ignoring",
1471	__FUNCTION__);
1472	return false;
1473	}
1474
1475	// Get the plugin from the process.
1476	auto process_sp = context->exe_ctx_ref.GetProcessSP();
1477	if (!process_sp) {
1478	LLDB_LOGF(log,
1479	"StructuredDataDarwinLog::%s() warning: invalid "
1480	"process in context, ignoring",
1481	__FUNCTION__);
1482	return false;
1483	}
1484	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() call is for process uid %d",
1485	__FUNCTION__, process_sp->GetUniqueID());
1486
1487	auto plugin_sp = process_sp->GetStructuredDataPlugin(type_name: GetDarwinLogTypeName());
1488	if (!plugin_sp) {
1489	LLDB_LOG(log, "warning: no plugin for feature {0} in process uid {1}",
1490	GetDarwinLogTypeName(), process_sp->GetUniqueID());
1491	return false;
1492	}
1493
1494	// Create the callback for when the thread plan completes.
1495	bool called_enable_method = false;
1496	const auto process_uid = process_sp->GetUniqueID();
1497
1498	std::weak_ptr<StructuredDataPlugin> plugin_wp(plugin_sp);
1499	ThreadPlanCallOnFunctionExit::Callback callback =
1500	[plugin_wp, &called_enable_method, log, process_uid]() {
1501	LLDB_LOGF(log,
1502	"StructuredDataDarwinLog::post-init callback: "
1503	"called (process uid %u)",
1504	process_uid);
1505
1506	auto strong_plugin_sp = plugin_wp.lock();
1507	if (!strong_plugin_sp) {
1508	LLDB_LOGF(log,
1509	"StructuredDataDarwinLog::post-init callback: "
1510	"plugin no longer exists, ignoring (process "
1511	"uid %u)",
1512	process_uid);
1513	return;
1514	}
1515	// Make sure we only call it once, just in case the thread plan hits
1516	// the breakpoint twice.
1517	if (!called_enable_method) {
1518	LLDB_LOGF(log,
1519	"StructuredDataDarwinLog::post-init callback: "
1520	"calling EnableNow() (process uid %u)",
1521	process_uid);
1522	static_cast<StructuredDataDarwinLog *>(strong_plugin_sp.get())
1523	->EnableNow();
1524	called_enable_method = true;
1525	} else {
1526	// Our breakpoint was hit more than once. Unexpected but no harm
1527	// done. Log it.
1528	LLDB_LOGF(log,
1529	"StructuredDataDarwinLog::post-init callback: "
1530	"skipping EnableNow(), already called by "
1531	"callback [we hit this more than once] "
1532	"(process uid %u)",
1533	process_uid);
1534	}
1535	};
1536
1537	// Grab the current thread.
1538	auto thread_sp = context->exe_ctx_ref.GetThreadSP();
1539	if (!thread_sp) {
1540	LLDB_LOGF(log,
1541	"StructuredDataDarwinLog::%s() warning: failed to "
1542	"retrieve the current thread from the execution "
1543	"context, nowhere to run the thread plan (process uid "
1544	"%u)",
1545	__FUNCTION__, process_sp->GetUniqueID());
1546	return false;
1547	}
1548
1549	// Queue the thread plan.
1550	auto thread_plan_sp =
1551	ThreadPlanSP(new ThreadPlanCallOnFunctionExit(*thread_sp, callback));
1552	const bool abort_other_plans = false;
1553	thread_sp->QueueThreadPlan(plan_sp&: thread_plan_sp, abort_other_plans);
1554	LLDB_LOGF(log,
1555	"StructuredDataDarwinLog::%s() queuing thread plan on "
1556	"trace library init method entry (process uid %u)",
1557	__FUNCTION__, process_sp->GetUniqueID());
1558
1559	// We return false here to indicate that it isn't a public stop.
1560	return false;
1561	}
1562
1563	void StructuredDataDarwinLog::AddInitCompletionHook(Process &process) {
1564	Log *log = GetLog(mask: LLDBLog::Process);
1565	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called (process uid %u)",
1566	__FUNCTION__, process.GetUniqueID());
1567
1568	// Make sure we haven't already done this.
1569	{
1570	std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);
1571	if (m_added_breakpoint) {
1572	LLDB_LOGF(log,
1573	"StructuredDataDarwinLog::%s() ignoring request, "
1574	"breakpoint already set (process uid %u)",
1575	__FUNCTION__, process.GetUniqueID());
1576	return;
1577	}
1578
1579	// We're about to do this, don't let anybody else try to do it.
1580	m_added_breakpoint = true;
1581	}
1582
1583	// Set a breakpoint for the process that will kick in when libtrace has
1584	// finished its initialization.
1585	Target &target = process.GetTarget();
1586
1587	// Build up the module list.
1588	FileSpecList module_spec_list;
1589	auto module_file_spec =
1590	FileSpec(GetGlobalProperties().GetLoggingModuleName());
1591	module_spec_list.Append(file: module_file_spec);
1592
1593	// We aren't specifying a source file set.
1594	FileSpecList *source_spec_list = nullptr;
1595
1596	const char *func_name = "_libtrace_init";
1597	const lldb::addr_t offset = 0;
1598	const LazyBool skip_prologue = eLazyBoolCalculate;
1599	// This is an internal breakpoint - the user shouldn't see it.
1600	const bool internal = true;
1601	const bool hardware = false;
1602
1603	auto breakpoint_sp = target.CreateBreakpoint(
1604	containingModules: &module_spec_list, containingSourceFiles: source_spec_list, func_name, func_name_type_mask: eFunctionNameTypeFull,
1605	language: eLanguageTypeC, offset, skip_prologue, internal, request_hardware: hardware);
1606	if (!breakpoint_sp) {
1607	// Huh? Bail here.
1608	LLDB_LOGF(log,
1609	"StructuredDataDarwinLog::%s() failed to set "
1610	"breakpoint in module %s, function %s (process uid %u)",
1611	__FUNCTION__, GetGlobalProperties().GetLoggingModuleName(),
1612	func_name, process.GetUniqueID());
1613	return;
1614	}
1615
1616	// Set our callback.
1617	breakpoint_sp->SetCallback(callback: InitCompletionHookCallback, baton: nullptr);
1618	m_breakpoint_id = breakpoint_sp->GetID();
1619	LLDB_LOGF(log,
1620	"StructuredDataDarwinLog::%s() breakpoint set in module %s,"
1621	"function %s (process uid %u)",
1622	__FUNCTION__, GetGlobalProperties().GetLoggingModuleName(),
1623	func_name, process.GetUniqueID());
1624	}
1625
1626	void StructuredDataDarwinLog::DumpTimestamp(Stream &stream,
1627	uint64_t timestamp) {
1628	const uint64_t delta_nanos = timestamp - m_first_timestamp_seen;
1629
1630	const uint64_t hours = delta_nanos / NANOS_PER_HOUR;
1631	uint64_t nanos_remaining = delta_nanos % NANOS_PER_HOUR;
1632
1633	const uint64_t minutes = nanos_remaining / NANOS_PER_MINUTE;
1634	nanos_remaining = nanos_remaining % NANOS_PER_MINUTE;
1635
1636	const uint64_t seconds = nanos_remaining / NANOS_PER_SECOND;
1637	nanos_remaining = nanos_remaining % NANOS_PER_SECOND;
1638
1639	stream.Printf(format: "%02" PRIu64 ":%02" PRIu64 ":%02" PRIu64 ".%09" PRIu64, hours,
1640	minutes, seconds, nanos_remaining);
1641	}
1642
1643	size_t
1644	StructuredDataDarwinLog::DumpHeader(Stream &output_stream,
1645	const StructuredData::Dictionary &event) {
1646	StreamString stream;
1647
1648	ProcessSP process_sp = GetProcess();
1649	if (!process_sp) {
1650	// TODO log
1651	return 0;
1652	}
1653
1654	DebuggerSP debugger_sp =
1655	process_sp->GetTarget().GetDebugger().shared_from_this();
1656	if (!debugger_sp) {
1657	// TODO log
1658	return 0;
1659	}
1660
1661	auto options_sp = GetGlobalEnableOptions(debugger_sp);
1662	if (!options_sp) {
1663	// TODO log
1664	return 0;
1665	}
1666
1667	// Check if we should even display a header.
1668	if (!options_sp->GetDisplayAnyHeaderFields())
1669	return 0;
1670
1671	stream.PutChar(ch: '[');
1672
1673	int header_count = 0;
1674	if (options_sp->GetDisplayTimestampRelative()) {
1675	uint64_t timestamp = 0;
1676	if (event.GetValueForKeyAsInteger(key: "timestamp", result&: timestamp)) {
1677	DumpTimestamp(stream, timestamp);
1678	++header_count;
1679	}
1680	}
1681
1682	if (options_sp->GetDisplayActivityChain()) {
1683	llvm::StringRef activity_chain;
1684	if (event.GetValueForKeyAsString(key: "activity-chain", result&: activity_chain) &&
1685	!activity_chain.empty()) {
1686	if (header_count > 0)
1687	stream.PutChar(ch: ',');
1688
1689	// Display the activity chain, from parent-most to child-most activity,
1690	// separated by a colon (:).
1691	stream.PutCString(cstr: "activity-chain=");
1692	stream.PutCString(cstr: activity_chain);
1693	++header_count;
1694	}
1695	}
1696
1697	if (options_sp->GetDisplaySubsystem()) {
1698	llvm::StringRef subsystem;
1699	if (event.GetValueForKeyAsString(key: "subsystem", result&: subsystem) &&
1700	!subsystem.empty()) {
1701	if (header_count > 0)
1702	stream.PutChar(ch: ',');
1703	stream.PutCString(cstr: "subsystem=");
1704	stream.PutCString(cstr: subsystem);
1705	++header_count;
1706	}
1707	}
1708
1709	if (options_sp->GetDisplayCategory()) {
1710	llvm::StringRef category;
1711	if (event.GetValueForKeyAsString(key: "category", result&: category) &&
1712	!category.empty()) {
1713	if (header_count > 0)
1714	stream.PutChar(ch: ',');
1715	stream.PutCString(cstr: "category=");
1716	stream.PutCString(cstr: category);
1717	++header_count;
1718	}
1719	}
1720	stream.PutCString(cstr: "] ");
1721
1722	output_stream.PutCString(cstr: stream.GetString());
1723
1724	return stream.GetSize();
1725	}
1726
1727	size_t StructuredDataDarwinLog::HandleDisplayOfEvent(
1728	const StructuredData::Dictionary &event, Stream &stream) {
1729	// Check the type of the event.
1730	llvm::StringRef event_type;
1731	if (!event.GetValueForKeyAsString(key: "type", result&: event_type)) {
1732	// Hmm, we expected to get events that describe what they are. Continue
1733	// anyway.
1734	return 0;
1735	}
1736
1737	if (event_type != GetLogEventType())
1738	return 0;
1739
1740	size_t total_bytes = 0;
1741
1742	// Grab the message content.
1743	llvm::StringRef message;
1744	if (!event.GetValueForKeyAsString(key: "message", result&: message))
1745	return true;
1746
1747	// Display the log entry.
1748	const auto len = message.size();
1749
1750	total_bytes += DumpHeader(output_stream&: stream, event);
1751
1752	stream.Write(src: message.data(), src_len: len);
1753	total_bytes += len;
1754
1755	// Add an end of line.
1756	stream.PutChar(ch: '\n');
1757	total_bytes += sizeof(char);
1758
1759	return total_bytes;
1760	}
1761
1762	void StructuredDataDarwinLog::EnableNow() {
1763	Log *log = GetLog(mask: LLDBLog::Process);
1764	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called", __FUNCTION__);
1765
1766	// Run the enable command.
1767	auto process_sp = GetProcess();
1768	if (!process_sp) {
1769	// Nothing to do.
1770	LLDB_LOGF(log,
1771	"StructuredDataDarwinLog::%s() warning: failed to get "
1772	"valid process, skipping",
1773	__FUNCTION__);
1774	return;
1775	}
1776	LLDB_LOGF(log, "StructuredDataDarwinLog::%s() call is for process uid %u",
1777	__FUNCTION__, process_sp->GetUniqueID());
1778
1779	// If we have configuration data, we can directly enable it now. Otherwise,
1780	// we need to run through the command interpreter to parse the auto-run
1781	// options (which is the only way we get here without having already-parsed
1782	// configuration data).
1783	DebuggerSP debugger_sp =
1784	process_sp->GetTarget().GetDebugger().shared_from_this();
1785	if (!debugger_sp) {
1786	LLDB_LOGF(log,
1787	"StructuredDataDarwinLog::%s() warning: failed to get "
1788	"debugger shared pointer, skipping (process uid %u)",
1789	__FUNCTION__, process_sp->GetUniqueID());
1790	return;
1791	}
1792
1793	auto options_sp = GetGlobalEnableOptions(debugger_sp);
1794	if (!options_sp) {
1795	// We haven't run the enable command yet. Just do that now, it'll take
1796	// care of the rest.
1797	auto &interpreter = debugger_sp->GetCommandInterpreter();
1798	const bool success = RunEnableCommand(interpreter);
1799	if (log) {
1800	if (success)
1801	LLDB_LOGF(log,
1802	"StructuredDataDarwinLog::%s() ran enable command "
1803	"successfully for (process uid %u)",
1804	__FUNCTION__, process_sp->GetUniqueID());
1805	else
1806	LLDB_LOGF(log,
1807	"StructuredDataDarwinLog::%s() error: running "
1808	"enable command failed (process uid %u)",
1809	__FUNCTION__, process_sp->GetUniqueID());
1810	}
1811	Debugger::ReportError(message: "failed to configure DarwinLog support",
1812	debugger_id: debugger_sp->GetID());
1813	return;
1814	}
1815
1816	// We've previously been enabled. We will re-enable now with the previously
1817	// specified options.
1818	auto config_sp = options_sp->BuildConfigurationData(true);
1819	if (!config_sp) {
1820	LLDB_LOGF(log,
1821	"StructuredDataDarwinLog::%s() warning: failed to "
1822	"build configuration data for enable options, skipping "
1823	"(process uid %u)",
1824	__FUNCTION__, process_sp->GetUniqueID());
1825	return;
1826	}
1827
1828	// We can run it directly.
1829	// Send configuration to the feature by way of the process.
1830	const Status error =
1831	process_sp->ConfigureStructuredData(type_name: GetDarwinLogTypeName(), config_sp: config_sp);
1832
1833	// Report results.
1834	if (!error.Success()) {
1835	LLDB_LOGF(log,
1836	"StructuredDataDarwinLog::%s() "
1837	"ConfigureStructuredData() call failed "
1838	"(process uid %u): %s",
1839	__FUNCTION__, process_sp->GetUniqueID(), error.AsCString());
1840	Debugger::ReportError(message: "failed to configure DarwinLog support",
1841	debugger_id: debugger_sp->GetID());
1842	m_is_enabled = false;
1843	} else {
1844	m_is_enabled = true;
1845	LLDB_LOGF(log,
1846	"StructuredDataDarwinLog::%s() success via direct "
1847	"configuration (process uid %u)",
1848	__FUNCTION__, process_sp->GetUniqueID());
1849	}
1850	}
1851