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