1 //===-- DarwinLogCollector.cpp ----------------------------------*- C++ -*-===//
2 //
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6 //
7 //===----------------------------------------------------------------------===//
8
9 #include "DarwinLogCollector.h"
10 #include "ActivityStreamSPI.h"
11
12 #include <dlfcn.h>
13
14 #include <cinttypes>
15 #include <memory>
16 #include <mutex>
17 #include <vector>
18
19 #include "DNB.h"
20 #include "DNBLog.h"
21 #include "DarwinLogTypes.h"
22 #include "LogFilterChain.h"
23 #include "LogFilterExactMatch.h"
24 #include "LogFilterRegex.h"
25 #include "LogMessageOsLog.h"
26 #include "MachProcess.h"
27 #include "RNBContext.h"
28 #include "RNBDefs.h"
29 #include "RNBRemote.h"
30
31 // Use an anonymous namespace for variables and methods that have no
32 // reason to leak out through the interface.
33 namespace {
34 /// Specify max depth that the activity parent-child chain will search
35 /// back to get the full activity chain name. If we do more than this,
36 /// we assume either we hit a loop or it's just too long.
37 static const size_t MAX_ACTIVITY_CHAIN_DEPTH = 10;
38
39 // Used to tap into and retrieve logs from target process.
40 // (Consumer of os_log).
41 static os_activity_stream_for_pid_t s_os_activity_stream_for_pid;
42 static os_activity_stream_resume_t s_os_activity_stream_resume;
43 static os_activity_stream_cancel_t s_os_activity_stream_cancel;
44 static os_log_copy_formatted_message_t s_os_log_copy_formatted_message;
45 static os_activity_stream_set_event_handler_t
46 s_os_activity_stream_set_event_handler;
47
LookupSPICalls()48 bool LookupSPICalls() {
49 static std::once_flag s_once_flag;
50 static bool s_has_spi;
51
52 std::call_once(s_once_flag, [] {
53 dlopen ("/System/Library/PrivateFrameworks/LoggingSupport.framework/LoggingSupport", RTLD_NOW);
54 s_os_activity_stream_for_pid = (os_activity_stream_for_pid_t)dlsym(
55 RTLD_DEFAULT, "os_activity_stream_for_pid");
56 s_os_activity_stream_resume = (os_activity_stream_resume_t)dlsym(
57 RTLD_DEFAULT, "os_activity_stream_resume");
58 s_os_activity_stream_cancel = (os_activity_stream_cancel_t)dlsym(
59 RTLD_DEFAULT, "os_activity_stream_cancel");
60 s_os_log_copy_formatted_message = (os_log_copy_formatted_message_t)dlsym(
61 RTLD_DEFAULT, "os_log_copy_formatted_message");
62 s_os_activity_stream_set_event_handler =
63 (os_activity_stream_set_event_handler_t)dlsym(
64 RTLD_DEFAULT, "os_activity_stream_set_event_handler");
65
66 // We'll indicate we're all set if every function entry point
67 // was found.
68 s_has_spi = (s_os_activity_stream_for_pid != nullptr) &&
69 (s_os_activity_stream_resume != nullptr) &&
70 (s_os_activity_stream_cancel != nullptr) &&
71 (s_os_log_copy_formatted_message != nullptr) &&
72 (s_os_activity_stream_set_event_handler != nullptr);
73 if (s_has_spi) {
74 DNBLogThreadedIf(LOG_DARWIN_LOG, "Found os_log SPI calls.");
75 // Tell LogMessageOsLog how to format messages when search
76 // criteria requires it.
77 LogMessageOsLog::SetFormatterFunction(s_os_log_copy_formatted_message);
78 } else {
79 DNBLogThreadedIf(LOG_DARWIN_LOG, "Failed to find os_log SPI "
80 "calls.");
81 }
82 });
83
84 return s_has_spi;
85 }
86
87 using Mutex = std::mutex;
88 static Mutex s_collector_mutex;
89 static std::vector<DarwinLogCollectorSP> s_collectors;
90
TrackCollector(const DarwinLogCollectorSP & collector_sp)91 static void TrackCollector(const DarwinLogCollectorSP &collector_sp) {
92 std::lock_guard<Mutex> locker(s_collector_mutex);
93 if (std::find(s_collectors.begin(), s_collectors.end(), collector_sp) !=
94 s_collectors.end()) {
95 DNBLogThreadedIf(LOG_DARWIN_LOG,
96 "attempted to add same collector multiple times");
97 return;
98 }
99 s_collectors.push_back(collector_sp);
100 }
101
StopTrackingCollector(const DarwinLogCollectorSP & collector_sp)102 static void StopTrackingCollector(const DarwinLogCollectorSP &collector_sp) {
103 std::lock_guard<Mutex> locker(s_collector_mutex);
104 s_collectors.erase(
105 std::remove(s_collectors.begin(), s_collectors.end(), collector_sp),
106 s_collectors.end());
107 }
108
FindCollectorForProcess(pid_t pid)109 static DarwinLogCollectorSP FindCollectorForProcess(pid_t pid) {
110 std::lock_guard<Mutex> locker(s_collector_mutex);
111 for (const auto &collector_sp : s_collectors) {
112 if (collector_sp && (collector_sp->GetProcessID() == pid))
113 return collector_sp;
114 }
115 return DarwinLogCollectorSP();
116 }
117
TargetStringToEnum(const std::string & filter_target_name)118 static FilterTarget TargetStringToEnum(const std::string &filter_target_name) {
119 if (filter_target_name == "activity")
120 return eFilterTargetActivity;
121 else if (filter_target_name == "activity-chain")
122 return eFilterTargetActivityChain;
123 else if (filter_target_name == "category")
124 return eFilterTargetCategory;
125 else if (filter_target_name == "message")
126 return eFilterTargetMessage;
127 else if (filter_target_name == "subsystem")
128 return eFilterTargetSubsystem;
129 else
130 return eFilterTargetInvalid;
131 }
132
133 class Configuration {
134 public:
Configuration(const JSONObject & config)135 Configuration(const JSONObject &config)
136 : m_is_valid(false),
137 m_activity_stream_flags(OS_ACTIVITY_STREAM_PROCESS_ONLY),
138 m_filter_chain_sp(nullptr) {
139 // Parse out activity stream flags
140 if (!ParseSourceFlags(config)) {
141 m_is_valid = false;
142 return;
143 }
144
145 // Parse filter rules
146 if (!ParseFilterRules(config)) {
147 m_is_valid = false;
148 return;
149 }
150
151 // Everything worked.
152 m_is_valid = true;
153 }
154
ParseSourceFlags(const JSONObject & config)155 bool ParseSourceFlags(const JSONObject &config) {
156 // Get the source-flags dictionary.
157 auto source_flags_sp = config.GetObject("source-flags");
158 if (!source_flags_sp)
159 return false;
160 if (!JSONObject::classof(source_flags_sp.get()))
161 return false;
162
163 const JSONObject &source_flags =
164 *static_cast<JSONObject *>(source_flags_sp.get());
165
166 // Parse out the flags.
167 bool include_any_process = false;
168 bool include_callstacks = false;
169 bool include_info_level = false;
170 bool include_debug_level = false;
171 bool live_stream = false;
172
173 if (!source_flags.GetObjectAsBool("any-process", include_any_process)) {
174 DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'any-process' missing from "
175 "configuration.");
176 return false;
177 }
178 if (!source_flags.GetObjectAsBool("callstacks", include_callstacks)) {
179 // We currently suppress the availability of this on the lldb
180 // side. We include here for devices when we enable in the
181 // future.
182 // DNBLogThreadedIf(LOG_DARWIN_LOG,
183 // "Source-flag 'callstacks' missing from "
184 // "configuration.");
185
186 // OK. We just skip callstacks.
187 // return false;
188 }
189 if (!source_flags.GetObjectAsBool("info-level", include_info_level)) {
190 DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'info-level' missing from "
191 "configuration.");
192 return false;
193 }
194 if (!source_flags.GetObjectAsBool("debug-level", include_debug_level)) {
195 DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'debug-level' missing from "
196 "configuration.");
197 return false;
198 }
199 if (!source_flags.GetObjectAsBool("live-stream", live_stream)) {
200 DNBLogThreadedIf(LOG_DARWIN_LOG, "Source-flag 'live-stream' missing from "
201 "configuration.");
202 return false;
203 }
204
205 // Setup the SPI flags based on this.
206 m_activity_stream_flags = 0;
207 if (!include_any_process)
208 m_activity_stream_flags |= OS_ACTIVITY_STREAM_PROCESS_ONLY;
209 if (include_callstacks)
210 m_activity_stream_flags |= OS_ACTIVITY_STREAM_CALLSTACK;
211 if (include_info_level)
212 m_activity_stream_flags |= OS_ACTIVITY_STREAM_INFO;
213 if (include_debug_level)
214 m_activity_stream_flags |= OS_ACTIVITY_STREAM_DEBUG;
215 if (!live_stream)
216 m_activity_stream_flags |= OS_ACTIVITY_STREAM_BUFFERED;
217
218 DNBLogThreadedIf(LOG_DARWIN_LOG, "m_activity_stream_flags = 0x%03x",
219 m_activity_stream_flags);
220
221 return true;
222 }
223
ParseFilterRules(const JSONObject & config)224 bool ParseFilterRules(const JSONObject &config) {
225 // Retrieve the default rule.
226 bool filter_default_accept = true;
227 if (!config.GetObjectAsBool("filter-fall-through-accepts",
228 filter_default_accept)) {
229 DNBLogThreadedIf(LOG_DARWIN_LOG, "Setting 'filter-fall-through-accepts' "
230 "missing from configuration.");
231 return false;
232 }
233 m_filter_chain_sp = std::make_shared<LogFilterChain>(filter_default_accept);
234 DNBLogThreadedIf(LOG_DARWIN_LOG, "DarwinLog no-match rule: %s.",
235 filter_default_accept ? "accept" : "reject");
236
237 // If we don't have the filter-rules array, we're done.
238 auto filter_rules_sp = config.GetObject("filter-rules");
239 if (!filter_rules_sp) {
240 DNBLogThreadedIf(LOG_DARWIN_LOG,
241 "No 'filter-rules' config element, all log "
242 "entries will use the no-match action (%s).",
243 filter_default_accept ? "accept" : "reject");
244 return true;
245 }
246 if (!JSONArray::classof(filter_rules_sp.get()))
247 return false;
248 const JSONArray &rules_config =
249 *static_cast<JSONArray *>(filter_rules_sp.get());
250
251 // Create the filters.
252 for (auto &rule_sp : rules_config.m_elements) {
253 if (!JSONObject::classof(rule_sp.get()))
254 return false;
255 const JSONObject &rule_config = *static_cast<JSONObject *>(rule_sp.get());
256
257 // Get whether this filter accepts or rejects.
258 bool filter_accepts = true;
259 if (!rule_config.GetObjectAsBool("accept", filter_accepts)) {
260 DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'accept' element missing.");
261 return false;
262 }
263
264 // Grab the target log field attribute for the match.
265 std::string target_attribute;
266 if (!rule_config.GetObjectAsString("attribute", target_attribute)) {
267 DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'attribute' element missing.");
268 return false;
269 }
270 auto target_enum = TargetStringToEnum(target_attribute);
271 if (target_enum == eFilterTargetInvalid) {
272 DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter attribute '%s' unsupported.",
273 target_attribute.c_str());
274 return false;
275 }
276
277 // Handle operation-specific fields and filter creation.
278 std::string filter_type;
279 if (!rule_config.GetObjectAsString("type", filter_type)) {
280 DNBLogThreadedIf(LOG_DARWIN_LOG, "Filter 'type' element missing.");
281 return false;
282 }
283 DNBLogThreadedIf(LOG_DARWIN_LOG, "Reading filter of type '%s'",
284 filter_type.c_str());
285
286 LogFilterSP filter_sp;
287 if (filter_type == "regex") {
288 // Grab the regex for the match.
289 std::string regex;
290 if (!rule_config.GetObjectAsString("regex", regex)) {
291 DNBLogError("Regex filter missing 'regex' element.");
292 return false;
293 }
294 DNBLogThreadedIf(LOG_DARWIN_LOG, "regex for filter: \"%s\"",
295 regex.c_str());
296
297 // Create the regex filter.
298 auto regex_filter =
299 new LogFilterRegex(filter_accepts, target_enum, regex);
300 filter_sp.reset(regex_filter);
301
302 // Validate that the filter is okay.
303 if (!regex_filter->IsValid()) {
304 DNBLogError("Invalid regex in filter: "
305 "regex=\"%s\", error=%s",
306 regex.c_str(), regex_filter->GetErrorAsCString());
307 return false;
308 }
309 } else if (filter_type == "match") {
310 // Grab the regex for the match.
311 std::string exact_text;
312 if (!rule_config.GetObjectAsString("exact_text", exact_text)) {
313 DNBLogError("Exact match filter missing "
314 "'exact_text' element.");
315 return false;
316 }
317
318 // Create the filter.
319 filter_sp = std::make_shared<LogFilterExactMatch>(
320 filter_accepts, target_enum, exact_text);
321 }
322
323 // Add the filter to the chain.
324 m_filter_chain_sp->AppendFilter(filter_sp);
325 }
326 return true;
327 }
328
IsValid() const329 bool IsValid() const { return m_is_valid; }
330
GetActivityStreamFlags() const331 os_activity_stream_flag_t GetActivityStreamFlags() const {
332 return m_activity_stream_flags;
333 }
334
GetLogFilterChain() const335 const LogFilterChainSP &GetLogFilterChain() const {
336 return m_filter_chain_sp;
337 }
338
339 private:
340 bool m_is_valid;
341 os_activity_stream_flag_t m_activity_stream_flags;
342 LogFilterChainSP m_filter_chain_sp;
343 };
344 }
345
IsSupported()346 bool DarwinLogCollector::IsSupported() {
347 // We're supported if we have successfully looked up the SPI entry points.
348 return LookupSPICalls();
349 }
350
StartCollectingForProcess(nub_process_t pid,const JSONObject & config)351 bool DarwinLogCollector::StartCollectingForProcess(nub_process_t pid,
352 const JSONObject &config) {
353 // If we're currently collecting for this process, kill the existing
354 // collector.
355 if (CancelStreamForProcess(pid)) {
356 DNBLogThreadedIf(LOG_DARWIN_LOG,
357 "%s() killed existing DarwinLog collector for pid %d.",
358 __FUNCTION__, pid);
359 }
360
361 // If the process isn't alive, we're done.
362 if (!DNBProcessIsAlive(pid)) {
363 DNBLogThreadedIf(LOG_DARWIN_LOG,
364 "%s() cannot collect for pid %d: process not alive.",
365 __FUNCTION__, pid);
366 return false;
367 }
368
369 // Validate the configuration.
370 auto spi_config = Configuration(config);
371 if (!spi_config.IsValid()) {
372 DNBLogThreadedIf(LOG_DARWIN_LOG,
373 "%s() invalid configuration, will not enable log "
374 "collection",
375 __FUNCTION__);
376 return false;
377 }
378
379 // Create the stream collector that will manage collected data
380 // for this pid.
381 DarwinLogCollectorSP collector_sp(
382 new DarwinLogCollector(pid, spi_config.GetLogFilterChain()));
383 std::weak_ptr<DarwinLogCollector> collector_wp(collector_sp);
384
385 // Setup the stream handling block.
386 os_activity_stream_block_t block =
387 ^bool(os_activity_stream_entry_t entry, int error) {
388 // Check if our collector is still alive.
389 DarwinLogCollectorSP inner_collector_sp = collector_wp.lock();
390 if (!inner_collector_sp)
391 return false;
392 return inner_collector_sp->HandleStreamEntry(entry, error);
393 };
394
395 os_activity_stream_event_block_t stream_event_block = ^void(
396 os_activity_stream_t stream, os_activity_stream_event_t event) {
397 switch (event) {
398 case OS_ACTIVITY_STREAM_EVENT_STARTED:
399 DNBLogThreadedIf(LOG_DARWIN_LOG,
400 "received stream event: "
401 "OS_ACTIVITY_STREAM_EVENT_STARTED, stream %p.",
402 (void *)stream);
403 break;
404 case OS_ACTIVITY_STREAM_EVENT_STOPPED:
405 DNBLogThreadedIf(LOG_DARWIN_LOG,
406 "received stream event: "
407 "OS_ACTIVITY_STREAM_EVENT_STOPPED, stream %p.",
408 (void *)stream);
409 break;
410 case OS_ACTIVITY_STREAM_EVENT_FAILED:
411 DNBLogThreadedIf(LOG_DARWIN_LOG,
412 "received stream event: "
413 "OS_ACTIVITY_STREAM_EVENT_FAILED, stream %p.",
414 (void *)stream);
415 break;
416 case OS_ACTIVITY_STREAM_EVENT_CHUNK_STARTED:
417 DNBLogThreadedIf(LOG_DARWIN_LOG,
418 "received stream event: "
419 "OS_ACTIVITY_STREAM_EVENT_CHUNK_STARTED, stream %p.",
420 (void *)stream);
421 break;
422 case OS_ACTIVITY_STREAM_EVENT_CHUNK_FINISHED:
423 DNBLogThreadedIf(LOG_DARWIN_LOG,
424 "received stream event: "
425 "OS_ACTIVITY_STREAM_EVENT_CHUNK_FINISHED, stream %p.",
426 (void *)stream);
427 break;
428 }
429 };
430
431 // Create the stream.
432 os_activity_stream_t activity_stream = (*s_os_activity_stream_for_pid)(
433 pid, spi_config.GetActivityStreamFlags(), block);
434 collector_sp->SetActivityStream(activity_stream);
435
436 // Specify the stream-related event handler.
437 (*s_os_activity_stream_set_event_handler)(activity_stream,
438 stream_event_block);
439
440 // Start the stream.
441 (*s_os_activity_stream_resume)(activity_stream);
442
443 TrackCollector(collector_sp);
444 return true;
445 }
446
447 DarwinLogEventVector
GetEventsForProcess(nub_process_t pid)448 DarwinLogCollector::GetEventsForProcess(nub_process_t pid) {
449 auto collector_sp = FindCollectorForProcess(pid);
450 if (!collector_sp) {
451 // We're not tracking a stream for this process.
452 return DarwinLogEventVector();
453 }
454
455 return collector_sp->RemoveEvents();
456 }
457
CancelStreamForProcess(nub_process_t pid)458 bool DarwinLogCollector::CancelStreamForProcess(nub_process_t pid) {
459 auto collector_sp = FindCollectorForProcess(pid);
460 if (!collector_sp) {
461 // We're not tracking a stream for this process.
462 return false;
463 }
464
465 collector_sp->CancelActivityStream();
466 StopTrackingCollector(collector_sp);
467
468 return true;
469 }
470
471 const char *
GetActivityForID(os_activity_id_t activity_id) const472 DarwinLogCollector::GetActivityForID(os_activity_id_t activity_id) const {
473 auto find_it = m_activity_map.find(activity_id);
474 return (find_it != m_activity_map.end()) ? find_it->second.m_name.c_str()
475 : nullptr;
476 }
477
478 /// Retrieve the full parent-child chain for activity names. These
479 /// can be arbitrarily deep. This method assumes the caller has already
480 /// locked the activity mutex.
GetActivityChainForID_internal(os_activity_id_t activity_id,std::string & result,size_t depth) const481 void DarwinLogCollector::GetActivityChainForID_internal(
482 os_activity_id_t activity_id, std::string &result, size_t depth) const {
483 if (depth > MAX_ACTIVITY_CHAIN_DEPTH) {
484 // Terminating condition - too deeply nested.
485 return;
486 } else if (activity_id == 0) {
487 // Terminating condition - no activity.
488 return;
489 }
490
491 auto find_it = m_activity_map.find(activity_id);
492 if (find_it == m_activity_map.end()) {
493 // Terminating condition - no data for activity_id.
494 return;
495 }
496
497 // Activity name becomes parent activity name chain + ':' + our activity
498 // name.
499 GetActivityChainForID_internal(find_it->second.m_parent_id, result,
500 depth + 1);
501 if (!result.empty())
502 result += ':';
503 result += find_it->second.m_name;
504 }
505
506 std::string
GetActivityChainForID(os_activity_id_t activity_id) const507 DarwinLogCollector::GetActivityChainForID(os_activity_id_t activity_id) const {
508 std::string result;
509 {
510 std::lock_guard<std::mutex> locker(m_activity_info_mutex);
511 GetActivityChainForID_internal(activity_id, result, 1);
512 }
513 return result;
514 }
515
DarwinLogCollector(nub_process_t pid,const LogFilterChainSP & filter_chain_sp)516 DarwinLogCollector::DarwinLogCollector(nub_process_t pid,
517 const LogFilterChainSP &filter_chain_sp)
518 : ActivityStore(), m_pid(pid), m_activity_stream(0), m_events(),
519 m_events_mutex(), m_filter_chain_sp(filter_chain_sp),
520 m_activity_info_mutex(), m_activity_map() {}
521
~DarwinLogCollector()522 DarwinLogCollector::~DarwinLogCollector() {
523 // Cancel the stream.
524 if (m_activity_stream) {
525 DNBLogThreadedIf(LOG_DARWIN_LOG, "tearing down activity stream "
526 "collector for %d",
527 m_pid);
528 (*s_os_activity_stream_cancel)(m_activity_stream);
529 m_activity_stream = 0;
530 } else {
531 DNBLogThreadedIf(LOG_DARWIN_LOG, "no stream to tear down for %d", m_pid);
532 }
533 }
534
SignalDataAvailable()535 void DarwinLogCollector::SignalDataAvailable() {
536 RNBRemoteSP remoteSP(g_remoteSP);
537 if (!remoteSP) {
538 // We're done. This is unexpected.
539 StopTrackingCollector(shared_from_this());
540 return;
541 }
542
543 RNBContext &ctx = remoteSP->Context();
544 ctx.Events().SetEvents(RNBContext::event_darwin_log_data_available);
545 // Wait for the main thread to consume this notification if it requested
546 // we wait for it.
547 ctx.Events().WaitForResetAck(RNBContext::event_darwin_log_data_available);
548 }
549
SetActivityStream(os_activity_stream_t activity_stream)550 void DarwinLogCollector::SetActivityStream(
551 os_activity_stream_t activity_stream) {
552 m_activity_stream = activity_stream;
553 }
554
HandleStreamEntry(os_activity_stream_entry_t entry,int error)555 bool DarwinLogCollector::HandleStreamEntry(os_activity_stream_entry_t entry,
556 int error) {
557 if ((error == 0) && (entry != nullptr)) {
558 if (entry->pid != m_pid) {
559 // For now, skip messages not originating from our process.
560 // Later we might want to keep all messages related to an event
561 // that we're tracking, even when it came from another process,
562 // possibly doing work on our behalf.
563 return true;
564 }
565
566 switch (entry->type) {
567 case OS_ACTIVITY_STREAM_TYPE_ACTIVITY_CREATE:
568 DNBLogThreadedIf(
569 LOG_DARWIN_LOG, "received activity create: "
570 "%s, creator aid %" PRIu64 ", unique_pid %" PRIu64
571 "(activity id=%" PRIu64 ", parent id=%" PRIu64 ")",
572 entry->activity_create.name, entry->activity_create.creator_aid,
573 entry->activity_create.unique_pid, entry->activity_id,
574 entry->parent_id);
575 {
576 std::lock_guard<std::mutex> locker(m_activity_info_mutex);
577 m_activity_map.insert(
578 std::make_pair(entry->activity_id,
579 ActivityInfo(entry->activity_create.name,
580 entry->activity_id, entry->parent_id)));
581 }
582 break;
583
584 case OS_ACTIVITY_STREAM_TYPE_ACTIVITY_TRANSITION:
585 DNBLogThreadedIf(
586 LOG_DARWIN_LOG, "received activity transition:"
587 "new aid: %" PRIu64 "(activity id=%" PRIu64
588 ", parent id=%" PRIu64 ", tid %" PRIu64 ")",
589 entry->activity_transition.transition_id, entry->activity_id,
590 entry->parent_id, entry->activity_transition.thread);
591 break;
592
593 case OS_ACTIVITY_STREAM_TYPE_LOG_MESSAGE: {
594 DNBLogThreadedIf(
595 LOG_DARWIN_LOG, "received log message: "
596 "(activity id=%" PRIu64 ", parent id=%" PRIu64 ", "
597 "tid %" PRIu64 "): format %s",
598 entry->activity_id, entry->parent_id, entry->log_message.thread,
599 entry->log_message.format ? entry->log_message.format
600 : "<invalid-format>");
601
602 // Do the real work here.
603 {
604 // Ensure our process is still alive. If not, we can
605 // cancel the collection.
606 if (!DNBProcessIsAlive(m_pid)) {
607 // We're outta here. This is the manner in which we
608 // stop collecting for a process.
609 StopTrackingCollector(shared_from_this());
610 return false;
611 }
612
613 LogMessageOsLog os_log_message(*this, *entry);
614 if (!m_filter_chain_sp ||
615 !m_filter_chain_sp->GetAcceptMessage(os_log_message)) {
616 // This log message was rejected by the filter,
617 // so stop processing it now.
618 return true;
619 }
620
621 // Copy over the relevant bits from the message.
622 const struct os_log_message_s &log_message = entry->log_message;
623
624 DarwinLogEventSP message_sp(new DarwinLogEvent());
625 // Indicate this event is a log message event.
626 message_sp->AddStringItem("type", "log");
627
628 // Add the message contents (fully expanded).
629 // Consider expanding on the remote side.
630 // Then we don't pay for expansion until when it is
631 // used.
632 const char *message_text = os_log_message.GetMessage();
633 if (message_text)
634 message_sp->AddStringItem("message", message_text);
635
636 // Add some useful data fields.
637 message_sp->AddIntegerItem("timestamp", log_message.timestamp);
638
639 // Do we want to do all activity name resolution on this
640 // side? Maybe. For now, send IDs and ID->name mappings
641 // and fix this up on that side. Later, when we add
642 // debugserver-side filtering, we'll want to get the
643 // activity names over here, so we should probably
644 // just send them as resolved strings.
645 message_sp->AddIntegerItem("activity_id", entry->activity_id);
646 message_sp->AddIntegerItem("parent_id", entry->parent_id);
647 message_sp->AddIntegerItem("thread_id", log_message.thread);
648 if (log_message.subsystem && strlen(log_message.subsystem) > 0)
649 message_sp->AddStringItem("subsystem", log_message.subsystem);
650 if (log_message.category && strlen(log_message.category) > 0)
651 message_sp->AddStringItem("category", log_message.category);
652 if (entry->activity_id != 0) {
653 std::string activity_chain =
654 GetActivityChainForID(entry->activity_id);
655 if (!activity_chain.empty())
656 message_sp->AddStringItem("activity-chain", activity_chain);
657 }
658
659 // Add it to the list for later collection.
660 {
661 std::lock_guard<std::mutex> locker(m_events_mutex);
662 m_events.push_back(message_sp);
663 }
664 SignalDataAvailable();
665 }
666 break;
667 }
668 }
669 } else {
670 DNBLogThreadedIf(LOG_DARWIN_LOG, "HandleStreamEntry: final call, "
671 "error %d",
672 error);
673 }
674 return true;
675 }
676
RemoveEvents()677 DarwinLogEventVector DarwinLogCollector::RemoveEvents() {
678 DarwinLogEventVector returned_events;
679 {
680 std::lock_guard<std::mutex> locker(m_events_mutex);
681 returned_events.swap(m_events);
682 }
683 DNBLogThreadedIf(LOG_DARWIN_LOG, "DarwinLogCollector::%s(): removing %lu "
684 "queued log entries",
685 __FUNCTION__, returned_events.size());
686 return returned_events;
687 }
688
CancelActivityStream()689 void DarwinLogCollector::CancelActivityStream() {
690 if (!m_activity_stream)
691 return;
692
693 DNBLogThreadedIf(LOG_DARWIN_LOG,
694 "DarwinLogCollector::%s(): canceling "
695 "activity stream %p",
696 __FUNCTION__, static_cast<void *>(m_activity_stream));
697 (*s_os_activity_stream_cancel)(m_activity_stream);
698 m_activity_stream = nullptr;
699 }
700