b9c1b51e45
*** to conform to clang-format’s LLVM style. This kind of mass change has
*** two obvious implications:
Firstly, merging this particular commit into a downstream fork may be a huge
effort. Alternatively, it may be worth merging all changes up to this commit,
performing the same reformatting operation locally, and then discarding the
merge for this particular commit. The commands used to accomplish this
reformatting were as follows (with current working directory as the root of
the repository):
find . \( -iname "*.c" -or -iname "*.cpp" -or -iname "*.h" -or -iname "*.mm" \) -exec clang-format -i {} +
find . -iname "*.py" -exec autopep8 --in-place --aggressive --aggressive {} + ;
The version of clang-format used was 3.9.0, and autopep8 was 1.2.4.
Secondly, “blame” style tools will generally point to this commit instead of
a meaningful prior commit. There are alternatives available that will attempt
to look through this change and find the appropriate prior commit. YMMV.
llvm-svn: 280751
698 lines
25 KiB
C++
698 lines
25 KiB
C++
//===-- DarwinLogCollector.cpp ----------------------------------*- C++ -*-===//
|
|
//
|
|
// The LLVM Compiler Infrastructure
|
|
//
|
|
// This file is distributed under the University of Illinois Open Source
|
|
// License. See LICENSE.TXT for details.
|
|
//
|
|
//===----------------------------------------------------------------------===//
|
|
|
|
#include "DarwinLogCollector.h"
|
|
#include "ActivityStreamSPI.h"
|
|
|
|
#include <dlfcn.h>
|
|
|
|
#include <cinttypes>
|
|
#include <mutex>
|
|
#include <vector>
|
|
|
|
#include "DNB.h"
|
|
#include "DNBLog.h"
|
|
#include "DarwinLogTypes.h"
|
|
#include "LogFilterChain.h"
|
|
#include "LogFilterExactMatch.h"
|
|
#include "LogFilterRegex.h"
|
|
#include "LogMessageOsLog.h"
|
|
#include "MachProcess.h"
|
|
#include "RNBContext.h"
|
|
#include "RNBDefs.h"
|
|
#include "RNBRemote.h"
|
|
|
|
// Use an anonymous namespace for variables and methods that have no
|
|
// reason to leak out through the interface.
|
|
namespace {
|
|
/// Specify max depth that the activity parent-child chain will search
|
|
/// back to get the full activity chain name. If we do more than this,
|
|
/// we assume either we hit a loop or it's just too long.
|
|
static const size_t MAX_ACTIVITY_CHAIN_DEPTH = 10;
|
|
|
|
// Used to tap into and retrieve logs from target process.
|
|
// (Consumer of os_log).
|
|
static os_activity_stream_for_pid_t s_os_activity_stream_for_pid;
|
|
static os_activity_stream_resume_t s_os_activity_stream_resume;
|
|
static os_activity_stream_cancel_t s_os_activity_stream_cancel;
|
|
static os_log_copy_formatted_message_t s_os_log_copy_formatted_message;
|
|
static os_activity_stream_set_event_handler_t
|
|
s_os_activity_stream_set_event_handler;
|
|
|
|
bool LookupSPICalls() {
|
|
static std::once_flag s_once_flag;
|
|
static bool s_has_spi;
|
|
|
|
std::call_once(s_once_flag, [] {
|
|
s_os_activity_stream_for_pid = (os_activity_stream_for_pid_t)dlsym(
|
|
RTLD_DEFAULT, "os_activity_stream_for_pid");
|
|
s_os_activity_stream_resume = (os_activity_stream_resume_t)dlsym(
|
|
RTLD_DEFAULT, "os_activity_stream_resume");
|
|
s_os_activity_stream_cancel = (os_activity_stream_cancel_t)dlsym(
|
|
RTLD_DEFAULT, "os_activity_stream_cancel");
|
|
s_os_log_copy_formatted_message = (os_log_copy_formatted_message_t)dlsym(
|
|
RTLD_DEFAULT, "os_log_copy_formatted_message");
|
|
s_os_activity_stream_set_event_handler =
|
|
(os_activity_stream_set_event_handler_t)dlsym(
|
|
RTLD_DEFAULT, "os_activity_stream_set_event_handler");
|
|
|
|
// We'll indicate we're all set if every function entry point
|
|
// was found.
|
|
s_has_spi = (s_os_activity_stream_for_pid != nullptr) &&
|
|
(s_os_activity_stream_resume != nullptr) &&
|
|
(s_os_activity_stream_cancel != nullptr) &&
|
|
(s_os_log_copy_formatted_message != nullptr) &&
|
|
(s_os_activity_stream_set_event_handler != nullptr);
|
|
if (s_has_spi) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Found os_log SPI calls.");
|
|
// Tell LogMessageOsLog how to format messages when search
|
|
// criteria requires it.
|
|
LogMessageOsLog::SetFormatterFunction(s_os_log_copy_formatted_message);
|
|
} else {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Failed to find os_log SPI "
|
|
"calls.");
|
|
}
|
|
});
|
|
|
|
return s_has_spi;
|
|
}
|
|
|
|
using Mutex = std::mutex;
|
|
static Mutex s_collector_mutex;
|
|
static std::vector<DarwinLogCollectorSP> s_collectors;
|
|
|
|
static void TrackCollector(const DarwinLogCollectorSP &collector_sp) {
|
|
std::lock_guard<Mutex> locker(s_collector_mutex);
|
|
if (std::find(s_collectors.begin(), s_collectors.end(), collector_sp) !=
|
|
s_collectors.end()) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"attempted to add same collector multiple times");
|
|
return;
|
|
}
|
|
s_collectors.push_back(collector_sp);
|
|
}
|
|
|
|
static void StopTrackingCollector(const DarwinLogCollectorSP &collector_sp) {
|
|
std::lock_guard<Mutex> locker(s_collector_mutex);
|
|
s_collectors.erase(
|
|
std::remove(s_collectors.begin(), s_collectors.end(), collector_sp),
|
|
s_collectors.end());
|
|
}
|
|
|
|
static DarwinLogCollectorSP FindCollectorForProcess(pid_t pid) {
|
|
std::lock_guard<Mutex> locker(s_collector_mutex);
|
|
for (const auto &collector_sp : s_collectors) {
|
|
if (collector_sp && (collector_sp->GetProcessID() == pid))
|
|
return collector_sp;
|
|
}
|
|
return DarwinLogCollectorSP();
|
|
}
|
|
|
|
static FilterTarget TargetStringToEnum(const std::string &filter_target_name) {
|
|
if (filter_target_name == "activity")
|
|
return eFilterTargetActivity;
|
|
else if (filter_target_name == "activity-chain")
|
|
return eFilterTargetActivityChain;
|
|
else if (filter_target_name == "category")
|
|
return eFilterTargetCategory;
|
|
else if (filter_target_name == "message")
|
|
return eFilterTargetMessage;
|
|
else if (filter_target_name == "subsystem")
|
|
return eFilterTargetSubsystem;
|
|
else
|
|
return eFilterTargetInvalid;
|
|
}
|
|
|
|
class Configuration {
|
|
public:
|
|
Configuration(const JSONObject &config)
|
|
: m_is_valid(false),
|
|
m_activity_stream_flags(OS_ACTIVITY_STREAM_PROCESS_ONLY),
|
|
m_filter_chain_sp(nullptr) {
|
|
// Parse out activity stream flags
|
|
if (!ParseSourceFlags(config)) {
|
|
m_is_valid = false;
|
|
return;
|
|
}
|
|
|
|
// Parse filter rules
|
|
if (!ParseFilterRules(config)) {
|
|
m_is_valid = false;
|
|
return;
|
|
}
|
|
|
|
// Everything worked.
|
|
m_is_valid = true;
|
|
}
|
|
|
|
bool ParseSourceFlags(const JSONObject &config) {
|
|
// Get the source-flags dictionary.
|
|
auto source_flags_sp = config.GetObject("source-flags");
|
|
if (!source_flags_sp)
|
|
return false;
|
|
if (!JSONObject::classof(source_flags_sp.get()))
|
|
return false;
|
|
|
|
const JSONObject &source_flags =
|
|
*static_cast<JSONObject *>(source_flags_sp.get());
|
|
|
|
// Parse out the flags.
|
|
bool include_any_process = false;
|
|
bool include_callstacks = false;
|
|
bool include_info_level = false;
|
|
bool include_debug_level = false;
|
|
bool live_stream = false;
|
|
|
|
if (!source_flags.GetObjectAsBool("any-process", include_any_process)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'any-process' missing from "
|
|
"configuration.");
|
|
return false;
|
|
}
|
|
if (!source_flags.GetObjectAsBool("callstacks", include_callstacks)) {
|
|
// We currently suppress the availability of this on the lldb
|
|
// side. We include here for devices when we enable in the
|
|
// future.
|
|
// DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
// "Source-flag 'callstacks' missing from "
|
|
// "configuration.");
|
|
|
|
// OK. We just skip callstacks.
|
|
// return false;
|
|
}
|
|
if (!source_flags.GetObjectAsBool("info-level", include_info_level)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'info-level' missing from "
|
|
"configuration.");
|
|
return false;
|
|
}
|
|
if (!source_flags.GetObjectAsBool("debug-level", include_debug_level)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'debug-level' missing from "
|
|
"configuration.");
|
|
return false;
|
|
}
|
|
if (!source_flags.GetObjectAsBool("live-stream", live_stream)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'live-stream' missing from "
|
|
"configuration.");
|
|
return false;
|
|
}
|
|
|
|
// Setup the SPI flags based on this.
|
|
m_activity_stream_flags = 0;
|
|
if (!include_any_process)
|
|
m_activity_stream_flags |= OS_ACTIVITY_STREAM_PROCESS_ONLY;
|
|
if (include_callstacks)
|
|
m_activity_stream_flags |= OS_ACTIVITY_STREAM_CALLSTACK;
|
|
if (include_info_level)
|
|
m_activity_stream_flags |= OS_ACTIVITY_STREAM_INFO;
|
|
if (include_debug_level)
|
|
m_activity_stream_flags |= OS_ACTIVITY_STREAM_DEBUG;
|
|
if (!live_stream)
|
|
m_activity_stream_flags |= OS_ACTIVITY_STREAM_BUFFERED;
|
|
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "m_activity_stream_flags = 0x%03x",
|
|
m_activity_stream_flags);
|
|
|
|
return true;
|
|
}
|
|
|
|
bool ParseFilterRules(const JSONObject &config) {
|
|
// Retrieve the default rule.
|
|
bool filter_default_accept = true;
|
|
if (!config.GetObjectAsBool("filter-fall-through-accepts",
|
|
filter_default_accept)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Setting 'filter-fall-through-accepts' "
|
|
"missing from configuration.");
|
|
return false;
|
|
}
|
|
m_filter_chain_sp.reset(new LogFilterChain(filter_default_accept));
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "DarwinLog no-match rule: %s.",
|
|
filter_default_accept ? "accept" : "reject");
|
|
|
|
// If we don't have the filter-rules array, we're done.
|
|
auto filter_rules_sp = config.GetObject("filter-rules");
|
|
if (!filter_rules_sp) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"No 'filter-rules' config element, all log "
|
|
"entries will use the no-match action (%s).",
|
|
filter_default_accept ? "accept" : "reject");
|
|
return true;
|
|
}
|
|
if (!JSONArray::classof(filter_rules_sp.get()))
|
|
return false;
|
|
const JSONArray &rules_config =
|
|
*static_cast<JSONArray *>(filter_rules_sp.get());
|
|
|
|
// Create the filters.
|
|
for (auto &rule_sp : rules_config.m_elements) {
|
|
if (!JSONObject::classof(rule_sp.get()))
|
|
return false;
|
|
const JSONObject &rule_config = *static_cast<JSONObject *>(rule_sp.get());
|
|
|
|
// Get whether this filter accepts or rejects.
|
|
bool filter_accepts = true;
|
|
if (!rule_config.GetObjectAsBool("accept", filter_accepts)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'accept' element missing.");
|
|
return false;
|
|
}
|
|
|
|
// Grab the target log field attribute for the match.
|
|
std::string target_attribute;
|
|
if (!rule_config.GetObjectAsString("attribute", target_attribute)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'attribute' element missing.");
|
|
return false;
|
|
}
|
|
auto target_enum = TargetStringToEnum(target_attribute);
|
|
if (target_enum == eFilterTargetInvalid) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter attribute '%s' unsupported.",
|
|
target_attribute.c_str());
|
|
return false;
|
|
}
|
|
|
|
// Handle operation-specific fields and filter creation.
|
|
std::string filter_type;
|
|
if (!rule_config.GetObjectAsString("type", filter_type)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'type' element missing.");
|
|
return false;
|
|
}
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "Reading filter of type '%s'",
|
|
filter_type.c_str());
|
|
|
|
LogFilterSP filter_sp;
|
|
if (filter_type == "regex") {
|
|
// Grab the regex for the match.
|
|
std::string regex;
|
|
if (!rule_config.GetObjectAsString("regex", regex)) {
|
|
DNBLogError("Regex filter missing 'regex' element.");
|
|
return false;
|
|
}
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "regex for filter: \"%s\"",
|
|
regex.c_str());
|
|
|
|
// Create the regex filter.
|
|
auto regex_filter =
|
|
new LogFilterRegex(filter_accepts, target_enum, regex);
|
|
filter_sp.reset(regex_filter);
|
|
|
|
// Validate that the filter is okay.
|
|
if (!regex_filter->IsValid()) {
|
|
DNBLogError("Invalid regex in filter: "
|
|
"regex=\"%s\", error=%s",
|
|
regex.c_str(), regex_filter->GetErrorAsCString());
|
|
return false;
|
|
}
|
|
} else if (filter_type == "match") {
|
|
// Grab the regex for the match.
|
|
std::string exact_text;
|
|
if (!rule_config.GetObjectAsString("exact_text", exact_text)) {
|
|
DNBLogError("Exact match filter missing "
|
|
"'exact_text' element.");
|
|
return false;
|
|
}
|
|
|
|
// Create the filter.
|
|
filter_sp.reset(
|
|
new LogFilterExactMatch(filter_accepts, target_enum, exact_text));
|
|
}
|
|
|
|
// Add the filter to the chain.
|
|
m_filter_chain_sp->AppendFilter(filter_sp);
|
|
}
|
|
return true;
|
|
}
|
|
|
|
bool IsValid() const { return m_is_valid; }
|
|
|
|
os_activity_stream_flag_t GetActivityStreamFlags() const {
|
|
return m_activity_stream_flags;
|
|
}
|
|
|
|
const LogFilterChainSP &GetLogFilterChain() const {
|
|
return m_filter_chain_sp;
|
|
}
|
|
|
|
private:
|
|
bool m_is_valid;
|
|
os_activity_stream_flag_t m_activity_stream_flags;
|
|
LogFilterChainSP m_filter_chain_sp;
|
|
};
|
|
}
|
|
|
|
bool DarwinLogCollector::IsSupported() {
|
|
// We're supported if we have successfully looked up the SPI entry points.
|
|
return LookupSPICalls();
|
|
}
|
|
|
|
bool DarwinLogCollector::StartCollectingForProcess(nub_process_t pid,
|
|
const JSONObject &config) {
|
|
// If we're currently collecting for this process, kill the existing
|
|
// collector.
|
|
if (CancelStreamForProcess(pid)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"%s() killed existing DarwinLog collector for pid %d.",
|
|
__FUNCTION__, pid);
|
|
}
|
|
|
|
// If the process isn't alive, we're done.
|
|
if (!DNBProcessIsAlive(pid)) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"%s() cannot collect for pid %d: process not alive.",
|
|
__FUNCTION__, pid);
|
|
return false;
|
|
}
|
|
|
|
// Validate the configuration.
|
|
auto spi_config = Configuration(config);
|
|
if (!spi_config.IsValid()) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"%s() invalid configuration, will not enable log "
|
|
"collection",
|
|
__FUNCTION__);
|
|
return false;
|
|
}
|
|
|
|
// Create the stream collector that will manage collected data
|
|
// for this pid.
|
|
DarwinLogCollectorSP collector_sp(
|
|
new DarwinLogCollector(pid, spi_config.GetLogFilterChain()));
|
|
std::weak_ptr<DarwinLogCollector> collector_wp(collector_sp);
|
|
|
|
// Setup the stream handling block.
|
|
os_activity_stream_block_t block =
|
|
^bool(os_activity_stream_entry_t entry, int error) {
|
|
// Check if our collector is still alive.
|
|
DarwinLogCollectorSP inner_collector_sp = collector_wp.lock();
|
|
if (!inner_collector_sp)
|
|
return false;
|
|
return inner_collector_sp->HandleStreamEntry(entry, error);
|
|
};
|
|
|
|
os_activity_stream_event_block_t stream_event_block = ^void(
|
|
os_activity_stream_t stream, os_activity_stream_event_t event) {
|
|
switch (event) {
|
|
case OS_ACTIVITY_STREAM_EVENT_STARTED:
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"received stream event: "
|
|
"OS_ACTIVITY_STREAM_EVENT_STARTED, stream %p.",
|
|
(void *)stream);
|
|
break;
|
|
case OS_ACTIVITY_STREAM_EVENT_STOPPED:
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"received stream event: "
|
|
"OS_ACTIVITY_STREAM_EVENT_STOPPED, stream %p.",
|
|
(void *)stream);
|
|
break;
|
|
case OS_ACTIVITY_STREAM_EVENT_FAILED:
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"received stream event: "
|
|
"OS_ACTIVITY_STREAM_EVENT_FAILED, stream %p.",
|
|
(void *)stream);
|
|
break;
|
|
case OS_ACTIVITY_STREAM_EVENT_CHUNK_STARTED:
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"received stream event: "
|
|
"OS_ACTIVITY_STREAM_EVENT_CHUNK_STARTED, stream %p.",
|
|
(void *)stream);
|
|
break;
|
|
case OS_ACTIVITY_STREAM_EVENT_CHUNK_FINISHED:
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG,
|
|
"received stream event: "
|
|
"OS_ACTIVITY_STREAM_EVENT_CHUNK_FINISHED, stream %p.",
|
|
(void *)stream);
|
|
break;
|
|
}
|
|
};
|
|
|
|
// Create the stream.
|
|
os_activity_stream_t activity_stream = (*s_os_activity_stream_for_pid)(
|
|
pid, spi_config.GetActivityStreamFlags(), block);
|
|
collector_sp->SetActivityStream(activity_stream);
|
|
|
|
// Specify the stream-related event handler.
|
|
(*s_os_activity_stream_set_event_handler)(activity_stream,
|
|
stream_event_block);
|
|
|
|
// Start the stream.
|
|
(*s_os_activity_stream_resume)(activity_stream);
|
|
|
|
TrackCollector(collector_sp);
|
|
return true;
|
|
}
|
|
|
|
DarwinLogEventVector
|
|
DarwinLogCollector::GetEventsForProcess(nub_process_t pid) {
|
|
auto collector_sp = FindCollectorForProcess(pid);
|
|
if (!collector_sp) {
|
|
// We're not tracking a stream for this process.
|
|
return DarwinLogEventVector();
|
|
}
|
|
|
|
return collector_sp->RemoveEvents();
|
|
}
|
|
|
|
bool DarwinLogCollector::CancelStreamForProcess(nub_process_t pid) {
|
|
auto collector_sp = FindCollectorForProcess(pid);
|
|
if (!collector_sp) {
|
|
// We're not tracking a stream for this process.
|
|
return false;
|
|
}
|
|
|
|
collector_sp->CancelActivityStream();
|
|
StopTrackingCollector(collector_sp);
|
|
|
|
return true;
|
|
}
|
|
|
|
const char *
|
|
DarwinLogCollector::GetActivityForID(os_activity_id_t activity_id) const {
|
|
auto find_it = m_activity_map.find(activity_id);
|
|
return (find_it != m_activity_map.end()) ? find_it->second.m_name.c_str()
|
|
: nullptr;
|
|
}
|
|
|
|
/// Retrieve the full parent-child chain for activity names. These
|
|
/// can be arbitrarily deep. This method assumes the caller has already
|
|
/// locked the activity mutex.
|
|
void DarwinLogCollector::GetActivityChainForID_internal(
|
|
os_activity_id_t activity_id, std::string &result, size_t depth) const {
|
|
if (depth > MAX_ACTIVITY_CHAIN_DEPTH) {
|
|
// Terminating condition - too deeply nested.
|
|
return;
|
|
} else if (activity_id == 0) {
|
|
// Terminating condition - no activity.
|
|
return;
|
|
}
|
|
|
|
auto find_it = m_activity_map.find(activity_id);
|
|
if (find_it == m_activity_map.end()) {
|
|
// Terminating condition - no data for activity_id.
|
|
return;
|
|
}
|
|
|
|
// Activity name becomes parent activity name chain + ':' + our activity
|
|
// name.
|
|
GetActivityChainForID_internal(find_it->second.m_parent_id, result,
|
|
depth + 1);
|
|
if (!result.empty())
|
|
result += ':';
|
|
result += find_it->second.m_name;
|
|
}
|
|
|
|
std::string
|
|
DarwinLogCollector::GetActivityChainForID(os_activity_id_t activity_id) const {
|
|
std::string result;
|
|
{
|
|
std::lock_guard<std::mutex> locker(m_activity_info_mutex);
|
|
GetActivityChainForID_internal(activity_id, result, 1);
|
|
}
|
|
return result;
|
|
}
|
|
|
|
DarwinLogCollector::DarwinLogCollector(nub_process_t pid,
|
|
const LogFilterChainSP &filter_chain_sp)
|
|
: ActivityStore(), m_pid(pid), m_activity_stream(0), m_events(),
|
|
m_events_mutex(), m_filter_chain_sp(filter_chain_sp),
|
|
m_activity_info_mutex(), m_activity_map() {}
|
|
|
|
DarwinLogCollector::~DarwinLogCollector() {
|
|
// Cancel the stream.
|
|
if (m_activity_stream) {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "tearing down activity stream "
|
|
"collector for %d",
|
|
m_pid);
|
|
(*s_os_activity_stream_cancel)(m_activity_stream);
|
|
m_activity_stream = 0;
|
|
} else {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "no stream to tear down for %d", m_pid);
|
|
}
|
|
}
|
|
|
|
void DarwinLogCollector::SignalDataAvailable() {
|
|
RNBRemoteSP remoteSP(g_remoteSP);
|
|
if (!remoteSP) {
|
|
// We're done. This is unexpected.
|
|
StopTrackingCollector(shared_from_this());
|
|
return;
|
|
}
|
|
|
|
RNBContext &ctx = remoteSP->Context();
|
|
ctx.Events().SetEvents(RNBContext::event_darwin_log_data_available);
|
|
// Wait for the main thread to consume this notification if it requested
|
|
// we wait for it.
|
|
ctx.Events().WaitForResetAck(RNBContext::event_darwin_log_data_available);
|
|
}
|
|
|
|
void DarwinLogCollector::SetActivityStream(
|
|
os_activity_stream_t activity_stream) {
|
|
m_activity_stream = activity_stream;
|
|
}
|
|
|
|
bool DarwinLogCollector::HandleStreamEntry(os_activity_stream_entry_t entry,
|
|
int error) {
|
|
if ((error == 0) && (entry != nullptr)) {
|
|
if (entry->pid != m_pid) {
|
|
// For now, skip messages not originating from our process.
|
|
// Later we might want to keep all messages related to an event
|
|
// that we're tracking, even when it came from another process,
|
|
// possibly doing work on our behalf.
|
|
return true;
|
|
}
|
|
|
|
switch (entry->type) {
|
|
case OS_ACTIVITY_STREAM_TYPE_ACTIVITY_CREATE:
|
|
DNBLogThreadedIf(
|
|
LOG_DARWIN_LOG, "received activity create: "
|
|
"%s, creator aid %" PRIu64 ", unique_pid %" PRIu64
|
|
"(activity id=%" PRIu64 ", parent id=%" PRIu64 ")",
|
|
entry->activity_create.name, entry->activity_create.creator_aid,
|
|
entry->activity_create.unique_pid, entry->activity_id,
|
|
entry->parent_id);
|
|
{
|
|
std::lock_guard<std::mutex> locker(m_activity_info_mutex);
|
|
m_activity_map.insert(
|
|
std::make_pair(entry->activity_id,
|
|
ActivityInfo(entry->activity_create.name,
|
|
entry->activity_id, entry->parent_id)));
|
|
}
|
|
break;
|
|
|
|
case OS_ACTIVITY_STREAM_TYPE_ACTIVITY_TRANSITION:
|
|
DNBLogThreadedIf(
|
|
LOG_DARWIN_LOG, "received activity transition:"
|
|
"new aid: %" PRIu64 "(activity id=%" PRIu64
|
|
", parent id=%" PRIu64 ", tid %" PRIu64 ")",
|
|
entry->activity_transition.transition_id, entry->activity_id,
|
|
entry->parent_id, entry->activity_transition.thread);
|
|
break;
|
|
|
|
case OS_ACTIVITY_STREAM_TYPE_LOG_MESSAGE: {
|
|
DNBLogThreadedIf(
|
|
LOG_DARWIN_LOG, "received log message: "
|
|
"(activity id=%" PRIu64 ", parent id=%" PRIu64 ", "
|
|
"tid %" PRIu64 "): format %s",
|
|
entry->activity_id, entry->parent_id, entry->log_message.thread,
|
|
entry->log_message.format ? entry->log_message.format
|
|
: "<invalid-format>");
|
|
|
|
// Do the real work here.
|
|
{
|
|
// Ensure our process is still alive. If not, we can
|
|
// cancel the collection.
|
|
if (!DNBProcessIsAlive(m_pid)) {
|
|
// We're outta here. This is the manner in which we
|
|
// stop collecting for a process.
|
|
StopTrackingCollector(shared_from_this());
|
|
return false;
|
|
}
|
|
|
|
LogMessageOsLog os_log_message(*this, *entry);
|
|
if (!m_filter_chain_sp ||
|
|
!m_filter_chain_sp->GetAcceptMessage(os_log_message)) {
|
|
// This log message was rejected by the filter,
|
|
// so stop processing it now.
|
|
return true;
|
|
}
|
|
|
|
// Copy over the relevant bits from the message.
|
|
const struct os_log_message_s &log_message = entry->log_message;
|
|
|
|
DarwinLogEventSP message_sp(new DarwinLogEvent());
|
|
// Indicate this event is a log message event.
|
|
message_sp->AddStringItem("type", "log");
|
|
|
|
// Add the message contents (fully expanded).
|
|
// Consider expanding on the remote side.
|
|
// Then we don't pay for expansion until when it is
|
|
// used.
|
|
const char *message_text = os_log_message.GetMessage();
|
|
if (message_text)
|
|
message_sp->AddStringItem("message", message_text);
|
|
|
|
// Add some useful data fields.
|
|
message_sp->AddIntegerItem("timestamp", log_message.timestamp);
|
|
|
|
// Do we want to do all activity name resolution on this
|
|
// side? Maybe. For now, send IDs and ID->name mappings
|
|
// and fix this up on that side. Later, when we add
|
|
// debugserver-side filtering, we'll want to get the
|
|
// activity names over here, so we should probably
|
|
// just send them as resolved strings.
|
|
message_sp->AddIntegerItem("activity_id", entry->activity_id);
|
|
message_sp->AddIntegerItem("parent_id", entry->parent_id);
|
|
message_sp->AddIntegerItem("thread_id", log_message.thread);
|
|
if (log_message.subsystem && strlen(log_message.subsystem) > 0)
|
|
message_sp->AddStringItem("subsystem", log_message.subsystem);
|
|
if (log_message.category && strlen(log_message.category) > 0)
|
|
message_sp->AddStringItem("category", log_message.category);
|
|
if (entry->activity_id != 0) {
|
|
std::string activity_chain =
|
|
GetActivityChainForID(entry->activity_id);
|
|
if (!activity_chain.empty())
|
|
message_sp->AddStringItem("activity-chain", activity_chain);
|
|
}
|
|
|
|
// Add it to the list for later collection.
|
|
{
|
|
std::lock_guard<std::mutex> locker(m_events_mutex);
|
|
m_events.push_back(message_sp);
|
|
}
|
|
SignalDataAvailable();
|
|
}
|
|
break;
|
|
}
|
|
}
|
|
} else {
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "HandleStreamEntry: final call, "
|
|
"error %d",
|
|
error);
|
|
}
|
|
return true;
|
|
}
|
|
|
|
DarwinLogEventVector DarwinLogCollector::RemoveEvents() {
|
|
DarwinLogEventVector returned_events;
|
|
{
|
|
std::lock_guard<std::mutex> locker(m_events_mutex);
|
|
returned_events.swap(m_events);
|
|
}
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "DarwinLogCollector::%s(): removing %lu "
|
|
"queued log entries",
|
|
__FUNCTION__, returned_events.size());
|
|
return returned_events;
|
|
}
|
|
|
|
void DarwinLogCollector::CancelActivityStream() {
|
|
if (!m_activity_stream)
|
|
return;
|
|
|
|
DNBLogThreadedIf(LOG_DARWIN_LOG, "DarwinLogCollector::%s(): canceling "
|
|
"activity stream %p",
|
|
__FUNCTION__, m_activity_stream);
|
|
(*s_os_activity_stream_cancel)(m_activity_stream);
|
|
m_activity_stream = nullptr;
|
|
}
|