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