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