Path: blob/main/contrib/llvm-project/lldb/source/Plugins/StructuredData/DarwinLog/StructuredDataDarwinLog.cpp
39648 views
//===-- StructuredDataDarwinLog.cpp ---------------------------------------===//1//2// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.3// See https://llvm.org/LICENSE.txt for license information.4// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception5//6//===----------------------------------------------------------------------===//78#include "StructuredDataDarwinLog.h"910#include <cstring>1112#include <memory>13#include <sstream>1415#include "lldb/Breakpoint/StoppointCallbackContext.h"16#include "lldb/Core/Debugger.h"17#include "lldb/Core/Module.h"18#include "lldb/Core/PluginManager.h"19#include "lldb/Host/OptionParser.h"20#include "lldb/Interpreter/CommandInterpreter.h"21#include "lldb/Interpreter/CommandObjectMultiword.h"22#include "lldb/Interpreter/CommandReturnObject.h"23#include "lldb/Interpreter/OptionArgParser.h"24#include "lldb/Interpreter/OptionValueProperties.h"25#include "lldb/Interpreter/OptionValueString.h"26#include "lldb/Interpreter/Property.h"27#include "lldb/Target/Process.h"28#include "lldb/Target/Target.h"29#include "lldb/Target/ThreadPlanCallOnFunctionExit.h"30#include "lldb/Utility/LLDBLog.h"31#include "lldb/Utility/Log.h"32#include "lldb/Utility/RegularExpression.h"3334#include "llvm/ADT/StringMap.h"3536#define DARWIN_LOG_TYPE_VALUE "DarwinLog"3738using namespace lldb;39using namespace lldb_private;4041LLDB_PLUGIN_DEFINE(StructuredDataDarwinLog)4243#pragma mark -44#pragma mark Anonymous Namespace4546// Anonymous namespace4748namespace sddarwinlog_private {49const uint64_t NANOS_PER_MICRO = 1000;50const uint64_t NANOS_PER_MILLI = NANOS_PER_MICRO * 1000;51const uint64_t NANOS_PER_SECOND = NANOS_PER_MILLI * 1000;52const uint64_t NANOS_PER_MINUTE = NANOS_PER_SECOND * 60;53const uint64_t NANOS_PER_HOUR = NANOS_PER_MINUTE * 60;5455static bool DEFAULT_FILTER_FALLTHROUGH_ACCEPTS = true;5657/// Global, sticky enable switch. If true, the user has explicitly58/// run the enable command. When a process launches or is attached to,59/// we will enable DarwinLog if either the settings for auto-enable is60/// on, or if the user had explicitly run enable at some point prior61/// to the launch/attach.62static bool s_is_explicitly_enabled;6364class EnableOptions;65using EnableOptionsSP = std::shared_ptr<EnableOptions>;6667using OptionsMap =68std::map<DebuggerWP, EnableOptionsSP, std::owner_less<DebuggerWP>>;6970static OptionsMap &GetGlobalOptionsMap() {71static OptionsMap s_options_map;72return s_options_map;73}7475static std::mutex &GetGlobalOptionsMapLock() {76static std::mutex s_options_map_lock;77return s_options_map_lock;78}7980EnableOptionsSP GetGlobalEnableOptions(const DebuggerSP &debugger_sp) {81if (!debugger_sp)82return EnableOptionsSP();8384std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());85OptionsMap &options_map = GetGlobalOptionsMap();86DebuggerWP debugger_wp(debugger_sp);87auto find_it = options_map.find(debugger_wp);88if (find_it != options_map.end())89return find_it->second;90else91return EnableOptionsSP();92}9394void SetGlobalEnableOptions(const DebuggerSP &debugger_sp,95const EnableOptionsSP &options_sp) {96std::lock_guard<std::mutex> locker(GetGlobalOptionsMapLock());97OptionsMap &options_map = GetGlobalOptionsMap();98DebuggerWP debugger_wp(debugger_sp);99auto find_it = options_map.find(debugger_wp);100if (find_it != options_map.end())101find_it->second = options_sp;102else103options_map.insert(std::make_pair(debugger_wp, options_sp));104}105106#pragma mark -107#pragma mark Settings Handling108109/// Code to handle the StructuredDataDarwinLog settings110111#define LLDB_PROPERTIES_darwinlog112#include "StructuredDataDarwinLogProperties.inc"113114enum {115#define LLDB_PROPERTIES_darwinlog116#include "StructuredDataDarwinLogPropertiesEnum.inc"117};118119class StructuredDataDarwinLogProperties : public Properties {120public:121static llvm::StringRef GetSettingName() {122static constexpr llvm::StringLiteral g_setting_name("darwin-log");123return g_setting_name;124}125126StructuredDataDarwinLogProperties() : Properties() {127m_collection_sp = std::make_shared<OptionValueProperties>(GetSettingName());128m_collection_sp->Initialize(g_darwinlog_properties);129}130131~StructuredDataDarwinLogProperties() override = default;132133bool GetEnableOnStartup() const {134const uint32_t idx = ePropertyEnableOnStartup;135return GetPropertyAtIndexAs<bool>(136idx, g_darwinlog_properties[idx].default_uint_value != 0);137}138139llvm::StringRef GetAutoEnableOptions() const {140const uint32_t idx = ePropertyAutoEnableOptions;141return GetPropertyAtIndexAs<llvm::StringRef>(142idx, g_darwinlog_properties[idx].default_cstr_value);143}144145const char *GetLoggingModuleName() const { return "libsystem_trace.dylib"; }146};147148static StructuredDataDarwinLogProperties &GetGlobalProperties() {149static StructuredDataDarwinLogProperties g_settings;150return g_settings;151}152153const char *const s_filter_attributes[] = {154"activity", // current activity155"activity-chain", // entire activity chain, each level separated by ':'156"category", // category of the log message157"message", // message contents, fully expanded158"subsystem" // subsystem of the log message159160// Consider implementing this action as it would be cheaper to filter.161// "message" requires always formatting the message, which is a waste of162// cycles if it ends up being rejected. "format", // format string163// used to format message text164};165166static llvm::StringRef GetDarwinLogTypeName() {167static constexpr llvm::StringLiteral s_key_name("DarwinLog");168return s_key_name;169}170171static llvm::StringRef GetLogEventType() {172static constexpr llvm::StringLiteral s_event_type("log");173return s_event_type;174}175176class FilterRule;177using FilterRuleSP = std::shared_ptr<FilterRule>;178179class FilterRule {180public:181virtual ~FilterRule() = default;182183using OperationCreationFunc =184std::function<FilterRuleSP(bool accept, size_t attribute_index,185const std::string &op_arg, Status &error)>;186187static void RegisterOperation(llvm::StringRef operation,188const OperationCreationFunc &creation_func) {189GetCreationFuncMap().insert(std::make_pair(operation, creation_func));190}191192static FilterRuleSP CreateRule(bool match_accepts, size_t attribute,193llvm::StringRef operation,194const std::string &op_arg, Status &error) {195// Find the creation func for this type of filter rule.196auto map = GetCreationFuncMap();197auto find_it = map.find(operation);198if (find_it == map.end()) {199error.SetErrorStringWithFormatv("unknown filter operation \"{0}\"",200operation);201return FilterRuleSP();202}203204return find_it->second(match_accepts, attribute, op_arg, error);205}206207StructuredData::ObjectSP Serialize() const {208StructuredData::Dictionary *dict_p = new StructuredData::Dictionary();209210// Indicate whether this is an accept or reject rule.211dict_p->AddBooleanItem("accept", m_accept);212213// Indicate which attribute of the message this filter references. This can214// drop into the rule-specific DoSerialization if we get to the point where215// not all FilterRule derived classes work on an attribute. (e.g. logical216// and/or and other compound operations).217dict_p->AddStringItem("attribute", s_filter_attributes[m_attribute_index]);218219// Indicate the type of the rule.220dict_p->AddStringItem("type", GetOperationType());221222// Let the rule add its own specific details here.223DoSerialization(*dict_p);224225return StructuredData::ObjectSP(dict_p);226}227228virtual void Dump(Stream &stream) const = 0;229230llvm::StringRef GetOperationType() const { return m_operation; }231232protected:233FilterRule(bool accept, size_t attribute_index, llvm::StringRef operation)234: m_accept(accept), m_attribute_index(attribute_index),235m_operation(operation) {}236237virtual void DoSerialization(StructuredData::Dictionary &dict) const = 0;238239bool GetMatchAccepts() const { return m_accept; }240241const char *GetFilterAttribute() const {242return s_filter_attributes[m_attribute_index];243}244245private:246using CreationFuncMap = llvm::StringMap<OperationCreationFunc>;247248static CreationFuncMap &GetCreationFuncMap() {249static CreationFuncMap s_map;250return s_map;251}252253const bool m_accept;254const size_t m_attribute_index;255// The lifetime of m_operation should be static.256const llvm::StringRef m_operation;257};258259using FilterRules = std::vector<FilterRuleSP>;260261class RegexFilterRule : public FilterRule {262public:263static void RegisterOperation() {264FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);265}266267void Dump(Stream &stream) const override {268stream.Printf("%s %s regex %s", GetMatchAccepts() ? "accept" : "reject",269GetFilterAttribute(), m_regex_text.c_str());270}271272protected:273void DoSerialization(StructuredData::Dictionary &dict) const override {274dict.AddStringItem("regex", m_regex_text);275}276277private:278static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,279const std::string &op_arg,280Status &error) {281// We treat the op_arg as a regex. Validate it.282if (op_arg.empty()) {283error.SetErrorString("regex filter type requires a regex "284"argument");285return FilterRuleSP();286}287288// Instantiate the regex so we can report any errors.289auto regex = RegularExpression(op_arg);290if (llvm::Error err = regex.GetError()) {291error.SetErrorString(llvm::toString(std::move(err)));292return FilterRuleSP();293}294295// We passed all our checks, this appears fine.296error.Clear();297return FilterRuleSP(new RegexFilterRule(accept, attribute_index, op_arg));298}299300static llvm::StringRef StaticGetOperation() {301static constexpr llvm::StringLiteral s_operation("regex");302return s_operation;303}304305RegexFilterRule(bool accept, size_t attribute_index,306const std::string ®ex_text)307: FilterRule(accept, attribute_index, StaticGetOperation()),308m_regex_text(regex_text) {}309310const std::string m_regex_text;311};312313class ExactMatchFilterRule : public FilterRule {314public:315static void RegisterOperation() {316FilterRule::RegisterOperation(StaticGetOperation(), CreateOperation);317}318319void Dump(Stream &stream) const override {320stream.Printf("%s %s match %s", GetMatchAccepts() ? "accept" : "reject",321GetFilterAttribute(), m_match_text.c_str());322}323324protected:325void DoSerialization(StructuredData::Dictionary &dict) const override {326dict.AddStringItem("exact_text", m_match_text);327}328329private:330static FilterRuleSP CreateOperation(bool accept, size_t attribute_index,331const std::string &op_arg,332Status &error) {333if (op_arg.empty()) {334error.SetErrorString("exact match filter type requires an "335"argument containing the text that must "336"match the specified message attribute.");337return FilterRuleSP();338}339340error.Clear();341return FilterRuleSP(342new ExactMatchFilterRule(accept, attribute_index, op_arg));343}344345static llvm::StringRef StaticGetOperation() {346static constexpr llvm::StringLiteral s_operation("match");347return s_operation;348}349350ExactMatchFilterRule(bool accept, size_t attribute_index,351const std::string &match_text)352: FilterRule(accept, attribute_index, StaticGetOperation()),353m_match_text(match_text) {}354355const std::string m_match_text;356};357358static void RegisterFilterOperations() {359ExactMatchFilterRule::RegisterOperation();360RegexFilterRule::RegisterOperation();361}362363// =========================================================================364// Commands365// =========================================================================366367/// Provides the main on-off switch for enabling darwin logging.368///369/// It is valid to run the enable command when logging is already enabled.370/// This resets the logging with whatever settings are currently set.371372static constexpr OptionDefinition g_enable_option_table[] = {373// Source stream include/exclude options (the first-level filter). This one374// should be made as small as possible as everything that goes through here375// must be processed by the process monitor.376{LLDB_OPT_SET_ALL, false, "any-process", 'a', OptionParser::eNoArgument,377nullptr, {}, 0, eArgTypeNone,378"Specifies log messages from other related processes should be "379"included."},380{LLDB_OPT_SET_ALL, false, "debug", 'd', OptionParser::eNoArgument, nullptr,381{}, 0, eArgTypeNone,382"Specifies debug-level log messages should be included. Specifying"383" --debug implies --info."},384{LLDB_OPT_SET_ALL, false, "info", 'i', OptionParser::eNoArgument, nullptr,385{}, 0, eArgTypeNone,386"Specifies info-level log messages should be included."},387{LLDB_OPT_SET_ALL, false, "filter", 'f', OptionParser::eRequiredArgument,388nullptr, {}, 0, eArgRawInput,389// There doesn't appear to be a great way for me to have these multi-line,390// formatted tables in help. This looks mostly right but there are extra391// linefeeds added at seemingly random spots, and indentation isn't392// handled properly on those lines.393"Appends a filter rule to the log message filter chain. Multiple "394"rules may be added by specifying this option multiple times, "395"once per filter rule. Filter rules are processed in the order "396"they are specified, with the --no-match-accepts setting used "397"for any message that doesn't match one of the rules.\n"398"\n"399" Filter spec format:\n"400"\n"401" --filter \"{action} {attribute} {op}\"\n"402"\n"403" {action} :=\n"404" accept |\n"405" reject\n"406"\n"407" {attribute} :=\n"408" activity | // message's most-derived activity\n"409" activity-chain | // message's {parent}:{child} activity\n"410" category | // message's category\n"411" message | // message's expanded contents\n"412" subsystem | // message's subsystem\n"413"\n"414" {op} :=\n"415" match {exact-match-text} |\n"416" regex {search-regex}\n"417"\n"418"The regex flavor used is the C++ std::regex ECMAScript format. "419"Prefer character classes like [[:digit:]] to \\d and the like, as "420"getting the backslashes escaped through properly is error-prone."},421{LLDB_OPT_SET_ALL, false, "live-stream", 'l',422OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,423"Specify whether logging events are live-streamed or buffered. "424"True indicates live streaming, false indicates buffered. The "425"default is true (live streaming). Live streaming will deliver "426"log messages with less delay, but buffered capture mode has less "427"of an observer effect."},428{LLDB_OPT_SET_ALL, false, "no-match-accepts", 'n',429OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,430"Specify whether a log message that doesn't match any filter rule "431"is accepted or rejected, where true indicates accept. The "432"default is true."},433{LLDB_OPT_SET_ALL, false, "echo-to-stderr", 'e',434OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,435"Specify whether os_log()/NSLog() messages are echoed to the "436"target program's stderr. When DarwinLog is enabled, we shut off "437"the mirroring of os_log()/NSLog() to the program's stderr. "438"Setting this flag to true will restore the stderr mirroring."439"The default is false."},440{LLDB_OPT_SET_ALL, false, "broadcast-events", 'b',441OptionParser::eRequiredArgument, nullptr, {}, 0, eArgTypeBoolean,442"Specify if the plugin should broadcast events. Broadcasting "443"log events is a requirement for displaying the log entries in "444"LLDB command-line. It is also required if LLDB clients want to "445"process log events. The default is true."},446// Message formatting options447{LLDB_OPT_SET_ALL, false, "timestamp-relative", 'r',448OptionParser::eNoArgument, nullptr, {}, 0, eArgTypeNone,449"Include timestamp in the message header when printing a log "450"message. The timestamp is relative to the first displayed "451"message."},452{LLDB_OPT_SET_ALL, false, "subsystem", 's', OptionParser::eNoArgument,453nullptr, {}, 0, eArgTypeNone,454"Include the subsystem in the message header when displaying "455"a log message."},456{LLDB_OPT_SET_ALL, false, "category", 'c', OptionParser::eNoArgument,457nullptr, {}, 0, eArgTypeNone,458"Include the category in the message header when displaying "459"a log message."},460{LLDB_OPT_SET_ALL, false, "activity-chain", 'C', OptionParser::eNoArgument,461nullptr, {}, 0, eArgTypeNone,462"Include the activity parent-child chain in the message header "463"when displaying a log message. The activity hierarchy is "464"displayed as {grandparent-activity}:"465"{parent-activity}:{activity}[:...]."},466{LLDB_OPT_SET_ALL, false, "all-fields", 'A', OptionParser::eNoArgument,467nullptr, {}, 0, eArgTypeNone,468"Shortcut to specify that all header fields should be displayed."}};469470class EnableOptions : public Options {471public:472EnableOptions()473: Options(),474m_filter_fall_through_accepts(DEFAULT_FILTER_FALLTHROUGH_ACCEPTS),475m_filter_rules() {}476477void OptionParsingStarting(ExecutionContext *execution_context) override {478m_include_debug_level = false;479m_include_info_level = false;480m_include_any_process = false;481m_filter_fall_through_accepts = DEFAULT_FILTER_FALLTHROUGH_ACCEPTS;482m_echo_to_stderr = false;483m_display_timestamp_relative = false;484m_display_subsystem = false;485m_display_category = false;486m_display_activity_chain = false;487m_broadcast_events = true;488m_live_stream = true;489m_filter_rules.clear();490}491492Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,493ExecutionContext *execution_context) override {494Status error;495496const int short_option = m_getopt_table[option_idx].val;497switch (short_option) {498case 'a':499m_include_any_process = true;500break;501502case 'A':503m_display_timestamp_relative = true;504m_display_category = true;505m_display_subsystem = true;506m_display_activity_chain = true;507break;508509case 'b':510m_broadcast_events =511OptionArgParser::ToBoolean(option_arg, true, nullptr);512break;513514case 'c':515m_display_category = true;516break;517518case 'C':519m_display_activity_chain = true;520break;521522case 'd':523m_include_debug_level = true;524break;525526case 'e':527m_echo_to_stderr = OptionArgParser::ToBoolean(option_arg, false, nullptr);528break;529530case 'f':531return ParseFilterRule(option_arg);532533case 'i':534m_include_info_level = true;535break;536537case 'l':538m_live_stream = OptionArgParser::ToBoolean(option_arg, false, nullptr);539break;540541case 'n':542m_filter_fall_through_accepts =543OptionArgParser::ToBoolean(option_arg, true, nullptr);544break;545546case 'r':547m_display_timestamp_relative = true;548break;549550case 's':551m_display_subsystem = true;552break;553554default:555error.SetErrorStringWithFormat("unsupported option '%c'", short_option);556}557return error;558}559560llvm::ArrayRef<OptionDefinition> GetDefinitions() override {561return llvm::ArrayRef(g_enable_option_table);562}563564StructuredData::DictionarySP BuildConfigurationData(bool enabled) {565StructuredData::DictionarySP config_sp(new StructuredData::Dictionary());566567// Set the basic enabled state.568config_sp->AddBooleanItem("enabled", enabled);569570// If we're disabled, there's nothing more to add.571if (!enabled)572return config_sp;573574// Handle source stream flags.575auto source_flags_sp =576StructuredData::DictionarySP(new StructuredData::Dictionary());577config_sp->AddItem("source-flags", source_flags_sp);578579source_flags_sp->AddBooleanItem("any-process", m_include_any_process);580source_flags_sp->AddBooleanItem("debug-level", m_include_debug_level);581// The debug-level flag, if set, implies info-level.582source_flags_sp->AddBooleanItem("info-level", m_include_info_level ||583m_include_debug_level);584source_flags_sp->AddBooleanItem("live-stream", m_live_stream);585586// Specify default filter rule (the fall-through)587config_sp->AddBooleanItem("filter-fall-through-accepts",588m_filter_fall_through_accepts);589590// Handle filter rules591if (!m_filter_rules.empty()) {592auto json_filter_rules_sp =593StructuredData::ArraySP(new StructuredData::Array);594config_sp->AddItem("filter-rules", json_filter_rules_sp);595for (auto &rule_sp : m_filter_rules) {596if (!rule_sp)597continue;598json_filter_rules_sp->AddItem(rule_sp->Serialize());599}600}601return config_sp;602}603604bool GetIncludeDebugLevel() const { return m_include_debug_level; }605606bool GetIncludeInfoLevel() const {607// Specifying debug level implies info level.608return m_include_info_level || m_include_debug_level;609}610611const FilterRules &GetFilterRules() const { return m_filter_rules; }612613bool GetFallthroughAccepts() const { return m_filter_fall_through_accepts; }614615bool GetEchoToStdErr() const { return m_echo_to_stderr; }616617bool GetDisplayTimestampRelative() const {618return m_display_timestamp_relative;619}620621bool GetDisplaySubsystem() const { return m_display_subsystem; }622bool GetDisplayCategory() const { return m_display_category; }623bool GetDisplayActivityChain() const { return m_display_activity_chain; }624625bool GetDisplayAnyHeaderFields() const {626return m_display_timestamp_relative || m_display_activity_chain ||627m_display_subsystem || m_display_category;628}629630bool GetBroadcastEvents() const { return m_broadcast_events; }631632private:633Status ParseFilterRule(llvm::StringRef rule_text) {634Status error;635636if (rule_text.empty()) {637error.SetErrorString("invalid rule_text");638return error;639}640641// 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}660661// Parse action.662auto action_end_pos = rule_text.find(' ');663if (action_end_pos == std::string::npos) {664error.SetErrorStringWithFormat("could not parse filter rule "665"action from \"%s\"",666rule_text.str().c_str());667return error;668}669auto action = rule_text.substr(0, action_end_pos);670bool accept;671if (action == "accept")672accept = true;673else if (action == "reject")674accept = false;675else {676error.SetErrorString("filter action must be \"accept\" or \"deny\"");677return error;678}679680// parse attribute681auto attribute_end_pos = rule_text.find(" ", action_end_pos + 1);682if (attribute_end_pos == std::string::npos) {683error.SetErrorStringWithFormat("could not parse filter rule "684"attribute from \"%s\"",685rule_text.str().c_str());686return error;687}688auto attribute = rule_text.substr(action_end_pos + 1,689attribute_end_pos - (action_end_pos + 1));690auto attribute_index = MatchAttributeIndex(attribute);691if (attribute_index < 0) {692error.SetErrorStringWithFormat("filter rule attribute unknown: "693"%s",694attribute.str().c_str());695return error;696}697698// parse operation699auto operation_end_pos = rule_text.find(" ", attribute_end_pos + 1);700auto operation = rule_text.substr(701attribute_end_pos + 1, operation_end_pos - (attribute_end_pos + 1));702703// add filter spec704auto rule_sp = FilterRule::CreateRule(705accept, attribute_index, operation,706std::string(rule_text.substr(operation_end_pos + 1)), error);707708if (rule_sp && error.Success())709m_filter_rules.push_back(rule_sp);710711return error;712}713714int MatchAttributeIndex(llvm::StringRef attribute_name) const {715for (const auto &Item : llvm::enumerate(s_filter_attributes)) {716if (attribute_name == Item.value())717return Item.index();718}719720// We didn't match anything.721return -1;722}723724bool m_include_debug_level = false;725bool m_include_info_level = false;726bool m_include_any_process = false;727bool m_filter_fall_through_accepts;728bool m_echo_to_stderr = false;729bool m_display_timestamp_relative = false;730bool m_display_subsystem = false;731bool m_display_category = false;732bool m_display_activity_chain = false;733bool m_broadcast_events = true;734bool m_live_stream = true;735FilterRules m_filter_rules;736};737738class EnableCommand : public CommandObjectParsed {739public:740EnableCommand(CommandInterpreter &interpreter, bool enable, const char *name,741const char *help, const char *syntax)742: CommandObjectParsed(interpreter, name, help, syntax), m_enable(enable),743m_options_sp(enable ? new EnableOptions() : nullptr) {}744745protected:746void AppendStrictSourcesWarning(CommandReturnObject &result,747const char *source_name) {748if (!source_name)749return;750751// Check if we're *not* using strict sources. If not, then the user is752// going to get debug-level info anyways, probably not what they're753// expecting. Unfortunately we can only fix this by adding an env var,754// which would have had to have happened already. Thus, a warning is the755// best we can do here.756StreamString stream;757stream.Printf("darwin-log source settings specify to exclude "758"%s messages, but setting "759"'plugin.structured-data.darwin-log."760"strict-sources' is disabled. This process will "761"automatically have %s messages included. Enable"762" the property and relaunch the target binary to have"763" these messages excluded.",764source_name, source_name);765result.AppendWarning(stream.GetString());766}767768void DoExecute(Args &command, CommandReturnObject &result) override {769// First off, set the global sticky state of enable/disable based on this770// command execution.771s_is_explicitly_enabled = m_enable;772773// Next, if this is an enable, save off the option data. We will need it774// later if a process hasn't been launched or attached yet.775if (m_enable) {776// Save off enabled configuration so we can apply these parsed options777// the next time an attach or launch occurs.778DebuggerSP debugger_sp =779GetCommandInterpreter().GetDebugger().shared_from_this();780SetGlobalEnableOptions(debugger_sp, m_options_sp);781}782783// Now check if we have a running process. If so, we should instruct the784// process monitor to enable/disable DarwinLog support now.785Target &target = GetSelectedOrDummyTarget();786787// Grab the active process.788auto process_sp = target.GetProcessSP();789if (!process_sp) {790// No active process, so there is nothing more to do right now.791result.SetStatus(eReturnStatusSuccessFinishNoResult);792return;793}794795// If the process is no longer alive, we can't do this now. We'll catch it796// the next time the process is started up.797if (!process_sp->IsAlive()) {798result.SetStatus(eReturnStatusSuccessFinishNoResult);799return;800}801802// Get the plugin for the process.803auto plugin_sp =804process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());805if (!plugin_sp || (plugin_sp->GetPluginName() !=806StructuredDataDarwinLog::GetStaticPluginName())) {807result.AppendError("failed to get StructuredDataPlugin for "808"the process");809}810StructuredDataDarwinLog &plugin =811*static_cast<StructuredDataDarwinLog *>(plugin_sp.get());812813if (m_enable) {814// Hook up the breakpoint for the process that detects when libtrace has815// been sufficiently initialized to really start the os_log stream. This816// is insurance to assure us that logging is really enabled. Requesting817// that logging be enabled for a process before libtrace is initialized818// results in a scenario where no errors occur, but no logging is819// captured, either. This step is to eliminate that possibility.820plugin.AddInitCompletionHook(*process_sp);821}822823// Send configuration to the feature by way of the process. Construct the824// options we will use.825auto config_sp = m_options_sp->BuildConfigurationData(m_enable);826const Status error =827process_sp->ConfigureStructuredData(GetDarwinLogTypeName(), config_sp);828829// Report results.830if (!error.Success()) {831result.AppendError(error.AsCString());832// Our configuration failed, so we're definitely disabled.833plugin.SetEnabled(false);834} else {835result.SetStatus(eReturnStatusSuccessFinishNoResult);836// Our configuration succeeded, so we're enabled/disabled per whichever837// one this command is setup to do.838plugin.SetEnabled(m_enable);839}840}841842Options *GetOptions() override {843// We don't have options when this represents disable.844return m_enable ? m_options_sp.get() : nullptr;845}846847private:848const bool m_enable;849EnableOptionsSP m_options_sp;850};851852/// Provides the status command.853class StatusCommand : public CommandObjectParsed {854public:855StatusCommand(CommandInterpreter &interpreter)856: CommandObjectParsed(interpreter, "status",857"Show whether Darwin log supported is available"858" and enabled.",859"plugin structured-data darwin-log status") {}860861protected:862void DoExecute(Args &command, CommandReturnObject &result) override {863auto &stream = result.GetOutputStream();864865// Figure out if we've got a process. If so, we can tell if DarwinLog is866// available for that process.867Target &target = GetSelectedOrDummyTarget();868auto process_sp = target.GetProcessSP();869if (!process_sp) {870stream.PutCString("Availability: unknown (requires process)\n");871stream.PutCString("Enabled: not applicable "872"(requires process)\n");873} else {874auto plugin_sp =875process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());876stream.Printf("Availability: %s\n",877plugin_sp ? "available" : "unavailable");878const bool enabled =879plugin_sp ? plugin_sp->GetEnabled(880StructuredDataDarwinLog::GetStaticPluginName())881: false;882stream.Printf("Enabled: %s\n", enabled ? "true" : "false");883}884885// Display filter settings.886DebuggerSP debugger_sp =887GetCommandInterpreter().GetDebugger().shared_from_this();888auto options_sp = GetGlobalEnableOptions(debugger_sp);889if (!options_sp) {890// Nothing more to do.891result.SetStatus(eReturnStatusSuccessFinishResult);892return;893}894895// Print filter rules896stream.PutCString("DarwinLog filter rules:\n");897898stream.IndentMore();899900if (options_sp->GetFilterRules().empty()) {901stream.Indent();902stream.PutCString("none\n");903} else {904// Print each of the filter rules.905int rule_number = 0;906for (auto rule_sp : options_sp->GetFilterRules()) {907++rule_number;908if (!rule_sp)909continue;910911stream.Indent();912stream.Printf("%02d: ", rule_number);913rule_sp->Dump(stream);914stream.PutChar('\n');915}916}917stream.IndentLess();918919// Print no-match handling.920stream.Indent();921stream.Printf("no-match behavior: %s\n",922options_sp->GetFallthroughAccepts() ? "accept" : "reject");923924result.SetStatus(eReturnStatusSuccessFinishResult);925}926};927928/// Provides the darwin-log base command929class BaseCommand : public CommandObjectMultiword {930public:931BaseCommand(CommandInterpreter &interpreter)932: CommandObjectMultiword(interpreter, "plugin structured-data darwin-log",933"Commands for configuring Darwin os_log "934"support.",935"") {936// enable937auto enable_help = "Enable Darwin log collection, or re-enable "938"with modified configuration.";939auto enable_syntax = "plugin structured-data darwin-log enable";940auto enable_cmd_sp = CommandObjectSP(941new EnableCommand(interpreter,942true, // enable943"enable", enable_help, enable_syntax));944LoadSubCommand("enable", enable_cmd_sp);945946// disable947auto disable_help = "Disable Darwin log collection.";948auto disable_syntax = "plugin structured-data darwin-log disable";949auto disable_cmd_sp = CommandObjectSP(950new EnableCommand(interpreter,951false, // disable952"disable", disable_help, disable_syntax));953LoadSubCommand("disable", disable_cmd_sp);954955// status956auto status_cmd_sp = CommandObjectSP(new StatusCommand(interpreter));957LoadSubCommand("status", status_cmd_sp);958}959};960961EnableOptionsSP ParseAutoEnableOptions(Status &error, Debugger &debugger) {962Log *log = GetLog(LLDBLog::Process);963// We are abusing the options data model here so that we can parse options964// without requiring the Debugger instance.965966// We have an empty execution context at this point. We only want to parse967// options, and we don't need any context to do this here. In fact, we want968// to be able to parse the enable options before having any context.969ExecutionContext exe_ctx;970971EnableOptionsSP options_sp(new EnableOptions());972options_sp->NotifyOptionParsingStarting(&exe_ctx);973974CommandReturnObject result(debugger.GetUseColor());975976// Parse the arguments.977auto options_property_sp =978debugger.GetPropertyValue(nullptr,979"plugin.structured-data.darwin-log."980"auto-enable-options",981error);982if (!error.Success())983return EnableOptionsSP();984if (!options_property_sp) {985error.SetErrorString("failed to find option setting for "986"plugin.structured-data.darwin-log.");987return EnableOptionsSP();988}989990const char *enable_options =991options_property_sp->GetAsString()->GetCurrentValue();992Args args(enable_options);993if (args.GetArgumentCount() > 0) {994// Eliminate the initial '--' that would be required to set the settings995// that themselves include '-' and/or '--'.996const char *first_arg = args.GetArgumentAtIndex(0);997if (first_arg && (strcmp(first_arg, "--") == 0))998args.Shift();999}10001001bool require_validation = false;1002llvm::Expected<Args> args_or =1003options_sp->Parse(args, &exe_ctx, PlatformSP(), require_validation);1004if (!args_or) {1005LLDB_LOG_ERROR(1006log, args_or.takeError(),1007"Parsing plugin.structured-data.darwin-log.auto-enable-options value "1008"failed: {0}");1009return EnableOptionsSP();1010}10111012if (!options_sp->VerifyOptions(result))1013return EnableOptionsSP();10141015// We successfully parsed and validated the options.1016return options_sp;1017}10181019bool RunEnableCommand(CommandInterpreter &interpreter) {1020StreamString command_stream;10211022command_stream << "plugin structured-data darwin-log enable";1023auto enable_options = GetGlobalProperties().GetAutoEnableOptions();1024if (!enable_options.empty()) {1025command_stream << ' ';1026command_stream << enable_options;1027}10281029// Run the command.1030CommandReturnObject return_object(interpreter.GetDebugger().GetUseColor());1031interpreter.HandleCommand(command_stream.GetData(), eLazyBoolNo,1032return_object);1033return return_object.Succeeded();1034}1035}1036using namespace sddarwinlog_private;10371038#pragma mark -1039#pragma mark Public static API10401041// Public static API10421043void StructuredDataDarwinLog::Initialize() {1044RegisterFilterOperations();1045PluginManager::RegisterPlugin(1046GetStaticPluginName(), "Darwin os_log() and os_activity() support",1047&CreateInstance, &DebuggerInitialize, &FilterLaunchInfo);1048}10491050void StructuredDataDarwinLog::Terminate() {1051PluginManager::UnregisterPlugin(&CreateInstance);1052}10531054#pragma mark -1055#pragma mark StructuredDataPlugin API10561057// StructuredDataPlugin API10581059bool StructuredDataDarwinLog::SupportsStructuredDataType(1060llvm::StringRef type_name) {1061return type_name == GetDarwinLogTypeName();1062}10631064void StructuredDataDarwinLog::HandleArrivalOfStructuredData(1065Process &process, llvm::StringRef type_name,1066const StructuredData::ObjectSP &object_sp) {1067Log *log = GetLog(LLDBLog::Process);1068if (log) {1069StreamString json_stream;1070if (object_sp)1071object_sp->Dump(json_stream);1072else1073json_stream.PutCString("<null>");1074LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called with json: %s",1075__FUNCTION__, json_stream.GetData());1076}10771078// Ignore empty structured data.1079if (!object_sp) {1080LLDB_LOGF(log,1081"StructuredDataDarwinLog::%s() StructuredData object "1082"is null",1083__FUNCTION__);1084return;1085}10861087// Ignore any data that isn't for us.1088if (type_name != GetDarwinLogTypeName()) {1089LLDB_LOG(log,1090"StructuredData type expected to be {0} but was {1}, ignoring",1091GetDarwinLogTypeName(), type_name);1092return;1093}10941095// Broadcast the structured data event if we have that enabled. This is the1096// way that the outside world (all clients) get access to this data. This1097// plugin sets policy as to whether we do that.1098DebuggerSP debugger_sp = process.GetTarget().GetDebugger().shared_from_this();1099auto options_sp = GetGlobalEnableOptions(debugger_sp);1100if (options_sp && options_sp->GetBroadcastEvents()) {1101LLDB_LOGF(log, "StructuredDataDarwinLog::%s() broadcasting event",1102__FUNCTION__);1103process.BroadcastStructuredData(object_sp, shared_from_this());1104}11051106// Later, hang on to a configurable amount of these and allow commands to1107// inspect, including showing backtraces.1108}11091110static void SetErrorWithJSON(Status &error, const char *message,1111StructuredData::Object &object) {1112if (!message) {1113error.SetErrorString("Internal error: message not set.");1114return;1115}11161117StreamString object_stream;1118object.Dump(object_stream);1119object_stream.Flush();11201121error.SetErrorStringWithFormat("%s: %s", message, object_stream.GetData());1122}11231124Status StructuredDataDarwinLog::GetDescription(1125const StructuredData::ObjectSP &object_sp, lldb_private::Stream &stream) {1126Status error;11271128if (!object_sp) {1129error.SetErrorString("No structured data.");1130return error;1131}11321133// Log message payload objects will be dictionaries.1134const StructuredData::Dictionary *dictionary = object_sp->GetAsDictionary();1135if (!dictionary) {1136SetErrorWithJSON(error, "Structured data should have been a dictionary "1137"but wasn't",1138*object_sp);1139return error;1140}11411142// Validate this is really a message for our plugin.1143llvm::StringRef type_name;1144if (!dictionary->GetValueForKeyAsString("type", type_name)) {1145SetErrorWithJSON(error, "Structured data doesn't contain mandatory "1146"type field",1147*object_sp);1148return error;1149}11501151if (type_name != GetDarwinLogTypeName()) {1152// This is okay - it simply means the data we received is not a log1153// message. We'll just format it as is.1154object_sp->Dump(stream);1155return error;1156}11571158// DarwinLog dictionaries store their data1159// in an array with key name "events".1160StructuredData::Array *events = nullptr;1161if (!dictionary->GetValueForKeyAsArray("events", events) || !events) {1162SetErrorWithJSON(error, "Log structured data is missing mandatory "1163"'events' field, expected to be an array",1164*object_sp);1165return error;1166}11671168events->ForEach(1169[&stream, &error, &object_sp, this](StructuredData::Object *object) {1170if (!object) {1171// Invalid. Stop iterating.1172SetErrorWithJSON(error, "Log event entry is null", *object_sp);1173return false;1174}11751176auto event = object->GetAsDictionary();1177if (!event) {1178// Invalid, stop iterating.1179SetErrorWithJSON(error, "Log event is not a dictionary", *object_sp);1180return false;1181}11821183// If we haven't already grabbed the first timestamp value, do that1184// now.1185if (!m_recorded_first_timestamp) {1186uint64_t timestamp = 0;1187if (event->GetValueForKeyAsInteger("timestamp", timestamp)) {1188m_first_timestamp_seen = timestamp;1189m_recorded_first_timestamp = true;1190}1191}11921193HandleDisplayOfEvent(*event, stream);1194return true;1195});11961197stream.Flush();1198return error;1199}12001201bool StructuredDataDarwinLog::GetEnabled(llvm::StringRef type_name) const {1202if (type_name == GetStaticPluginName())1203return m_is_enabled;1204return false;1205}12061207void StructuredDataDarwinLog::SetEnabled(bool enabled) {1208m_is_enabled = enabled;1209}12101211void StructuredDataDarwinLog::ModulesDidLoad(Process &process,1212ModuleList &module_list) {1213Log *log = GetLog(LLDBLog::Process);1214LLDB_LOGF(log, "StructuredDataDarwinLog::%s called (process uid %u)",1215__FUNCTION__, process.GetUniqueID());12161217// Check if we should enable the darwin log support on startup/attach.1218if (!GetGlobalProperties().GetEnableOnStartup() &&1219!s_is_explicitly_enabled) {1220// We're neither auto-enabled or explicitly enabled, so we shouldn't try to1221// enable here.1222LLDB_LOGF(log,1223"StructuredDataDarwinLog::%s not applicable, we're not "1224"enabled (process uid %u)",1225__FUNCTION__, process.GetUniqueID());1226return;1227}12281229// If we already added the breakpoint, we've got nothing left to do.1230{1231std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);1232if (m_added_breakpoint) {1233LLDB_LOGF(log,1234"StructuredDataDarwinLog::%s process uid %u's "1235"post-libtrace-init breakpoint is already set",1236__FUNCTION__, process.GetUniqueID());1237return;1238}1239}12401241// The logging support module name, specifies the name of the image name that1242// must be loaded into the debugged process before we can try to enable1243// logging.1244const char *logging_module_cstr =1245GetGlobalProperties().GetLoggingModuleName();1246if (!logging_module_cstr || (logging_module_cstr[0] == 0)) {1247// We need this. Bail.1248LLDB_LOGF(log,1249"StructuredDataDarwinLog::%s no logging module name "1250"specified, we don't know where to set a breakpoint "1251"(process uid %u)",1252__FUNCTION__, process.GetUniqueID());1253return;1254}12551256// We need to see libtrace in the list of modules before we can enable1257// tracing for the target process.1258bool found_logging_support_module = false;1259for (size_t i = 0; i < module_list.GetSize(); ++i) {1260auto module_sp = module_list.GetModuleAtIndex(i);1261if (!module_sp)1262continue;12631264auto &file_spec = module_sp->GetFileSpec();1265found_logging_support_module =1266(file_spec.GetFilename() == logging_module_cstr);1267if (found_logging_support_module)1268break;1269}12701271if (!found_logging_support_module) {1272LLDB_LOGF(log,1273"StructuredDataDarwinLog::%s logging module %s "1274"has not yet been loaded, can't set a breakpoint "1275"yet (process uid %u)",1276__FUNCTION__, logging_module_cstr, process.GetUniqueID());1277return;1278}12791280// Time to enqueue the breakpoint so we can wait for logging support to be1281// initialized before we try to tap the libtrace stream.1282AddInitCompletionHook(process);1283LLDB_LOGF(log,1284"StructuredDataDarwinLog::%s post-init hook breakpoint "1285"set for logging module %s (process uid %u)",1286__FUNCTION__, logging_module_cstr, process.GetUniqueID());12871288// We need to try the enable here as well, which will succeed in the event1289// that we're attaching to (rather than launching) the process and the1290// process is already past initialization time. In that case, the completion1291// breakpoint will never get hit and therefore won't start that way. It1292// doesn't hurt much beyond a bit of bandwidth if we end up doing this twice.1293// It hurts much more if we don't get the logging enabled when the user1294// expects it.1295EnableNow();1296}12971298// public destructor12991300StructuredDataDarwinLog::~StructuredDataDarwinLog() {1301if (m_breakpoint_id != LLDB_INVALID_BREAK_ID) {1302ProcessSP process_sp(GetProcess());1303if (process_sp) {1304process_sp->GetTarget().RemoveBreakpointByID(m_breakpoint_id);1305m_breakpoint_id = LLDB_INVALID_BREAK_ID;1306}1307}1308}13091310#pragma mark -1311#pragma mark Private instance methods13121313// Private constructors13141315StructuredDataDarwinLog::StructuredDataDarwinLog(const ProcessWP &process_wp)1316: StructuredDataPlugin(process_wp), m_recorded_first_timestamp(false),1317m_first_timestamp_seen(0), m_is_enabled(false),1318m_added_breakpoint_mutex(), m_added_breakpoint(),1319m_breakpoint_id(LLDB_INVALID_BREAK_ID) {}13201321// Private static methods13221323StructuredDataPluginSP1324StructuredDataDarwinLog::CreateInstance(Process &process) {1325// Currently only Apple targets support the os_log/os_activity protocol.1326if (process.GetTarget().GetArchitecture().GetTriple().getVendor() ==1327llvm::Triple::VendorType::Apple) {1328auto process_wp = ProcessWP(process.shared_from_this());1329return StructuredDataPluginSP(new StructuredDataDarwinLog(process_wp));1330} else {1331return StructuredDataPluginSP();1332}1333}13341335void StructuredDataDarwinLog::DebuggerInitialize(Debugger &debugger) {1336// Setup parent class first.1337StructuredDataPlugin::InitializeBasePluginForDebugger(debugger);13381339// Get parent command.1340auto &interpreter = debugger.GetCommandInterpreter();1341llvm::StringRef parent_command_text = "plugin structured-data";1342auto parent_command =1343interpreter.GetCommandObjectForCommand(parent_command_text);1344if (!parent_command) {1345// Ut oh, parent failed to create parent command.1346// TODO log1347return;1348}13491350auto command_name = "darwin-log";1351auto command_sp = CommandObjectSP(new BaseCommand(interpreter));1352bool result = parent_command->LoadSubCommand(command_name, command_sp);1353if (!result) {1354// TODO log it once we setup structured data logging1355}13561357if (!PluginManager::GetSettingForPlatformPlugin(1358debugger, StructuredDataDarwinLogProperties::GetSettingName())) {1359const bool is_global_setting = true;1360PluginManager::CreateSettingForStructuredDataPlugin(1361debugger, GetGlobalProperties().GetValueProperties(),1362"Properties for the darwin-log plug-in.", is_global_setting);1363}1364}13651366Status StructuredDataDarwinLog::FilterLaunchInfo(ProcessLaunchInfo &launch_info,1367Target *target) {1368Status error;13691370// If we're not debugging this launched process, there's nothing for us to do1371// here.1372if (!launch_info.GetFlags().AnySet(eLaunchFlagDebug))1373return error;13741375// Darwin os_log() support automatically adds debug-level and info-level1376// messages when a debugger is attached to a process. However, with1377// integrated support for debugging built into the command-line LLDB, the1378// user may specifically set to *not* include debug-level and info-level1379// content. When the user is using the integrated log support, we want to1380// put the kabosh on that automatic adding of info and debug level. This is1381// done by adding an environment variable to the process on launch. (This1382// also means it is not possible to suppress this behavior if attaching to an1383// already-running app).1384// Log *log = GetLog(LLDBLog::Platform);13851386// If the target architecture is not one that supports DarwinLog, we have1387// nothing to do here.1388auto &triple = target ? target->GetArchitecture().GetTriple()1389: launch_info.GetArchitecture().GetTriple();1390if (triple.getVendor() != llvm::Triple::Apple) {1391return error;1392}13931394// If DarwinLog is not enabled (either by explicit user command or via the1395// auto-enable option), then we have nothing to do.1396if (!GetGlobalProperties().GetEnableOnStartup() &&1397!s_is_explicitly_enabled) {1398// Nothing to do, DarwinLog is not enabled.1399return error;1400}14011402// If we don't have parsed configuration info, that implies we have enable-1403// on-startup set up, but we haven't yet attempted to run the enable command.1404if (!target) {1405// We really can't do this without a target. We need to be able to get to1406// the debugger to get the proper options to do this right.1407// TODO log.1408error.SetErrorString("requires a target to auto-enable DarwinLog.");1409return error;1410}14111412DebuggerSP debugger_sp = target->GetDebugger().shared_from_this();1413auto options_sp = GetGlobalEnableOptions(debugger_sp);1414if (!options_sp && debugger_sp) {1415options_sp = ParseAutoEnableOptions(error, *debugger_sp.get());1416if (!options_sp || !error.Success())1417return error;14181419// We already parsed the options, save them now so we don't generate them1420// again until the user runs the command manually.1421SetGlobalEnableOptions(debugger_sp, options_sp);1422}14231424if (!options_sp->GetEchoToStdErr()) {1425// The user doesn't want to see os_log/NSLog messages echo to stderr. That1426// mechanism is entirely separate from the DarwinLog support. By default we1427// don't want to get it via stderr, because that would be in duplicate of1428// the explicit log support here.14291430// Here we need to strip out any OS_ACTIVITY_DT_MODE setting to prevent1431// echoing of os_log()/NSLog() to stderr in the target program.1432launch_info.GetEnvironment().erase("OS_ACTIVITY_DT_MODE");14331434// We will also set the env var that tells any downstream launcher from1435// adding OS_ACTIVITY_DT_MODE.1436launch_info.GetEnvironment()["IDE_DISABLED_OS_ACTIVITY_DT_MODE"] = "1";1437}14381439// Set the OS_ACTIVITY_MODE env var appropriately to enable/disable debug and1440// info level messages.1441const char *env_var_value;1442if (options_sp->GetIncludeDebugLevel())1443env_var_value = "debug";1444else if (options_sp->GetIncludeInfoLevel())1445env_var_value = "info";1446else1447env_var_value = "default";14481449launch_info.GetEnvironment()["OS_ACTIVITY_MODE"] = env_var_value;14501451return error;1452}14531454bool StructuredDataDarwinLog::InitCompletionHookCallback(1455void *baton, StoppointCallbackContext *context, lldb::user_id_t break_id,1456lldb::user_id_t break_loc_id) {1457// We hit the init function. We now want to enqueue our new thread plan,1458// which will in turn enqueue a StepOut thread plan. When the StepOut1459// finishes and control returns to our new thread plan, that is the time when1460// we can execute our logic to enable the logging support.14611462Log *log = GetLog(LLDBLog::Process);1463LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called", __FUNCTION__);14641465// Get the current thread.1466if (!context) {1467LLDB_LOGF(log,1468"StructuredDataDarwinLog::%s() warning: no context, "1469"ignoring",1470__FUNCTION__);1471return false;1472}14731474// Get the plugin from the process.1475auto process_sp = context->exe_ctx_ref.GetProcessSP();1476if (!process_sp) {1477LLDB_LOGF(log,1478"StructuredDataDarwinLog::%s() warning: invalid "1479"process in context, ignoring",1480__FUNCTION__);1481return false;1482}1483LLDB_LOGF(log, "StructuredDataDarwinLog::%s() call is for process uid %d",1484__FUNCTION__, process_sp->GetUniqueID());14851486auto plugin_sp = process_sp->GetStructuredDataPlugin(GetDarwinLogTypeName());1487if (!plugin_sp) {1488LLDB_LOG(log, "warning: no plugin for feature {0} in process uid {1}",1489GetDarwinLogTypeName(), process_sp->GetUniqueID());1490return false;1491}14921493// Create the callback for when the thread plan completes.1494bool called_enable_method = false;1495const auto process_uid = process_sp->GetUniqueID();14961497std::weak_ptr<StructuredDataPlugin> plugin_wp(plugin_sp);1498ThreadPlanCallOnFunctionExit::Callback callback =1499[plugin_wp, &called_enable_method, log, process_uid]() {1500LLDB_LOGF(log,1501"StructuredDataDarwinLog::post-init callback: "1502"called (process uid %u)",1503process_uid);15041505auto strong_plugin_sp = plugin_wp.lock();1506if (!strong_plugin_sp) {1507LLDB_LOGF(log,1508"StructuredDataDarwinLog::post-init callback: "1509"plugin no longer exists, ignoring (process "1510"uid %u)",1511process_uid);1512return;1513}1514// Make sure we only call it once, just in case the thread plan hits1515// the breakpoint twice.1516if (!called_enable_method) {1517LLDB_LOGF(log,1518"StructuredDataDarwinLog::post-init callback: "1519"calling EnableNow() (process uid %u)",1520process_uid);1521static_cast<StructuredDataDarwinLog *>(strong_plugin_sp.get())1522->EnableNow();1523called_enable_method = true;1524} else {1525// Our breakpoint was hit more than once. Unexpected but no harm1526// done. Log it.1527LLDB_LOGF(log,1528"StructuredDataDarwinLog::post-init callback: "1529"skipping EnableNow(), already called by "1530"callback [we hit this more than once] "1531"(process uid %u)",1532process_uid);1533}1534};15351536// Grab the current thread.1537auto thread_sp = context->exe_ctx_ref.GetThreadSP();1538if (!thread_sp) {1539LLDB_LOGF(log,1540"StructuredDataDarwinLog::%s() warning: failed to "1541"retrieve the current thread from the execution "1542"context, nowhere to run the thread plan (process uid "1543"%u)",1544__FUNCTION__, process_sp->GetUniqueID());1545return false;1546}15471548// Queue the thread plan.1549auto thread_plan_sp =1550ThreadPlanSP(new ThreadPlanCallOnFunctionExit(*thread_sp, callback));1551const bool abort_other_plans = false;1552thread_sp->QueueThreadPlan(thread_plan_sp, abort_other_plans);1553LLDB_LOGF(log,1554"StructuredDataDarwinLog::%s() queuing thread plan on "1555"trace library init method entry (process uid %u)",1556__FUNCTION__, process_sp->GetUniqueID());15571558// We return false here to indicate that it isn't a public stop.1559return false;1560}15611562void StructuredDataDarwinLog::AddInitCompletionHook(Process &process) {1563Log *log = GetLog(LLDBLog::Process);1564LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called (process uid %u)",1565__FUNCTION__, process.GetUniqueID());15661567// Make sure we haven't already done this.1568{1569std::lock_guard<std::mutex> locker(m_added_breakpoint_mutex);1570if (m_added_breakpoint) {1571LLDB_LOGF(log,1572"StructuredDataDarwinLog::%s() ignoring request, "1573"breakpoint already set (process uid %u)",1574__FUNCTION__, process.GetUniqueID());1575return;1576}15771578// We're about to do this, don't let anybody else try to do it.1579m_added_breakpoint = true;1580}15811582// Set a breakpoint for the process that will kick in when libtrace has1583// finished its initialization.1584Target &target = process.GetTarget();15851586// Build up the module list.1587FileSpecList module_spec_list;1588auto module_file_spec =1589FileSpec(GetGlobalProperties().GetLoggingModuleName());1590module_spec_list.Append(module_file_spec);15911592// We aren't specifying a source file set.1593FileSpecList *source_spec_list = nullptr;15941595const char *func_name = "_libtrace_init";1596const lldb::addr_t offset = 0;1597const LazyBool skip_prologue = eLazyBoolCalculate;1598// This is an internal breakpoint - the user shouldn't see it.1599const bool internal = true;1600const bool hardware = false;16011602auto breakpoint_sp = target.CreateBreakpoint(1603&module_spec_list, source_spec_list, func_name, eFunctionNameTypeFull,1604eLanguageTypeC, offset, skip_prologue, internal, hardware);1605if (!breakpoint_sp) {1606// Huh? Bail here.1607LLDB_LOGF(log,1608"StructuredDataDarwinLog::%s() failed to set "1609"breakpoint in module %s, function %s (process uid %u)",1610__FUNCTION__, GetGlobalProperties().GetLoggingModuleName(),1611func_name, process.GetUniqueID());1612return;1613}16141615// Set our callback.1616breakpoint_sp->SetCallback(InitCompletionHookCallback, nullptr);1617m_breakpoint_id = breakpoint_sp->GetID();1618LLDB_LOGF(log,1619"StructuredDataDarwinLog::%s() breakpoint set in module %s,"1620"function %s (process uid %u)",1621__FUNCTION__, GetGlobalProperties().GetLoggingModuleName(),1622func_name, process.GetUniqueID());1623}16241625void StructuredDataDarwinLog::DumpTimestamp(Stream &stream,1626uint64_t timestamp) {1627const uint64_t delta_nanos = timestamp - m_first_timestamp_seen;16281629const uint64_t hours = delta_nanos / NANOS_PER_HOUR;1630uint64_t nanos_remaining = delta_nanos % NANOS_PER_HOUR;16311632const uint64_t minutes = nanos_remaining / NANOS_PER_MINUTE;1633nanos_remaining = nanos_remaining % NANOS_PER_MINUTE;16341635const uint64_t seconds = nanos_remaining / NANOS_PER_SECOND;1636nanos_remaining = nanos_remaining % NANOS_PER_SECOND;16371638stream.Printf("%02" PRIu64 ":%02" PRIu64 ":%02" PRIu64 ".%09" PRIu64, hours,1639minutes, seconds, nanos_remaining);1640}16411642size_t1643StructuredDataDarwinLog::DumpHeader(Stream &output_stream,1644const StructuredData::Dictionary &event) {1645StreamString stream;16461647ProcessSP process_sp = GetProcess();1648if (!process_sp) {1649// TODO log1650return 0;1651}16521653DebuggerSP debugger_sp =1654process_sp->GetTarget().GetDebugger().shared_from_this();1655if (!debugger_sp) {1656// TODO log1657return 0;1658}16591660auto options_sp = GetGlobalEnableOptions(debugger_sp);1661if (!options_sp) {1662// TODO log1663return 0;1664}16651666// Check if we should even display a header.1667if (!options_sp->GetDisplayAnyHeaderFields())1668return 0;16691670stream.PutChar('[');16711672int header_count = 0;1673if (options_sp->GetDisplayTimestampRelative()) {1674uint64_t timestamp = 0;1675if (event.GetValueForKeyAsInteger("timestamp", timestamp)) {1676DumpTimestamp(stream, timestamp);1677++header_count;1678}1679}16801681if (options_sp->GetDisplayActivityChain()) {1682llvm::StringRef activity_chain;1683if (event.GetValueForKeyAsString("activity-chain", activity_chain) &&1684!activity_chain.empty()) {1685if (header_count > 0)1686stream.PutChar(',');16871688// Display the activity chain, from parent-most to child-most activity,1689// separated by a colon (:).1690stream.PutCString("activity-chain=");1691stream.PutCString(activity_chain);1692++header_count;1693}1694}16951696if (options_sp->GetDisplaySubsystem()) {1697llvm::StringRef subsystem;1698if (event.GetValueForKeyAsString("subsystem", subsystem) &&1699!subsystem.empty()) {1700if (header_count > 0)1701stream.PutChar(',');1702stream.PutCString("subsystem=");1703stream.PutCString(subsystem);1704++header_count;1705}1706}17071708if (options_sp->GetDisplayCategory()) {1709llvm::StringRef category;1710if (event.GetValueForKeyAsString("category", category) &&1711!category.empty()) {1712if (header_count > 0)1713stream.PutChar(',');1714stream.PutCString("category=");1715stream.PutCString(category);1716++header_count;1717}1718}1719stream.PutCString("] ");17201721output_stream.PutCString(stream.GetString());17221723return stream.GetSize();1724}17251726size_t StructuredDataDarwinLog::HandleDisplayOfEvent(1727const StructuredData::Dictionary &event, Stream &stream) {1728// Check the type of the event.1729llvm::StringRef event_type;1730if (!event.GetValueForKeyAsString("type", event_type)) {1731// Hmm, we expected to get events that describe what they are. Continue1732// anyway.1733return 0;1734}17351736if (event_type != GetLogEventType())1737return 0;17381739size_t total_bytes = 0;17401741// Grab the message content.1742llvm::StringRef message;1743if (!event.GetValueForKeyAsString("message", message))1744return true;17451746// Display the log entry.1747const auto len = message.size();17481749total_bytes += DumpHeader(stream, event);17501751stream.Write(message.data(), len);1752total_bytes += len;17531754// Add an end of line.1755stream.PutChar('\n');1756total_bytes += sizeof(char);17571758return total_bytes;1759}17601761void StructuredDataDarwinLog::EnableNow() {1762Log *log = GetLog(LLDBLog::Process);1763LLDB_LOGF(log, "StructuredDataDarwinLog::%s() called", __FUNCTION__);17641765// Run the enable command.1766auto process_sp = GetProcess();1767if (!process_sp) {1768// Nothing to do.1769LLDB_LOGF(log,1770"StructuredDataDarwinLog::%s() warning: failed to get "1771"valid process, skipping",1772__FUNCTION__);1773return;1774}1775LLDB_LOGF(log, "StructuredDataDarwinLog::%s() call is for process uid %u",1776__FUNCTION__, process_sp->GetUniqueID());17771778// If we have configuration data, we can directly enable it now. Otherwise,1779// we need to run through the command interpreter to parse the auto-run1780// options (which is the only way we get here without having already-parsed1781// configuration data).1782DebuggerSP debugger_sp =1783process_sp->GetTarget().GetDebugger().shared_from_this();1784if (!debugger_sp) {1785LLDB_LOGF(log,1786"StructuredDataDarwinLog::%s() warning: failed to get "1787"debugger shared pointer, skipping (process uid %u)",1788__FUNCTION__, process_sp->GetUniqueID());1789return;1790}17911792auto options_sp = GetGlobalEnableOptions(debugger_sp);1793if (!options_sp) {1794// We haven't run the enable command yet. Just do that now, it'll take1795// care of the rest.1796auto &interpreter = debugger_sp->GetCommandInterpreter();1797const bool success = RunEnableCommand(interpreter);1798if (log) {1799if (success)1800LLDB_LOGF(log,1801"StructuredDataDarwinLog::%s() ran enable command "1802"successfully for (process uid %u)",1803__FUNCTION__, process_sp->GetUniqueID());1804else1805LLDB_LOGF(log,1806"StructuredDataDarwinLog::%s() error: running "1807"enable command failed (process uid %u)",1808__FUNCTION__, process_sp->GetUniqueID());1809}1810Debugger::ReportError("failed to configure DarwinLog support",1811debugger_sp->GetID());1812return;1813}18141815// We've previously been enabled. We will re-enable now with the previously1816// specified options.1817auto config_sp = options_sp->BuildConfigurationData(true);1818if (!config_sp) {1819LLDB_LOGF(log,1820"StructuredDataDarwinLog::%s() warning: failed to "1821"build configuration data for enable options, skipping "1822"(process uid %u)",1823__FUNCTION__, process_sp->GetUniqueID());1824return;1825}18261827// We can run it directly.1828// Send configuration to the feature by way of the process.1829const Status error =1830process_sp->ConfigureStructuredData(GetDarwinLogTypeName(), config_sp);18311832// Report results.1833if (!error.Success()) {1834LLDB_LOGF(log,1835"StructuredDataDarwinLog::%s() "1836"ConfigureStructuredData() call failed "1837"(process uid %u): %s",1838__FUNCTION__, process_sp->GetUniqueID(), error.AsCString());1839Debugger::ReportError("failed to configure DarwinLog support",1840debugger_sp->GetID());1841m_is_enabled = false;1842} else {1843m_is_enabled = true;1844LLDB_LOGF(log,1845"StructuredDataDarwinLog::%s() success via direct "1846"configuration (process uid %u)",1847__FUNCTION__, process_sp->GetUniqueID());1848}1849}185018511852