1 //===-- StructuredDataDarwinLog.cpp -----------------------------*- C++ -*-===//
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
7 //===----------------------------------------------------------------------===//
9 #include "StructuredDataDarwinLog.h"
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/Log.h"
32 #include "lldb/Utility/RegularExpression.h"
34 #define DARWIN_LOG_TYPE_VALUE "DarwinLog"
37 using namespace lldb_private;
40 #pragma mark Anonymous Namespace
42 // Anonymous namespace
44 namespace sddarwinlog_private {
45 const uint64_t NANOS_PER_MICRO = 1000;
46 const uint64_t NANOS_PER_MILLI = NANOS_PER_MICRO * 1000;
47 const uint64_t NANOS_PER_SECOND = NANOS_PER_MILLI * 1000;
48 const uint64_t NANOS_PER_MINUTE = NANOS_PER_SECOND * 60;
49 const uint64_t NANOS_PER_HOUR = NANOS_PER_MINUTE * 60;
51 static bool DEFAULT_FILTER_FALLTHROUGH_ACCEPTS = true;
53 /// Global, sticky enable switch. If true, the user has explicitly
54 /// run the enable command. When a process launches or is attached to,
55 /// we will enable DarwinLog if either the settings for auto-enable is
56 /// on, or if the user had explicitly run enable at some point prior
57 /// to the launch/attach.
58 static bool s_is_explicitly_enabled;
61 using EnableOptionsSP = std::shared_ptr<EnableOptions>;
64 std::map<DebuggerWP, EnableOptionsSP, std::owner_less<DebuggerWP>>;
66 static OptionsMap &GetGlobalOptionsMap() {
67 static OptionsMap s_options_map;
71 static std::mutex &GetGlobalOptionsMapLock() {
72 static std::mutex s_options_map_lock;
73 return s_options_map_lock;
76 EnableOptionsSP GetGlobalEnableOptions(const DebuggerSP &debugger_sp) {
78 return EnableOptionsSP();
80 std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());
81 OptionsMap &options_map = GetGlobalOptionsMap();
82 DebuggerWP debugger_wp(debugger_sp);
83 auto find_it = options_map.find(debugger_wp);
84 if (find_it != options_map.end())
85 return find_it->second;
87 return EnableOptionsSP();
90 void SetGlobalEnableOptions(const DebuggerSP &debugger_sp,
91 const EnableOptionsSP &options_sp) {
92 std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());
93 OptionsMap &options_map = GetGlobalOptionsMap();
94 DebuggerWP debugger_wp(debugger_sp);
95 auto find_it = options_map.find(debugger_wp);
96 if (find_it != options_map.end())
97 find_it->second = options_sp;
99 options_map.insert(std::make_pair(debugger_wp, options_sp));
103 #pragma mark Settings Handling
105 /// Code to handle the StructuredDataDarwinLog settings
107 static constexpr PropertyDefinition g_properties[] = {
109 "enable-on-startup", // name
110 OptionValue::eTypeBoolean, // type
112 false, // default uint value
113 nullptr, // default cstring value
115 "Enable Darwin os_log collection when debugged process is launched "
116 "or attached." // description
119 "auto-enable-options", // name
120 OptionValue::eTypeString, // type
122 0, // default uint value
123 "", // default cstring value
125 "Specify the options to 'plugin structured-data darwin-log enable' "
126 "that should be applied when automatically enabling logging on "
127 "startup/attach." // description
130 enum { ePropertyEnableOnStartup = 0, ePropertyAutoEnableOptions = 1 };
132 class StructuredDataDarwinLogProperties : public Properties {
134 static ConstString &GetSettingName() {
135 static ConstString g_setting_name("darwin-log");
136 return g_setting_name;
139 StructuredDataDarwinLogProperties() : Properties() {
140 m_collection_sp = std::make_shared<OptionValueProperties>(GetSettingName());
141 m_collection_sp->Initialize(g_properties);
144 ~StructuredDataDarwinLogProperties() override {}
146 bool GetEnableOnStartup() const {
147 const uint32_t idx = ePropertyEnableOnStartup;
148 return m_collection_sp->GetPropertyAtIndexAsBoolean(
149 nullptr, idx, g_properties[idx].default_uint_value != 0);
152 llvm::StringRef GetAutoEnableOptions() const {
153 const uint32_t idx = ePropertyAutoEnableOptions;
154 return m_collection_sp->GetPropertyAtIndexAsString(
155 nullptr, idx, g_properties[idx].default_cstr_value);
158 const char *GetLoggingModuleName() const { return "libsystem_trace.dylib"; }
161 using StructuredDataDarwinLogPropertiesSP =
162 std::shared_ptr<StructuredDataDarwinLogProperties>;
164 static const StructuredDataDarwinLogPropertiesSP &GetGlobalProperties() {
165 static StructuredDataDarwinLogPropertiesSP g_settings_sp;
167 g_settings_sp = std::make_shared<StructuredDataDarwinLogProperties>();
168 return g_settings_sp;
171 const char *const s_filter_attributes[] = {
172 "activity", // current activity
173 "activity-chain", // entire activity chain, each level separated by ':'
174 "category", // category of the log message
175 "message", // message contents, fully expanded
176 "subsystem" // subsystem of the log message
178 // Consider implementing this action as it would be cheaper to filter.
179 // "message" requires always formatting the message, which is a waste of
180 // cycles if it ends up being rejected. "format", // format string
181 // used to format message text
184 static ConstString GetDarwinLogTypeName() {
185 static const ConstString s_key_name("DarwinLog");
189 static ConstString GetLogEventType() {
190 static const ConstString s_event_type("log");
195 using FilterRuleSP = std::shared_ptr<FilterRule>;
199 virtual ~FilterRule() {}
201 using OperationCreationFunc =
202 std::function<FilterRuleSP(bool accept, size_t attribute_index,
203 const std::string &op_arg, Status &error)>;
205 static void RegisterOperation(ConstString operation,
206 const OperationCreationFunc &creation_func) {
207 GetCreationFuncMap().insert(std::make_pair(operation, creation_func));
210 static FilterRuleSP CreateRule(bool match_accepts, size_t attribute,
211 ConstString operation,
212 const std::string &op_arg, Status &error) {
213 // Find the creation func for this type of filter rule.
214 auto map = GetCreationFuncMap();
215 auto find_it = map.find(operation);
216 if (find_it == map.end()) {
217 error.SetErrorStringWithFormat("unknown filter operation \""
219 operation.GetCString());
220 return FilterRuleSP();
223 return find_it->second(match_accepts, attribute, op_arg, error);
226 StructuredData::ObjectSP Serialize() const {
227 StructuredData::Dictionary *dict_p = new StructuredData::Dictionary();
229 // Indicate whether this is an accept or reject rule.
230 dict_p->AddBooleanItem("accept", m_accept);
232 // Indicate which attribute of the message this filter references. This can
233 // drop into the rule-specific DoSerialization if we get to the point where
234 // not all FilterRule derived classes work on an attribute. (e.g. logical
235 // and/or and other compound operations).
236 dict_p->AddStringItem("attribute", s_filter_attributes[m_attribute_index]);
238 // Indicate the type of the rule.
239 dict_p->AddStringItem("type", GetOperationType().GetCString());
241 // Let the rule add its own specific details here.
242 DoSerialization(*dict_p);
244 return StructuredData::ObjectSP(dict_p);
247 virtual void Dump(Stream &stream) const = 0;
249 ConstString GetOperationType() const { return m_operation; }
252 FilterRule(bool accept, size_t attribute_index, ConstString operation)
253 : m_accept(accept), m_attribute_index(attribute_index),
254 m_operation(operation) {}
256 virtual void DoSerialization(StructuredData::Dictionary &dict) const = 0;
258 bool GetMatchAccepts() const { return m_accept; }
260 const char *GetFilterAttribute() const {
261 return s_filter_attributes[m_attribute_index];
265 using CreationFuncMap = std::map<ConstString, OperationCreationFunc>;
267 static CreationFuncMap &GetCreationFuncMap() {
268 static CreationFuncMap s_map;
273 const size_t m_attribute_index;
274 const ConstString m_operation;
277 using FilterRules = std::vector<FilterRuleSP>;
279 class RegexFilterRule : public FilterRule {
281 static void RegisterOperation() {
282 FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);
285 void Dump(Stream &stream) const override {
286 stream.Printf("%s %s regex %s", GetMatchAccepts() ? "accept" : "reject",
287 GetFilterAttribute(), m_regex_text.c_str());
291 void DoSerialization(StructuredData::Dictionary &dict) const override {
292 dict.AddStringItem("regex", m_regex_text);
296 static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,
297 const std::string &op_arg,
299 // We treat the op_arg as a regex. Validate it.
300 if (op_arg.empty()) {
301 error.SetErrorString("regex filter type requires a regex "
303 return FilterRuleSP();
306 // Instantiate the regex so we can report any errors.
307 auto regex = RegularExpression(op_arg);
308 if (!regex.IsValid()) {
309 char error_text[256];
310 error_text[0] = '\0';
311 regex.GetErrorAsCString(error_text, sizeof(error_text));
312 error.SetErrorString(error_text);
313 return FilterRuleSP();
316 // We passed all our checks, this appears fine.
318 return FilterRuleSP(new RegexFilterRule(accept, attribute_index, op_arg));
321 static ConstString StaticGetOperation() {
322 static ConstString s_operation("regex");
326 RegexFilterRule(bool accept, size_t attribute_index,
327 const std::string ®ex_text)
328 : FilterRule(accept, attribute_index, StaticGetOperation()),
329 m_regex_text(regex_text) {}
331 const std::string m_regex_text;
334 class ExactMatchFilterRule : public FilterRule {
336 static void RegisterOperation() {
337 FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);
340 void Dump(Stream &stream) const override {
341 stream.Printf("%s %s match %s", GetMatchAccepts() ? "accept" : "reject",
342 GetFilterAttribute(), m_match_text.c_str());
346 void DoSerialization(StructuredData::Dictionary &dict) const override {
347 dict.AddStringItem("exact_text", m_match_text);
351 static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,
352 const std::string &op_arg,
354 if (op_arg.empty()) {
355 error.SetErrorString("exact match filter type requires an "
356 "argument containing the text that must "
357 "match the specified message attribute.");
358 return FilterRuleSP();
363 new ExactMatchFilterRule(accept, attribute_index, op_arg));
366 static ConstString StaticGetOperation() {
367 static ConstString s_operation("match");
371 ExactMatchFilterRule(bool accept, size_t attribute_index,
372 const std::string &match_text)
373 : FilterRule(accept, attribute_index, StaticGetOperation()),
374 m_match_text(match_text) {}
376 const std::string m_match_text;
379 static void RegisterFilterOperations() {
380 ExactMatchFilterRule::RegisterOperation();
381 RegexFilterRule::RegisterOperation();
384 // =========================================================================
386 // =========================================================================
388 /// Provides the main on-off switch for enabling darwin logging.
390 /// It is valid to run the enable command when logging is already enabled.
391 /// This resets the logging with whatever settings are currently set.
393 static constexpr OptionDefinition g_enable_option_table[] = {
394 // Source stream include/exclude options (the first-level filter). This one
395 // should be made as small as possible as everything that goes through here
396 // must be processed by the process monitor.
397 {LLDB_OPT_SET_ALL, false, "any-process", 'a', OptionParser::eNoArgument,
398 nullptr, {}, 0, eArgTypeNone,
399 "Specifies log messages from other related processes should be "
401 {LLDB_OPT_SET_ALL, false, "debug", 'd', OptionParser::eNoArgument, nullptr,
403 "Specifies debug-level log messages should be included. Specifying"
404 " --debug implies --info."},
405 {LLDB_OPT_SET_ALL, false, "info", 'i', OptionParser::eNoArgument, nullptr,
407 "Specifies info-level log messages should be included."},
408 {LLDB_OPT_SET_ALL, false, "filter", 'f', OptionParser::eRequiredArgument,
409 nullptr, {}, 0, eArgRawInput,
410 // There doesn't appear to be a great way for me to have these multi-line,
411 // formatted tables in help. This looks mostly right but there are extra
412 // linefeeds added at seemingly random spots, and indentation isn't
413 // handled properly on those lines.
414 "Appends a filter rule to the log message filter chain. Multiple "
415 "rules may be added by specifying this option multiple times, "
416 "once per filter rule. Filter rules are processed in the order "
417 "they are specified, with the --no-match-accepts setting used "
418 "for any message that doesn't match one of the rules.\n"
420 " Filter spec format:\n"
422 " --filter \"{action} {attribute} {op}\"\n"
429 " activity | // message's most-derived activity\n"
430 " activity-chain | // message's {parent}:{child} activity\n"
431 " category | // message's category\n"
432 " message | // message's expanded contents\n"
433 " subsystem | // message's subsystem\n"
436 " match {exact-match-text} |\n"
437 " regex {search-regex}\n"
439 "The regex flavor used is the C++ std::regex ECMAScript format. "
440 "Prefer character classes like [[:digit:]] to \\d and the like, as "
441 "getting the backslashes escaped through properly is error-prone."},
442 {LLDB_OPT_SET_ALL, false, "live-stream", 'l',
443 OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,
444 "Specify whether logging events are live-streamed or buffered. "
445 "True indicates live streaming, false indicates buffered. The "
446 "default is true (live streaming). Live streaming will deliver "
447 "log messages with less delay, but buffered capture mode has less "
448 "of an observer effect."},
449 {LLDB_OPT_SET_ALL, false, "no-match-accepts", 'n',
450 OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,
451 "Specify whether a log message that doesn't match any filter rule "
452 "is accepted or rejected, where true indicates accept. The "
454 {LLDB_OPT_SET_ALL, false, "echo-to-stderr", 'e',
455 OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,
456 "Specify whether os_log()/NSLog() messages are echoed to the "
457 "target program's stderr. When DarwinLog is enabled, we shut off "
458 "the mirroring of os_log()/NSLog() to the program's stderr. "
459 "Setting this flag to true will restore the stderr mirroring."
460 "The default is false."},
461 {LLDB_OPT_SET_ALL, false, "broadcast-events", 'b',
462 OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,
463 "Specify if the plugin should broadcast events. Broadcasting "
464 "log events is a requirement for displaying the log entries in "
465 "LLDB command-line. It is also required if LLDB clients want to "
466 "process log events. The default is true."},
467 // Message formatting options
468 {LLDB_OPT_SET_ALL, false, "timestamp-relative", 'r',
469 OptionParser::eNoArgument, nullptr, {}, 0, eArgTypeNone,
470 "Include timestamp in the message header when printing a log "
471 "message. The timestamp is relative to the first displayed "
473 {LLDB_OPT_SET_ALL, false, "subsystem", 's', OptionParser::eNoArgument,
474 nullptr, {}, 0, eArgTypeNone,
475 "Include the subsystem in the message header when displaying "
477 {LLDB_OPT_SET_ALL, false, "category", 'c', OptionParser::eNoArgument,
478 nullptr, {}, 0, eArgTypeNone,
479 "Include the category in the message header when displaying "
481 {LLDB_OPT_SET_ALL, false, "activity-chain", 'C', OptionParser::eNoArgument,
482 nullptr, {}, 0, eArgTypeNone,
483 "Include the activity parent-child chain in the message header "
484 "when displaying a log message. The activity hierarchy is "
485 "displayed as {grandparent-activity}:"
486 "{parent-activity}:{activity}[:...]."},
487 {LLDB_OPT_SET_ALL, false, "all-fields", 'A', OptionParser::eNoArgument,
488 nullptr, {}, 0, eArgTypeNone,
489 "Shortcut to specify that all header fields should be displayed."}};
491 class EnableOptions : public Options {
494 : Options(), m_include_debug_level(false), m_include_info_level(false),
495 m_include_any_process(false),
496 m_filter_fall_through_accepts(DEFAULT_FILTER_FALLTHROUGH_ACCEPTS),
497 m_echo_to_stderr(false), m_display_timestamp_relative(false),
498 m_display_subsystem(false), m_display_category(false),
499 m_display_activity_chain(false), m_broadcast_events(true),
500 m_live_stream(true), m_filter_rules() {}
502 void OptionParsingStarting(ExecutionContext *execution_context) override {
503 m_include_debug_level = false;
504 m_include_info_level = false;
505 m_include_any_process = false;
506 m_filter_fall_through_accepts = DEFAULT_FILTER_FALLTHROUGH_ACCEPTS;
507 m_echo_to_stderr = false;
508 m_display_timestamp_relative = false;
509 m_display_subsystem = false;
510 m_display_category = false;
511 m_display_activity_chain = false;
512 m_broadcast_events = true;
513 m_live_stream = true;
514 m_filter_rules.clear();
517 Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,
518 ExecutionContext *execution_context) override {
521 const int short_option = m_getopt_table[option_idx].val;
522 switch (short_option) {
524 m_include_any_process = true;
528 m_display_timestamp_relative = true;
529 m_display_category = true;
530 m_display_subsystem = true;
531 m_display_activity_chain = true;
536 OptionArgParser::ToBoolean(option_arg, true, nullptr);
540 m_display_category = true;
544 m_display_activity_chain = true;
548 m_include_debug_level = true;
552 m_echo_to_stderr = OptionArgParser::ToBoolean(option_arg, false, nullptr);
556 return ParseFilterRule(option_arg);
559 m_include_info_level = true;
563 m_live_stream = OptionArgParser::ToBoolean(option_arg, false, nullptr);
567 m_filter_fall_through_accepts =
568 OptionArgParser::ToBoolean(option_arg, true, nullptr);
572 m_display_timestamp_relative = true;
576 m_display_subsystem = true;
580 error.SetErrorStringWithFormat("unsupported option '%c'", short_option);
585 llvm::ArrayRef<OptionDefinition> GetDefinitions() override {
586 return llvm::makeArrayRef(g_enable_option_table);
589 StructuredData::DictionarySP BuildConfigurationData(bool enabled) {
590 StructuredData::DictionarySP config_sp(new StructuredData::Dictionary());
592 // Set the basic enabled state.
593 config_sp->AddBooleanItem("enabled", enabled);
595 // If we're disabled, there's nothing more to add.
599 // Handle source stream flags.
600 auto source_flags_sp =
601 StructuredData::DictionarySP(new StructuredData::Dictionary());
602 config_sp->AddItem("source-flags", source_flags_sp);
604 source_flags_sp->AddBooleanItem("any-process", m_include_any_process);
605 source_flags_sp->AddBooleanItem("debug-level", m_include_debug_level);
606 // The debug-level flag, if set, implies info-level.
607 source_flags_sp->AddBooleanItem("info-level", m_include_info_level ||
608 m_include_debug_level);
609 source_flags_sp->AddBooleanItem("live-stream", m_live_stream);
611 // Specify default filter rule (the fall-through)
612 config_sp->AddBooleanItem("filter-fall-through-accepts",
613 m_filter_fall_through_accepts);
615 // Handle filter rules
616 if (!m_filter_rules.empty()) {
617 auto json_filter_rules_sp =
618 StructuredData::ArraySP(new StructuredData::Array);
619 config_sp->AddItem("filter-rules", json_filter_rules_sp);
620 for (auto &rule_sp : m_filter_rules) {
623 json_filter_rules_sp->AddItem(rule_sp->Serialize());
629 bool GetIncludeDebugLevel() const { return m_include_debug_level; }
631 bool GetIncludeInfoLevel() const {
632 // Specifying debug level implies info level.
633 return m_include_info_level || m_include_debug_level;
636 const FilterRules &GetFilterRules() const { return m_filter_rules; }
638 bool GetFallthroughAccepts() const { return m_filter_fall_through_accepts; }
640 bool GetEchoToStdErr() const { return m_echo_to_stderr; }
642 bool GetDisplayTimestampRelative() const {
643 return m_display_timestamp_relative;
646 bool GetDisplaySubsystem() const { return m_display_subsystem; }
647 bool GetDisplayCategory() const { return m_display_category; }
648 bool GetDisplayActivityChain() const { return m_display_activity_chain; }
650 bool GetDisplayAnyHeaderFields() const {
651 return m_display_timestamp_relative || m_display_activity_chain ||
652 m_display_subsystem || m_display_category;
655 bool GetBroadcastEvents() const { return m_broadcast_events; }
658 Status ParseFilterRule(llvm::StringRef rule_text) {
661 if (rule_text.empty()) {
662 error.SetErrorString("invalid rule_text");
666 // filter spec format:
668 // {action} {attribute} {op}
683 // match {exact-match-text} |
684 // regex {search-regex}
687 auto action_end_pos = rule_text.find(" ");
688 if (action_end_pos == std::string::npos) {
689 error.SetErrorStringWithFormat("could not parse filter rule "
690 "action from \"%s\"",
691 rule_text.str().c_str());
694 auto action = rule_text.substr(0, action_end_pos);
696 if (action == "accept")
698 else if (action == "reject")
701 error.SetErrorString("filter action must be \"accept\" or \"deny\"");
706 auto attribute_end_pos = rule_text.find(" ", action_end_pos + 1);
707 if (attribute_end_pos == std::string::npos) {
708 error.SetErrorStringWithFormat("could not parse filter rule "
709 "attribute from \"%s\"",
710 rule_text.str().c_str());
713 auto attribute = rule_text.substr(action_end_pos + 1,
714 attribute_end_pos - (action_end_pos + 1));
715 auto attribute_index = MatchAttributeIndex(attribute);
716 if (attribute_index < 0) {
717 error.SetErrorStringWithFormat("filter rule attribute unknown: "
719 attribute.str().c_str());
724 auto operation_end_pos = rule_text.find(" ", attribute_end_pos + 1);
725 auto operation = rule_text.substr(
726 attribute_end_pos + 1, operation_end_pos - (attribute_end_pos + 1));
730 FilterRule::CreateRule(accept, attribute_index, ConstString(operation),
731 rule_text.substr(operation_end_pos + 1), error);
733 if (rule_sp && error.Success())
734 m_filter_rules.push_back(rule_sp);
739 int MatchAttributeIndex(llvm::StringRef attribute_name) const {
740 for (const auto &Item : llvm::enumerate(s_filter_attributes)) {
741 if (attribute_name == Item.value())
745 // We didn't match anything.
749 bool m_include_debug_level;
750 bool m_include_info_level;
751 bool m_include_any_process;
752 bool m_filter_fall_through_accepts;
753 bool m_echo_to_stderr;
754 bool m_display_timestamp_relative;
755 bool m_display_subsystem;
756 bool m_display_category;
757 bool m_display_activity_chain;
758 bool m_broadcast_events;
760 FilterRules m_filter_rules;
763 class EnableCommand : public CommandObjectParsed {
765 EnableCommand(CommandInterpreter &interpreter, bool enable, const char *name,
766 const char *help, const char *syntax)
767 : CommandObjectParsed(interpreter, name, help, syntax), m_enable(enable),
768 m_options_sp(enable ? new EnableOptions() : nullptr) {}
771 void AppendStrictSourcesWarning(CommandReturnObject &result,
772 const char *source_name) {
776 // Check if we're *not* using strict sources. If not, then the user is
777 // going to get debug-level info anyways, probably not what they're
778 // expecting. Unfortunately we can only fix this by adding an env var,
779 // which would have had to have happened already. Thus, a warning is the
780 // best we can do here.
782 stream.Printf("darwin-log source settings specify to exclude "
783 "%s messages, but setting "
784 "'plugin.structured-data.darwin-log."
785 "strict-sources' is disabled. This process will "
786 "automatically have %s messages included. Enable"
787 " the property and relaunch the target binary to have"
788 " these messages excluded.",
789 source_name, source_name);
790 result.AppendWarning(stream.GetString());
793 bool DoExecute(Args &command, CommandReturnObject &result) override {
794 // First off, set the global sticky state of enable/disable based on this
795 // command execution.
796 s_is_explicitly_enabled = m_enable;
798 // Next, if this is an enable, save off the option data. We will need it
799 // later if a process hasn't been launched or attached yet.
801 // Save off enabled configuration so we can apply these parsed options
802 // the next time an attach or launch occurs.
803 DebuggerSP debugger_sp =
804 GetCommandInterpreter().GetDebugger().shared_from_this();
805 SetGlobalEnableOptions(debugger_sp, m_options_sp);
808 // Now check if we have a running process. If so, we should instruct the
809 // process monitor to enable/disable DarwinLog support now.
810 Target *target = GetSelectedOrDummyTarget();
812 // No target, so there is nothing more to do right now.
813 result.SetStatus(eReturnStatusSuccessFinishNoResult);
817 // Grab the active process.
818 auto process_sp = target->GetProcessSP();
820 // No active process, so there is nothing more to do right now.
821 result.SetStatus(eReturnStatusSuccessFinishNoResult);
825 // If the process is no longer alive, we can't do this now. We'll catch it
826 // the next time the process is started up.
827 if (!process_sp->IsAlive()) {
828 result.SetStatus(eReturnStatusSuccessFinishNoResult);
832 // Get the plugin for the process.
834 process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());
835 if (!plugin_sp || (plugin_sp->GetPluginName() !=
836 StructuredDataDarwinLog::GetStaticPluginName())) {
837 result.AppendError("failed to get StructuredDataPlugin for "
839 result.SetStatus(eReturnStatusFailed);
841 StructuredDataDarwinLog &plugin =
842 *static_cast<StructuredDataDarwinLog *>(plugin_sp.get());
845 // Hook up the breakpoint for the process that detects when libtrace has
846 // been sufficiently initialized to really start the os_log stream. This
847 // is insurance to assure us that logging is really enabled. Requesting
848 // that logging be enabled for a process before libtrace is initialized
849 // results in a scenario where no errors occur, but no logging is
850 // captured, either. This step is to eliminate that possibility.
851 plugin.AddInitCompletionHook(*process_sp);
854 // Send configuration to the feature by way of the process. Construct the
855 // options we will use.
856 auto config_sp = m_options_sp->BuildConfigurationData(m_enable);
858 process_sp->ConfigureStructuredData(GetDarwinLogTypeName(), config_sp);
861 if (!error.Success()) {
862 result.AppendError(error.AsCString());
863 result.SetStatus(eReturnStatusFailed);
864 // Our configuration failed, so we're definitely disabled.
865 plugin.SetEnabled(false);
867 result.SetStatus(eReturnStatusSuccessFinishNoResult);
868 // Our configuration succeeded, so we're enabled/disabled per whichever
869 // one this command is setup to do.
870 plugin.SetEnabled(m_enable);
872 return result.Succeeded();
875 Options *GetOptions() override {
876 // We don't have options when this represents disable.
877 return m_enable ? m_options_sp.get() : nullptr;
882 EnableOptionsSP m_options_sp;
885 /// Provides the status command.
886 class StatusCommand : public CommandObjectParsed {
888 StatusCommand(CommandInterpreter &interpreter)
889 : CommandObjectParsed(interpreter, "status",
890 "Show whether Darwin log supported is available"
892 "plugin structured-data darwin-log status") {}
895 bool DoExecute(Args &command, CommandReturnObject &result) override {
896 auto &stream = result.GetOutputStream();
898 // Figure out if we've got a process. If so, we can tell if DarwinLog is
899 // available for that process.
900 Target *target = GetSelectedOrDummyTarget();
901 auto process_sp = target ? target->GetProcessSP() : ProcessSP();
902 if (!target || !process_sp) {
903 stream.PutCString("Availability: unknown (requires process)\n");
904 stream.PutCString("Enabled: not applicable "
905 "(requires process)\n");
908 process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());
909 stream.Printf("Availability: %s\n",
910 plugin_sp ? "available" : "unavailable");
911 ConstString plugin_name = StructuredDataDarwinLog::GetStaticPluginName();
913 plugin_sp ? plugin_sp->GetEnabled(plugin_name) : false;
914 stream.Printf("Enabled: %s\n", enabled ? "true" : "false");
917 // Display filter settings.
918 DebuggerSP debugger_sp =
919 GetCommandInterpreter().GetDebugger().shared_from_this();
920 auto options_sp = GetGlobalEnableOptions(debugger_sp);
922 // Nothing more to do.
923 result.SetStatus(eReturnStatusSuccessFinishResult);
927 // Print filter rules
928 stream.PutCString("DarwinLog filter rules:\n");
932 if (options_sp->GetFilterRules().empty()) {
934 stream.PutCString("none\n");
936 // Print each of the filter rules.
938 for (auto rule_sp : options_sp->GetFilterRules()) {
944 stream.Printf("%02d: ", rule_number);
945 rule_sp->Dump(stream);
946 stream.PutChar('\n');
951 // Print no-match handling.
953 stream.Printf("no-match behavior: %s\n",
954 options_sp->GetFallthroughAccepts() ? "accept" : "reject");
956 result.SetStatus(eReturnStatusSuccessFinishResult);
961 /// Provides the darwin-log base command
962 class BaseCommand : public CommandObjectMultiword {
964 BaseCommand(CommandInterpreter &interpreter)
965 : CommandObjectMultiword(interpreter, "plugin structured-data darwin-log",
966 "Commands for configuring Darwin os_log "
970 auto enable_help = "Enable Darwin log collection, or re-enable "
971 "with modified configuration.";
972 auto enable_syntax = "plugin structured-data darwin-log enable";
973 auto enable_cmd_sp = CommandObjectSP(
974 new EnableCommand(interpreter,
976 "enable", enable_help, enable_syntax));
977 LoadSubCommand("enable", enable_cmd_sp);
980 auto disable_help = "Disable Darwin log collection.";
981 auto disable_syntax = "plugin structured-data darwin-log disable";
982 auto disable_cmd_sp = CommandObjectSP(
983 new EnableCommand(interpreter,
985 "disable", disable_help, disable_syntax));
986 LoadSubCommand("disable", disable_cmd_sp);
989 auto status_cmd_sp = CommandObjectSP(new StatusCommand(interpreter));
990 LoadSubCommand("status", status_cmd_sp);
994 EnableOptionsSP ParseAutoEnableOptions(Status &error, Debugger &debugger) {
995 Log *log = GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS);
996 // We are abusing the options data model here so that we can parse options
997 // without requiring the Debugger instance.
999 // We have an empty execution context at this point. We only want to parse
1000 // options, and we don't need any context to do this here. In fact, we want
1001 // to be able to parse the enable options before having any context.
1002 ExecutionContext exe_ctx;
1004 EnableOptionsSP options_sp(new EnableOptions());
1005 options_sp->NotifyOptionParsingStarting(&exe_ctx);
1007 CommandReturnObject result;
1009 // Parse the arguments.
1010 auto options_property_sp =
1011 debugger.GetPropertyValue(nullptr, "plugin.structured-data.darwin-log."
1012 "auto-enable-options",
1014 if (!error.Success())
1015 return EnableOptionsSP();
1016 if (!options_property_sp) {
1017 error.SetErrorString("failed to find option setting for "
1018 "plugin.structured-data.darwin-log.");
1019 return EnableOptionsSP();
1022 const char *enable_options =
1023 options_property_sp->GetAsString()->GetCurrentValue();
1024 Args args(enable_options);
1025 if (args.GetArgumentCount() > 0) {
1026 // Eliminate the initial '--' that would be required to set the settings
1027 // that themselves include '-' and/or '--'.
1028 const char *first_arg = args.GetArgumentAtIndex(0);
1029 if (first_arg && (strcmp(first_arg, "--") == 0))
1033 bool require_validation = false;
1034 llvm::Expected<Args> args_or =
1035 options_sp->Parse(args, &exe_ctx, PlatformSP(), require_validation);
1038 log, args_or.takeError(),
1039 "Parsing plugin.structured-data.darwin-log.auto-enable-options value "
1041 return EnableOptionsSP();
1044 if (!options_sp->VerifyOptions(result))
1045 return EnableOptionsSP();
1047 // We successfully parsed and validated the options.
1051 bool RunEnableCommand(CommandInterpreter &interpreter) {
1052 StreamString command_stream;
1054 command_stream << "plugin structured-data darwin-log enable";
1055 auto enable_options = GetGlobalProperties()->GetAutoEnableOptions();
1056 if (!enable_options.empty()) {
1057 command_stream << ' ';
1058 command_stream << enable_options;
1062 CommandReturnObject return_object;
1063 interpreter.HandleCommand(command_stream.GetData(), eLazyBoolNo,
1065 return return_object.Succeeded();
1068 using namespace sddarwinlog_private;
1071 #pragma mark Public static API
1073 // Public static API
1075 void StructuredDataDarwinLog::Initialize() {
1076 RegisterFilterOperations();
1077 PluginManager::RegisterPlugin(
1078 GetStaticPluginName(), "Darwin os_log() and os_activity() support",
1079 &CreateInstance, &DebuggerInitialize, &FilterLaunchInfo);
1082 void StructuredDataDarwinLog::Terminate() {
1083 PluginManager::UnregisterPlugin(&CreateInstance);
1086 ConstString StructuredDataDarwinLog::GetStaticPluginName() {
1087 static ConstString s_plugin_name("darwin-log");
1088 return s_plugin_name;
1092 #pragma mark PluginInterface API
1094 // PluginInterface API
1096 ConstString StructuredDataDarwinLog::GetPluginName() {
1097 return GetStaticPluginName();
1100 uint32_t StructuredDataDarwinLog::GetPluginVersion() { return 1; }
1103 #pragma mark StructuredDataPlugin API
1105 // StructuredDataPlugin API
1107 bool StructuredDataDarwinLog::SupportsStructuredDataType(
1108 ConstString type_name) {
1109 return type_name == GetDarwinLogTypeName();
1112 void StructuredDataDarwinLog::HandleArrivalOfStructuredData(
1113 Process &process, ConstString type_name,
1114 const StructuredData::ObjectSP &object_sp) {
1115 Log *log(lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS));
1117 StreamString json_stream;
1119 object_sp->Dump(json_stream);
1121 json_stream.PutCString("<null>");
1122 log->Printf("StructuredDataDarwinLog::%s() called with json: %s",
1123 __FUNCTION__, json_stream.GetData());
1126 // Ignore empty structured data.
1129 log->Printf("StructuredDataDarwinLog::%s() StructuredData object "
1135 // Ignore any data that isn't for us.
1136 if (type_name != GetDarwinLogTypeName()) {
1138 log->Printf("StructuredDataDarwinLog::%s() StructuredData type "
1139 "expected to be %s but was %s, ignoring",
1140 __FUNCTION__, GetDarwinLogTypeName().AsCString(),
1141 type_name.AsCString());
1145 // Broadcast the structured data event if we have that enabled. This is the
1146 // way that the outside world (all clients) get access to this data. This
1147 // plugin sets policy as to whether we do that.
1148 DebuggerSP debugger_sp = process.GetTarget().GetDebugger().shared_from_this();
1149 auto options_sp = GetGlobalEnableOptions(debugger_sp);
1150 if (options_sp && options_sp->GetBroadcastEvents()) {
1152 log->Printf("StructuredDataDarwinLog::%s() broadcasting event",
1154 process.BroadcastStructuredData(object_sp, shared_from_this());
1157 // Later, hang on to a configurable amount of these and allow commands to
1158 // inspect, including showing backtraces.
1161 static void SetErrorWithJSON(Status &error, const char *message,
1162 StructuredData::Object &object) {
1164 error.SetErrorString("Internal error: message not set.");
1168 StreamString object_stream;
1169 object.Dump(object_stream);
1170 object_stream.Flush();
1172 error.SetErrorStringWithFormat("%s: %s", message, object_stream.GetData());
1175 Status StructuredDataDarwinLog::GetDescription(
1176 const StructuredData::ObjectSP &object_sp, lldb_private::Stream &stream) {
1180 error.SetErrorString("No structured data.");
1184 // Log message payload objects will be dictionaries.
1185 const StructuredData::Dictionary *dictionary = object_sp->GetAsDictionary();
1187 SetErrorWithJSON(error, "Structured data should have been a dictionary "
1193 // Validate this is really a message for our plugin.
1194 ConstString type_name;
1195 if (!dictionary->GetValueForKeyAsString("type", type_name)) {
1196 SetErrorWithJSON(error, "Structured data doesn't contain mandatory "
1202 if (type_name != GetDarwinLogTypeName()) {
1203 // This is okay - it simply means the data we received is not a log
1204 // message. We'll just format it as is.
1205 object_sp->Dump(stream);
1209 // DarwinLog dictionaries store their data
1210 // in an array with key name "events".
1211 StructuredData::Array *events = nullptr;
1212 if (!dictionary->GetValueForKeyAsArray("events", events) || !events) {
1213 SetErrorWithJSON(error, "Log structured data is missing mandatory "
1214 "'events' field, expected to be an array",
1220 [&stream, &error, &object_sp, this](StructuredData::Object *object) {
1222 // Invalid. Stop iterating.
1223 SetErrorWithJSON(error, "Log event entry is null", *object_sp);
1227 auto event = object->GetAsDictionary();
1229 // Invalid, stop iterating.
1230 SetErrorWithJSON(error, "Log event is not a dictionary", *object_sp);
1234 // If we haven't already grabbed the first timestamp value, do that
1236 if (!m_recorded_first_timestamp) {
1237 uint64_t timestamp = 0;
1238 if (event->GetValueForKeyAsInteger("timestamp", timestamp)) {
1239 m_first_timestamp_seen = timestamp;
1240 m_recorded_first_timestamp = true;
1244 HandleDisplayOfEvent(*event, stream);
1252 bool StructuredDataDarwinLog::GetEnabled(ConstString type_name) const {
1253 if (type_name == GetStaticPluginName())
1254 return m_is_enabled;
1259 void StructuredDataDarwinLog::SetEnabled(bool enabled) {
1260 m_is_enabled = enabled;
1263 void StructuredDataDarwinLog::ModulesDidLoad(Process &process,
1264 ModuleList &module_list) {
1265 Log *log(lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS));
1267 log->Printf("StructuredDataDarwinLog::%s called (process uid %u)",
1268 __FUNCTION__, process.GetUniqueID());
1270 // Check if we should enable the darwin log support on startup/attach.
1271 if (!GetGlobalProperties()->GetEnableOnStartup() &&
1272 !s_is_explicitly_enabled) {
1273 // We're neither auto-enabled or explicitly enabled, so we shouldn't try to
1276 log->Printf("StructuredDataDarwinLog::%s not applicable, we're not "
1277 "enabled (process uid %u)",
1278 __FUNCTION__, process.GetUniqueID());
1282 // If we already added the breakpoint, we've got nothing left to do.
1284 std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);
1285 if (m_added_breakpoint) {
1287 log->Printf("StructuredDataDarwinLog::%s process uid %u's "
1288 "post-libtrace-init breakpoint is already set",
1289 __FUNCTION__, process.GetUniqueID());
1294 // The logging support module name, specifies the name of the image name that
1295 // must be loaded into the debugged process before we can try to enable
1297 const char *logging_module_cstr =
1298 GetGlobalProperties()->GetLoggingModuleName();
1299 if (!logging_module_cstr || (logging_module_cstr[0] == 0)) {
1300 // We need this. Bail.
1302 log->Printf("StructuredDataDarwinLog::%s no logging module name "
1303 "specified, we don't know where to set a breakpoint "
1305 __FUNCTION__, process.GetUniqueID());
1309 const ConstString logging_module_name = ConstString(logging_module_cstr);
1311 // We need to see libtrace in the list of modules before we can enable
1312 // tracing for the target process.
1313 bool found_logging_support_module = false;
1314 for (size_t i = 0; i < module_list.GetSize(); ++i) {
1315 auto module_sp = module_list.GetModuleAtIndex(i);
1319 auto &file_spec = module_sp->GetFileSpec();
1320 found_logging_support_module =
1321 (file_spec.GetLastPathComponent() == logging_module_name);
1322 if (found_logging_support_module)
1326 if (!found_logging_support_module) {
1328 log->Printf("StructuredDataDarwinLog::%s logging module %s "
1329 "has not yet been loaded, can't set a breakpoint "
1330 "yet (process uid %u)",
1331 __FUNCTION__, logging_module_name.AsCString(),
1332 process.GetUniqueID());
1336 // Time to enqueue the breakpoint so we can wait for logging support to be
1337 // initialized before we try to tap the libtrace stream.
1338 AddInitCompletionHook(process);
1340 log->Printf("StructuredDataDarwinLog::%s post-init hook breakpoint "
1341 "set for logging module %s (process uid %u)",
1342 __FUNCTION__, logging_module_name.AsCString(),
1343 process.GetUniqueID());
1345 // We need to try the enable here as well, which will succeed in the event
1346 // that we're attaching to (rather than launching) the process and the
1347 // process is already past initialization time. In that case, the completion
1348 // breakpoint will never get hit and therefore won't start that way. It
1349 // doesn't hurt much beyond a bit of bandwidth if we end up doing this twice.
1350 // It hurts much more if we don't get the logging enabled when the user
1355 // public destructor
1357 StructuredDataDarwinLog::~StructuredDataDarwinLog() {
1358 if (m_breakpoint_id != LLDB_INVALID_BREAK_ID) {
1359 ProcessSP process_sp(GetProcess());
1361 process_sp->GetTarget().RemoveBreakpointByID(m_breakpoint_id);
1362 m_breakpoint_id = LLDB_INVALID_BREAK_ID;
1368 #pragma mark Private instance methods
1370 // Private constructors
1372 StructuredDataDarwinLog::StructuredDataDarwinLog(const ProcessWP &process_wp)
1373 : StructuredDataPlugin(process_wp), m_recorded_first_timestamp(false),
1374 m_first_timestamp_seen(0), m_is_enabled(false),
1375 m_added_breakpoint_mutex(), m_added_breakpoint(),
1376 m_breakpoint_id(LLDB_INVALID_BREAK_ID) {}
1378 // Private static methods
1380 StructuredDataPluginSP
1381 StructuredDataDarwinLog::CreateInstance(Process &process) {
1382 // Currently only Apple targets support the os_log/os_activity protocol.
1383 if (process.GetTarget().GetArchitecture().GetTriple().getVendor() ==
1384 llvm::Triple::VendorType::Apple) {
1385 auto process_wp = ProcessWP(process.shared_from_this());
1386 return StructuredDataPluginSP(new StructuredDataDarwinLog(process_wp));
1388 return StructuredDataPluginSP();
1392 void StructuredDataDarwinLog::DebuggerInitialize(Debugger &debugger) {
1393 // Setup parent class first.
1394 StructuredDataPlugin::InitializeBasePluginForDebugger(debugger);
1396 // Get parent command.
1397 auto &interpreter = debugger.GetCommandInterpreter();
1398 llvm::StringRef parent_command_text = "plugin structured-data";
1399 auto parent_command =
1400 interpreter.GetCommandObjectForCommand(parent_command_text);
1401 if (!parent_command) {
1402 // Ut oh, parent failed to create parent command.
1407 auto command_name = "darwin-log";
1408 auto command_sp = CommandObjectSP(new BaseCommand(interpreter));
1409 bool result = parent_command->LoadSubCommand(command_name, command_sp);
1411 // TODO log it once we setup structured data logging
1414 if (!PluginManager::GetSettingForPlatformPlugin(
1415 debugger, StructuredDataDarwinLogProperties::GetSettingName())) {
1416 const bool is_global_setting = true;
1417 PluginManager::CreateSettingForStructuredDataPlugin(
1418 debugger, GetGlobalProperties()->GetValueProperties(),
1419 ConstString("Properties for the darwin-log"
1425 Status StructuredDataDarwinLog::FilterLaunchInfo(ProcessLaunchInfo &launch_info,
1429 // If we're not debugging this launched process, there's nothing for us to do
1431 if (!launch_info.GetFlags().AnySet(eLaunchFlagDebug))
1434 // Darwin os_log() support automatically adds debug-level and info-level
1435 // messages when a debugger is attached to a process. However, with
1436 // integrated support for debugging built into the command-line LLDB, the
1437 // user may specifically set to *not* include debug-level and info-level
1438 // content. When the user is using the integrated log support, we want to
1439 // put the kabosh on that automatic adding of info and debug level. This is
1440 // done by adding an environment variable to the process on launch. (This
1441 // also means it is not possible to suppress this behavior if attaching to an
1442 // already-running app).
1443 // Log *log(GetLogIfAnyCategoriesSet(LIBLLDB_LOG_PLATFORM));
1445 // If the target architecture is not one that supports DarwinLog, we have
1446 // nothing to do here.
1447 auto &triple = target ? target->GetArchitecture().GetTriple()
1448 : launch_info.GetArchitecture().GetTriple();
1449 if (triple.getVendor() != llvm::Triple::Apple) {
1453 // If DarwinLog is not enabled (either by explicit user command or via the
1454 // auto-enable option), then we have nothing to do.
1455 if (!GetGlobalProperties()->GetEnableOnStartup() &&
1456 !s_is_explicitly_enabled) {
1457 // Nothing to do, DarwinLog is not enabled.
1461 // If we don't have parsed configuration info, that implies we have enable-
1462 // on-startup set up, but we haven't yet attempted to run the enable command.
1464 // We really can't do this without a target. We need to be able to get to
1465 // the debugger to get the proper options to do this right.
1467 error.SetErrorString("requires a target to auto-enable DarwinLog.");
1471 DebuggerSP debugger_sp = target->GetDebugger().shared_from_this();
1472 auto options_sp = GetGlobalEnableOptions(debugger_sp);
1473 if (!options_sp && debugger_sp) {
1474 options_sp = ParseAutoEnableOptions(error, *debugger_sp.get());
1475 if (!options_sp || !error.Success())
1478 // We already parsed the options, save them now so we don't generate them
1479 // again until the user runs the command manually.
1480 SetGlobalEnableOptions(debugger_sp, options_sp);
1483 if (!options_sp->GetEchoToStdErr()) {
1484 // The user doesn't want to see os_log/NSLog messages echo to stderr. That
1485 // mechanism is entirely separate from the DarwinLog support. By default we
1486 // don't want to get it via stderr, because that would be in duplicate of
1487 // the explicit log support here.
1489 // Here we need to strip out any OS_ACTIVITY_DT_MODE setting to prevent
1490 // echoing of os_log()/NSLog() to stderr in the target program.
1491 launch_info.GetEnvironment().erase("OS_ACTIVITY_DT_MODE");
1493 // We will also set the env var that tells any downstream launcher from
1494 // adding OS_ACTIVITY_DT_MODE.
1495 launch_info.GetEnvironment()["IDE_DISABLED_OS_ACTIVITY_DT_MODE"] = "1";
1498 // Set the OS_ACTIVITY_MODE env var appropriately to enable/disable debug and
1499 // info level messages.
1500 const char *env_var_value;
1501 if (options_sp->GetIncludeDebugLevel())
1502 env_var_value = "debug";
1503 else if (options_sp->GetIncludeInfoLevel())
1504 env_var_value = "info";
1506 env_var_value = "default";
1508 launch_info.GetEnvironment()["OS_ACTIVITY_MODE"] = env_var_value;
1513 bool StructuredDataDarwinLog::InitCompletionHookCallback(
1514 void *baton, StoppointCallbackContext *context, lldb::user_id_t break_id,
1515 lldb::user_id_t break_loc_id) {
1516 // We hit the init function. We now want to enqueue our new thread plan,
1517 // which will in turn enqueue a StepOut thread plan. When the StepOut
1518 // finishes and control returns to our new thread plan, that is the time when
1519 // we can execute our logic to enable the logging support.
1521 Log *log(lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS));
1523 log->Printf("StructuredDataDarwinLog::%s() called", __FUNCTION__);
1525 // Get the current thread.
1528 log->Printf("StructuredDataDarwinLog::%s() warning: no context, "
1534 // Get the plugin from the process.
1535 auto process_sp = context->exe_ctx_ref.GetProcessSP();
1538 log->Printf("StructuredDataDarwinLog::%s() warning: invalid "
1539 "process in context, ignoring",
1544 log->Printf("StructuredDataDarwinLog::%s() call is for process uid %d",
1545 __FUNCTION__, process_sp->GetUniqueID());
1547 auto plugin_sp = process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());
1550 log->Printf("StructuredDataDarwinLog::%s() warning: no plugin for "
1551 "feature %s in process uid %u",
1552 __FUNCTION__, GetDarwinLogTypeName().AsCString(),
1553 process_sp->GetUniqueID());
1557 // Create the callback for when the thread plan completes.
1558 bool called_enable_method = false;
1559 const auto process_uid = process_sp->GetUniqueID();
1561 std::weak_ptr<StructuredDataPlugin> plugin_wp(plugin_sp);
1562 ThreadPlanCallOnFunctionExit::Callback callback =
1563 [plugin_wp, &called_enable_method, log, process_uid]() {
1565 log->Printf("StructuredDataDarwinLog::post-init callback: "
1566 "called (process uid %u)",
1569 auto strong_plugin_sp = plugin_wp.lock();
1570 if (!strong_plugin_sp) {
1572 log->Printf("StructuredDataDarwinLog::post-init callback: "
1573 "plugin no longer exists, ignoring (process "
1578 // Make sure we only call it once, just in case the thread plan hits
1579 // the breakpoint twice.
1580 if (!called_enable_method) {
1582 log->Printf("StructuredDataDarwinLog::post-init callback: "
1583 "calling EnableNow() (process uid %u)",
1585 static_cast<StructuredDataDarwinLog *>(strong_plugin_sp.get())
1587 called_enable_method = true;
1589 // Our breakpoint was hit more than once. Unexpected but no harm
1592 log->Printf("StructuredDataDarwinLog::post-init callback: "
1593 "skipping EnableNow(), already called by "
1594 "callback [we hit this more than once] "
1600 // Grab the current thread.
1601 auto thread_sp = context->exe_ctx_ref.GetThreadSP();
1604 log->Printf("StructuredDataDarwinLog::%s() warning: failed to "
1605 "retrieve the current thread from the execution "
1606 "context, nowhere to run the thread plan (process uid "
1608 __FUNCTION__, process_sp->GetUniqueID());
1612 // Queue the thread plan.
1613 auto thread_plan_sp =
1614 ThreadPlanSP(new ThreadPlanCallOnFunctionExit(*thread_sp, callback));
1615 const bool abort_other_plans = false;
1616 thread_sp->QueueThreadPlan(thread_plan_sp, abort_other_plans);
1618 log->Printf("StructuredDataDarwinLog::%s() queuing thread plan on "
1619 "trace library init method entry (process uid %u)",
1620 __FUNCTION__, process_sp->GetUniqueID());
1622 // We return false here to indicate that it isn't a public stop.
1626 void StructuredDataDarwinLog::AddInitCompletionHook(Process &process) {
1627 Log *log(lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS));
1629 log->Printf("StructuredDataDarwinLog::%s() called (process uid %u)",
1630 __FUNCTION__, process.GetUniqueID());
1632 // Make sure we haven't already done this.
1634 std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);
1635 if (m_added_breakpoint) {
1637 log->Printf("StructuredDataDarwinLog::%s() ignoring request, "
1638 "breakpoint already set (process uid %u)",
1639 __FUNCTION__, process.GetUniqueID());
1643 // We're about to do this, don't let anybody else try to do it.
1644 m_added_breakpoint = true;
1647 // Set a breakpoint for the process that will kick in when libtrace has
1648 // finished its initialization.
1649 Target &target = process.GetTarget();
1651 // Build up the module list.
1652 FileSpecList module_spec_list;
1653 auto module_file_spec =
1654 FileSpec(GetGlobalProperties()->GetLoggingModuleName());
1655 module_spec_list.Append(module_file_spec);
1657 // We aren't specifying a source file set.
1658 FileSpecList *source_spec_list = nullptr;
1660 const char *func_name = "_libtrace_init";
1661 const lldb::addr_t offset = 0;
1662 const LazyBool skip_prologue = eLazyBoolCalculate;
1663 // This is an internal breakpoint - the user shouldn't see it.
1664 const bool internal = true;
1665 const bool hardware = false;
1667 auto breakpoint_sp = target.CreateBreakpoint(
1668 &module_spec_list, source_spec_list, func_name, eFunctionNameTypeFull,
1669 eLanguageTypeC, offset, skip_prologue, internal, hardware);
1670 if (!breakpoint_sp) {
1673 log->Printf("StructuredDataDarwinLog::%s() failed to set "
1674 "breakpoint in module %s, function %s (process uid %u)",
1675 __FUNCTION__, GetGlobalProperties()->GetLoggingModuleName(),
1676 func_name, process.GetUniqueID());
1680 // Set our callback.
1681 breakpoint_sp->SetCallback(InitCompletionHookCallback, nullptr);
1682 m_breakpoint_id = breakpoint_sp->GetID();
1684 log->Printf("StructuredDataDarwinLog::%s() breakpoint set in module %s,"
1685 "function %s (process uid %u)",
1686 __FUNCTION__, GetGlobalProperties()->GetLoggingModuleName(),
1687 func_name, process.GetUniqueID());
1690 void StructuredDataDarwinLog::DumpTimestamp(Stream &stream,
1691 uint64_t timestamp) {
1692 const uint64_t delta_nanos = timestamp - m_first_timestamp_seen;
1694 const uint64_t hours = delta_nanos / NANOS_PER_HOUR;
1695 uint64_t nanos_remaining = delta_nanos % NANOS_PER_HOUR;
1697 const uint64_t minutes = nanos_remaining / NANOS_PER_MINUTE;
1698 nanos_remaining = nanos_remaining % NANOS_PER_MINUTE;
1700 const uint64_t seconds = nanos_remaining / NANOS_PER_SECOND;
1701 nanos_remaining = nanos_remaining % NANOS_PER_SECOND;
1703 stream.Printf("%02" PRIu64 ":%02" PRIu64 ":%02" PRIu64 ".%09" PRIu64, hours,
1704 minutes, seconds, nanos_remaining);
1708 StructuredDataDarwinLog::DumpHeader(Stream &output_stream,
1709 const StructuredData::Dictionary &event) {
1710 StreamString stream;
1712 ProcessSP process_sp = GetProcess();
1718 DebuggerSP debugger_sp =
1719 process_sp->GetTarget().GetDebugger().shared_from_this();
1725 auto options_sp = GetGlobalEnableOptions(debugger_sp);
1731 // Check if we should even display a header.
1732 if (!options_sp->GetDisplayAnyHeaderFields())
1735 stream.PutChar('[');
1737 int header_count = 0;
1738 if (options_sp->GetDisplayTimestampRelative()) {
1739 uint64_t timestamp = 0;
1740 if (event.GetValueForKeyAsInteger("timestamp", timestamp)) {
1741 DumpTimestamp(stream, timestamp);
1746 if (options_sp->GetDisplayActivityChain()) {
1747 llvm::StringRef activity_chain;
1748 if (event.GetValueForKeyAsString("activity-chain", activity_chain) &&
1749 !activity_chain.empty()) {
1750 if (header_count > 0)
1751 stream.PutChar(',');
1753 // Display the activity chain, from parent-most to child-most activity,
1754 // separated by a colon (:).
1755 stream.PutCString("activity-chain=");
1756 stream.PutCString(activity_chain);
1761 if (options_sp->GetDisplaySubsystem()) {
1762 llvm::StringRef subsystem;
1763 if (event.GetValueForKeyAsString("subsystem", subsystem) &&
1764 !subsystem.empty()) {
1765 if (header_count > 0)
1766 stream.PutChar(',');
1767 stream.PutCString("subsystem=");
1768 stream.PutCString(subsystem);
1773 if (options_sp->GetDisplayCategory()) {
1774 llvm::StringRef category;
1775 if (event.GetValueForKeyAsString("category", category) &&
1776 !category.empty()) {
1777 if (header_count > 0)
1778 stream.PutChar(',');
1779 stream.PutCString("category=");
1780 stream.PutCString(category);
1784 stream.PutCString("] ");
1786 output_stream.PutCString(stream.GetString());
1788 return stream.GetSize();
1791 size_t StructuredDataDarwinLog::HandleDisplayOfEvent(
1792 const StructuredData::Dictionary &event, Stream &stream) {
1793 // Check the type of the event.
1794 ConstString event_type;
1795 if (!event.GetValueForKeyAsString("type", event_type)) {
1796 // Hmm, we expected to get events that describe what they are. Continue
1801 if (event_type != GetLogEventType())
1804 size_t total_bytes = 0;
1806 // Grab the message content.
1807 llvm::StringRef message;
1808 if (!event.GetValueForKeyAsString("message", message))
1811 // Display the log entry.
1812 const auto len = message.size();
1814 total_bytes += DumpHeader(stream, event);
1816 stream.Write(message.data(), len);
1819 // Add an end of line.
1820 stream.PutChar('\n');
1821 total_bytes += sizeof(char);
1826 void StructuredDataDarwinLog::EnableNow() {
1827 Log *log(lldb_private::GetLogIfAllCategoriesSet(LIBLLDB_LOG_PROCESS));
1829 log->Printf("StructuredDataDarwinLog::%s() called", __FUNCTION__);
1831 // Run the enable command.
1832 auto process_sp = GetProcess();
1836 log->Printf("StructuredDataDarwinLog::%s() warning: failed to get "
1837 "valid process, skipping",
1842 log->Printf("StructuredDataDarwinLog::%s() call is for process uid %u",
1843 __FUNCTION__, process_sp->GetUniqueID());
1845 // If we have configuration data, we can directly enable it now. Otherwise,
1846 // we need to run through the command interpreter to parse the auto-run
1847 // options (which is the only way we get here without having already-parsed
1848 // configuration data).
1849 DebuggerSP debugger_sp =
1850 process_sp->GetTarget().GetDebugger().shared_from_this();
1853 log->Printf("StructuredDataDarwinLog::%s() warning: failed to get "
1854 "debugger shared pointer, skipping (process uid %u)",
1855 __FUNCTION__, process_sp->GetUniqueID());
1859 auto options_sp = GetGlobalEnableOptions(debugger_sp);
1861 // We haven't run the enable command yet. Just do that now, it'll take
1862 // care of the rest.
1863 auto &interpreter = debugger_sp->GetCommandInterpreter();
1864 const bool success = RunEnableCommand(interpreter);
1867 log->Printf("StructuredDataDarwinLog::%s() ran enable command "
1868 "successfully for (process uid %u)",
1869 __FUNCTION__, process_sp->GetUniqueID());
1871 log->Printf("StructuredDataDarwinLog::%s() error: running "
1872 "enable command failed (process uid %u)",
1873 __FUNCTION__, process_sp->GetUniqueID());
1875 // Report failures to the debugger error stream.
1876 auto error_stream_sp = debugger_sp->GetAsyncErrorStream();
1877 if (error_stream_sp) {
1878 error_stream_sp->Printf("failed to configure DarwinLog "
1880 error_stream_sp->Flush();
1885 // We've previously been enabled. We will re-enable now with the previously
1886 // specified options.
1887 auto config_sp = options_sp->BuildConfigurationData(true);
1890 log->Printf("StructuredDataDarwinLog::%s() warning: failed to "
1891 "build configuration data for enable options, skipping "
1893 __FUNCTION__, process_sp->GetUniqueID());
1897 // We can run it directly.
1898 // Send configuration to the feature by way of the process.
1899 const Status error =
1900 process_sp->ConfigureStructuredData(GetDarwinLogTypeName(), config_sp);
1903 if (!error.Success()) {
1905 log->Printf("StructuredDataDarwinLog::%s() "
1906 "ConfigureStructuredData() call failed "
1907 "(process uid %u): %s",
1908 __FUNCTION__, process_sp->GetUniqueID(), error.AsCString());
1909 auto error_stream_sp = debugger_sp->GetAsyncErrorStream();
1910 if (error_stream_sp) {
1911 error_stream_sp->Printf("failed to configure DarwinLog "
1914 error_stream_sp->Flush();
1916 m_is_enabled = false;
1918 m_is_enabled = true;
1920 log->Printf("StructuredDataDarwinLog::%s() success via direct "
1921 "configuration (process uid %u)",
1922 __FUNCTION__, process_sp->GetUniqueID());