src/dyld_usage.cpp

   1 /*
   2  * Copyright (c) 2017 Apple Inc. All rights reserved.
   3  *
   4  * @APPLE_LICENSE_HEADER_START@
   5  *
   6  * "Portions Copyright (c) 1999 Apple Computer, Inc.  All Rights
   7  * Reserved.  This file contains Original Code and/or Modifications of
   8  * Original Code as defined in and that are subject to the Apple Public
   9  * Source License Version 1.0 (the 'License').  You may not use this file
  10  * except in compliance with the License.  Please obtain a copy of the
  11  * License at http://www.apple.com/publicsource and read it before using
  12  * this file.
  13  *
  14  * The Original Code and all software distributed under the License are
  15  * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER
  16  * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,
  17  * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,
  18  * FITNESS FOR A PARTICULAR PURPOSE OR NON-INFRINGEMENT.  Please see the
  19  * License for the specific language governing rights and limitations
  20  * under the License."
  21  *
  22  * @APPLE_LICENSE_HEADER_END@
  23  */
  24
  25 #include <map>
  26 #include <set>
  27 #include <memory>
  28 #include <string>
  29 #include <cstring>
  30 #include <array>
  31 #include <vector>
  32 #include <iomanip>
  33 #include <sstream>
  34 #include <iostream>
  35 #include <cinttypes>
  36 #include <dlfcn.h>
  37 #include <unistd.h>
  38 #include <stdint.h>
  39 #include <termios.h>
  40 #include <sys/ioctl.h>
  41 #include <libutil.h>
  42 #include <ktrace/session.h>
  43 #include <dispatch/dispatch.h>
  44 #include <System/sys/kdebug.h>
  45
  46 #include "Tracing.h"
  47
  48 #define DBG_FUNC_ALL    (DBG_FUNC_START | DBG_FUNC_END)
  49
  50
  51 /*
  52  * MAXCOLS controls when extra data kicks in.
  53  * MAX_WIDE_MODE_COLS controls -w mode to get even wider data in path.
  54  */
  55 #define MAXCOLS (132)
  56 #define MAXWIDTH (MAXCOLS + 64)
  57
  58 unsigned int columns = 0;
  59 ktrace_session_t s;
  60 bool wideflag = false;
  61 bool RAW_flag = false;
  62 bool JSON_flag = false;
  63 bool JSON_Tracing_flag = false;
  64 dispatch_source_t sigwinch_source;
  65 static void
  66 exit_usage(void)
  67 {
  68     fprintf(stderr, "Usage: dyld_usage [-e] [-f mode] [-t seconds] [-R rawfile [-S start_time] [-E end_time]] [pid | cmd [pid | cmd] ...]\n");
  69     fprintf(stderr, "  -e    exclude the specified list of pids from the sample\n");
  70     fprintf(stderr, "        and exclude dyld_usage by default\n");
  71     fprintf(stderr, "  -t    specifies timeout in seconds (for use in automated tools)\n");
  72     fprintf(stderr, "  -R    specifies a raw trace file to process\n");
  73     fprintf(stderr, "  pid   selects process(s) to sample\n");
  74     fprintf(stderr, "  cmd   selects process(s) matching command string to sample\n");
  75     fprintf(stderr, "By default (no options) the following processes are excluded from the output:\n");
  76     fprintf(stderr, "dyld_usage, Terminal, telnetd, sshd, rlogind, tcsh, csh, sh\n\n");
  77
  78     exit(1);
  79 }
  80
  81 static void
  82 get_screenwidth(void)
  83 {
  84     struct winsize size;
  85
  86     columns = MAXCOLS;
  87
  88     if (isatty(STDOUT_FILENO)) {
  89         if (ioctl(1, TIOCGWINSZ, &size) != -1) {
  90             columns = size.ws_col;
  91
  92             if (columns > MAXWIDTH)
  93                 columns = MAXWIDTH;
  94         }
  95     }
  96 }
  97
  98 std::map<uint64_t, uint64_t> gActiveStringIDs;
  99 std::map<uint64_t, std::string> gActiveStrings;
 100
 101 const std::string& stringForID(uint64_t id) {
 102     static std::string emptyString = "";
 103     auto i = gActiveStrings.find(id);
 104     if (i == gActiveStrings.end())
 105         return emptyString;
 106     return i->second;
 107 }
 108
 109 static uint64_t
 110 mach_to_nano(uint64_t mach)
 111 {
 112     uint64_t nanoseconds = 0;
 113     assert(ktrace_convert_timestamp_to_nanoseconds(s, mach, &nanoseconds) == 0);
 114     return nanoseconds;
 115 }
 116
 117 static
 118 std::string safeStringFromCString(const char *str) {
 119     if (str) {
 120         return str;
 121     }
 122     return "";
 123 }
 124
 125 struct output_renderer {
 126     output_renderer(ktrace_session_t S, ktrace_event_t E) :
 127     _commandName(safeStringFromCString(ktrace_get_execname_for_thread(s, E->threadid))),
 128     _threadid((unsigned long)(E->threadid)), _pid(ktrace_get_pid_for_thread(s, E->threadid)) {}
 129     void recordEvent(ktrace_event_t event) {
 130         uint32_t code = event->debugid & KDBG_EVENTID_MASK;
 131         if (event->debugid & DBG_FUNC_START) {
 132             switch(code) {
 133                 case DBG_DYLD_TIMING_DLOPEN: enqueueEvent<dlopen>(event, true); break;
 134                 case DBG_DYLD_TIMING_DLOPEN_PREFLIGHT: enqueueEvent<dlopen_preflight>(event, true); break;
 135                 case DBG_DYLD_TIMING_LAUNCH_EXECUTABLE: enqueueEvent<app_launch>(event, true); break;
 136                 case DBG_DYLD_TIMING_DLSYM: enqueueEvent<dlsym>(event, true); break;
 137                 case DBG_DYLD_TIMING_STATIC_INITIALIZER: enqueueEvent<static_init>(event, false); break;
 138                 case DBG_DYLD_TIMING_MAP_IMAGE: enqueueEvent<map_image>(event, false); break;
 139                 case DBG_DYLD_TIMING_APPLY_FIXUPS: enqueueEvent<apply_fixups>(event, false); break;
 140                 case DBG_DYLD_TIMING_ATTACH_CODESIGNATURE: enqueueEvent<attach_signature>(event, false); break;
 141                 case DBG_DYLD_TIMING_BUILD_CLOSURE: enqueueEvent<build_closure>(event, false); break;
 142                 case DBG_DYLD_TIMING_DLADDR: enqueueEvent<dladdr>(event, true); break;
 143                 case DBG_DYLD_TIMING_DLCLOSE: enqueueEvent<dlclose>(event, true); break;
 144                 case DBG_DYLD_TIMING_FUNC_FOR_ADD_IMAGE: enqueueEvent<add_image_callback>(event, false); break;
 145                 case DBG_DYLD_TIMING_FUNC_FOR_REMOVE_IMAGE: enqueueEvent<remove_image_callback>(event, false); break;
 146                 case DBG_DYLD_TIMING_OBJC_INIT: enqueueEvent<objc_image_init>(event, false); break;
 147                 case DBG_DYLD_TIMING_OBJC_MAP: enqueueEvent<objc_images_map>(event, false); break;
 148             }
 149         } else {
 150             switch(code) {
 151                 case DBG_DYLD_TIMING_DLOPEN: dequeueEvent<dlopen>(event, [&](dlopen* endEvent){
 152                     endEvent->result = event->arg2;
 153                 }); break;
 154                 case DBG_DYLD_TIMING_DLOPEN_PREFLIGHT: dequeueEvent<dlopen_preflight>(event, [&](dlopen_preflight* endEvent){
 155                     endEvent->result = event->arg2;
 156                 }); break;
 157                 case DBG_DYLD_TIMING_LAUNCH_EXECUTABLE: dequeueEvent<app_launch>(event, [&](app_launch* endEvent){
 158                     endEvent->launchMode = event->arg4;
 159                 }); break;
 160                 case DBG_DYLD_TIMING_DLSYM: dequeueEvent<dlsym>(event, [&](dlsym* endEvent){
 161                     endEvent->result = event->arg2;
 162                 }); break;
 163                 case DBG_DYLD_TIMING_STATIC_INITIALIZER: dequeueEvent<static_init>(event, [&](static_init* endEvent){}); break;
 164                 case DBG_DYLD_TIMING_MAP_IMAGE: dequeueEvent<map_image>(event, [&](map_image* endEvent){
 165                     endEvent->result = event->arg2;
 166                 }); break;
 167                 case DBG_DYLD_TIMING_APPLY_FIXUPS: dequeueEvent<apply_fixups>(event, [&](apply_fixups* endEvent){}); break;
 168                 case DBG_DYLD_TIMING_ATTACH_CODESIGNATURE: dequeueEvent<attach_signature>(event, [&](attach_signature* endEvent){}); break;
 169                 case DBG_DYLD_TIMING_BUILD_CLOSURE: dequeueEvent<build_closure>(event, [&](build_closure* endEvent){
 170                     endEvent->closureBuildState = event->arg2;
 171                 }); break;
 172                 case DBG_DYLD_TIMING_DLCLOSE: dequeueEvent<dlclose>(event, [&](dlclose* endEvent){
 173                     endEvent->result = (int)event->arg2;
 174                 }); break;
 175                 case DBG_DYLD_TIMING_DLADDR: dequeueEvent<dladdr>(event, [&](dladdr* endEvent){
 176                     endEvent->result = (int)event->arg2;
 177                     endEvent->imageAddress = (int)event->arg3;
 178                     endEvent->symbolAddress = (int)event->arg4;
 179                 }); break;
 180                 case DBG_DYLD_TIMING_FUNC_FOR_ADD_IMAGE: dequeueEvent<add_image_callback>(event, [&](add_image_callback* endEvent){}); break;
 181                 case DBG_DYLD_TIMING_FUNC_FOR_REMOVE_IMAGE: dequeueEvent<remove_image_callback>(event, [&](remove_image_callback* endEvent){}); break;
 182                 case DBG_DYLD_TIMING_OBJC_INIT: dequeueEvent<objc_image_init>(event, [&](objc_image_init* endEvent){}); break;
 183                 case DBG_DYLD_TIMING_OBJC_MAP: dequeueEvent<objc_images_map>(event, [&](objc_images_map* endEvent){}); break;
 184             }
 185         }
 186     }
 187
 188     bool empty() { return !_currentRootEvent && _eventStack.empty() && _rootEvents.empty(); }
 189 private:
 190     template<typename T>
 191     void enqueueEvent(ktrace_event_t event, bool rootEvent) {
 192         auto sharedEvent = std::make_shared<T>(event);
 193         if (!_currentRootEvent) {
 194             if (!rootEvent) return;
 195             assert(_eventStack.empty());
 196             _currentRootEvent = sharedEvent;
 197         } else {
 198             sharedEvent->setDepth(_eventStack.size());
 199             _eventStack.back()->addChild(sharedEvent);
 200         }
 201         _eventStack.push_back(sharedEvent);
 202     }
 203
 204     template<typename T>
 205     void dequeueEvent(ktrace_event_t event, std::function<void(T*)> lambda) {
 206         if (_eventStack.empty()) return;
 207         auto currentEvent = dynamic_cast<T*>(_eventStack.back().get());
 208         currentEvent->setEndEvent(event);
 209         lambda(currentEvent);
 210         _eventStack.pop_back();
 211         if (_currentRootEvent && _eventStack.empty()) {
 212             output(_currentRootEvent);
 213             _currentRootEvent = nullptr;
 214         }
 215     }
 216
 217     struct event_pair {
 218         event_pair(ktrace_event_t E) : _startTime(E->timestamp), _walltime(E->walltime), _threadid((unsigned long)(E->threadid)), _depth(0),
 219                                        _eventCode(KDBG_EXTRACT_CODE(E->debugid)) {};
 220         virtual ~event_pair(){}
 221         std::vector<std::shared_ptr<event_pair>>& children() { return _children; }
 222         void setDepth(uint64_t D) { _depth = D; }
 223         uint64_t depth() { return _depth; }
 224         struct timeval walltime() { return _walltime; };
 225         uint64_t startTimestamp() { return _startTime; };
 226         uint64_t endTimestamp() { return _endTime; }
 227         unsigned long threadid() { return _threadid; }
 228         void addChild(std::shared_ptr<event_pair> child) {_children.push_back(child);}
 229         void setEndEvent(ktrace_event_t E) { _endTime = E->timestamp; }
 230         uint16_t eventCode() const { return _eventCode; }
 231     private:
 232         std::vector<std::shared_ptr<event_pair>> _children;
 233         uint64_t _startTime;
 234         uint64_t _endTime;
 235         uint64_t _depth;
 236         unsigned long _threadid;
 237         uint16_t _eventCode;
 238         struct timeval _walltime;
 239     };
 240
 241     time_t _lastTimeWallSeconds = -1;
 242     std::string _timestampStr;
 243     std::string _commandName;
 244     pid_t _pid;
 245     unsigned long _threadid;
 246
 247     std::string timestamp(std::shared_ptr<event_pair> event, bool extended) {
 248         std::ostringstream result;
 249         struct timeval now_walltime = event->walltime();
 250         assert(now_walltime.tv_sec || now_walltime.tv_usec);
 251
 252         /* try and reuse the timestamp string */
 253         if (_lastTimeWallSeconds != now_walltime.tv_sec) {
 254             char timestamp[32];
 255             (void)strftime(timestamp, sizeof (timestamp), "%H:%M:%S", localtime(&now_walltime.tv_sec));
 256             _lastTimeWallSeconds = now_walltime.tv_sec;
 257             _timestampStr = timestamp;
 258         }
 259         result << _timestampStr;
 260
 261         if (extended) {
 262             result << "." << std::setw(6) << std::setfill('0') << std::to_string(now_walltime.tv_usec);
 263         }
 264         return result.str();
 265     }
 266
 267     std::string process(std::shared_ptr<event_pair> event, bool extended) {
 268         if (extended) {
 269             std::ostringstream result;
 270             result << _commandName << "." << std::to_string(event->threadid());
 271             return result.str();
 272         } else {
 273             std::string result = _commandName;
 274             result.resize(12, ' ');
 275             return result;
 276         }
 277     }
 278
 279     std::string duration(std::shared_ptr<event_pair> event) {
 280         std::ostringstream result;
 281         uint64_t usecs = (mach_to_nano(event->endTimestamp() - event->startTimestamp()) + (NSEC_PER_USEC - 1)) / NSEC_PER_USEC;
 282         uint64_t secs = usecs / USEC_PER_SEC;
 283         usecs -= secs * USEC_PER_SEC;
 284         result << secs << "." << std::setw(6) << std::setfill('0') << usecs;
 285         return result.str();
 286     }
 287
 288 public:
 289     void outputConsole(std::shared_ptr<event_pair> node, uint64_t width, std::ostringstream& sstr, uint64_t depth) {
 290         std::ostringstream line;
 291         bool extended = false;
 292         if (auto dlopenNode = dynamic_cast<dlopen *>(node.get())) {
 293             line << "dlopen(\"" << dlopenNode->path << "\", " << dlopenNode->flagString() << ") -> 0x" << dlopenNode->result;
 294         } else if (auto dlopenPreflightNode = dynamic_cast<dlopen_preflight *>(node.get())) {
 295             line << "dlopen_preflight(\"" << dlopenPreflightNode->path << ") -> 0x" << dlopenPreflightNode->result;
 296         } else if (auto dlsymNode = dynamic_cast<dlsym *>(node.get())) {
 297             line << "dlsym(0x" << std::hex << dlsymNode->handle << ", \"" << dlsymNode->symbol << "\") -> " << dlsymNode->result;
 298         } else if (auto mapImageNode = dynamic_cast<map_image *>(node.get())) {
 299             line << "map file \"" << mapImageNode->path << "\" -> 0x" << std::hex << mapImageNode->result;
 300         } else if (auto sigNode = dynamic_cast<attach_signature *>(node.get())) {
 301             line << "attach codesignature";
 302         } else if (auto buildClosureNode = dynamic_cast<build_closure *>(node.get())) {
 303             line << "build closure -> " << buildClosureNode->buildStateString();
 304         } else if (auto launchNode = dynamic_cast<app_launch *>(node.get())) {
 305             line << "app launch (dyld" << std::dec << launchNode->launchMode << ") -> 0x" << std::hex << launchNode->address;
 306         } else if (auto initNode  = dynamic_cast<static_init *>(node.get())) {
 307             line << "run static initializer 0x" << std::hex << initNode->funcAddress;
 308         } else if (auto initNode  = dynamic_cast<apply_fixups *>(node.get())) {
 309             line << "apply fixups";
 310         } else if (auto dlcloseNode  = dynamic_cast<dlclose *>(node.get())) {
 311             line << "dlclose(0x" << std::hex << dlcloseNode->handle << ") -> " << dlcloseNode->result;
 312         } else if (auto dladdrNode  = dynamic_cast<dladdr *>(node.get())) {
 313             line << "dladdr(0x" << dladdrNode->address << ") -> image: 0x" << std::hex << dladdrNode->imageAddress;
 314             line << ", symbol: 0x" << dladdrNode->symbolAddress;
 315         } else if (auto addImageNode  = dynamic_cast<add_image_callback *>(node.get())) {
 316             line << std::hex << "add image callback(0x" << addImageNode->funcAddress << ") for image 0x" << addImageNode->libraryAddress;
 317         } else if (auto removeImageNode  = dynamic_cast<remove_image_callback *>(node.get())) {
 318             line << std::hex << "remove image callback(0x" << removeImageNode->funcAddress << ") for image 0x" << removeImageNode->libraryAddress;
 319         } else if (auto objcInitNode  = dynamic_cast<objc_image_init *>(node.get())) {
 320             line << std::hex << "objC init image(0x" << objcInitNode->libraryAddress << ")";
 321         } else if (auto objcMapNode  = dynamic_cast<objc_images_map *>(node.get())) {
 322             line << std::hex << "objC map images callback";
 323         }
 324
 325         if (width > MAXCOLS) {
 326             extended = true;
 327         }
 328
 329         std::string timestampStr = timestamp(node, extended);
 330         std::string lineStr = line.str();
 331         std::string commandStr = process(node, extended);
 332         std::string durationStr = duration(node);
 333         size_t lineMax = (size_t)width - (timestampStr.length() + commandStr.length() + durationStr.length() + 2*(size_t)depth + 3);
 334         lineStr.resize(lineMax, ' ');
 335
 336         sstr << timestampStr << " ";
 337         std::fill_n(std::ostream_iterator<char>(sstr), 2*depth, ' ');
 338         sstr << lineStr << " " << durationStr << " " << commandStr << std::endl;
 339
 340         for (const auto& child : node->children()) {
 341             outputConsole(child, width, sstr, depth+1);
 342         }
 343     }
 344
 345     void outputJSON(std::shared_ptr<event_pair> node, std::ostringstream& sstr) {
 346         if (auto dlopenNode = dynamic_cast<dlopen *>(node.get())) {
 347             sstr << std::hex;
 348             sstr << "{\"type\":\"dlopen\",\"path\":\"" << dlopenNode->path << "\",\"flags\":\"0x" << dlopenNode->flags << "\"";
 349             sstr << ",\"result\":\"" << dlopenNode->result << "\"";
 350         } else if (auto dlopenPreflightNode = dynamic_cast<dlopen_preflight *>(node.get())) {
 351             sstr << std::hex;
 352             sstr << "{\"type\":\"dlopen_preflight\",\"path\":\"" << dlopenPreflightNode->path << "\"";
 353             sstr << ",\"result\":\"" << dlopenPreflightNode->result << "\"";
 354         } else if (auto dlsymNode = dynamic_cast<dlsym *>(node.get())) {
 355             sstr << std::hex  << "{\"type\":\"dlsym\",\"symbol\":\"" << dlsymNode->symbol << "\",\"handle\":\"0x";
 356             sstr << dlsymNode->handle << "\",\"result\":\"0x" << dlsymNode->result << "\"";
 357         } else if (auto mapImageNode = dynamic_cast<map_image *>(node.get())) {
 358             sstr << std::hex;
 359             sstr << "{\"type\":\"map_image\",\"path\":\"" << mapImageNode->path << "\",\"result\":\"0x" << mapImageNode->result << "\"";
 360         } else if (auto sigNode = dynamic_cast<attach_signature *>(node.get())) {
 361             sstr << "{\"type\":\"attach_codesignature\"";
 362         } else if (auto buildClosureNode = dynamic_cast<build_closure *>(node.get())) {
 363             sstr << "{\"type\":\"build_closure\", \"state\":\"" << buildClosureNode->buildStateString() << "\"";
 364         } else if (auto launchNode = dynamic_cast<app_launch *>(node.get())) {
 365             sstr << std::hex;
 366             sstr << "{\"type\":\"app_launch\",\"address\":\"0x";
 367             sstr << launchNode->address << "\",\"mode\":" << launchNode->launchMode << "";
 368         } else if (auto initNode  = dynamic_cast<static_init *>(node.get())) {
 369             sstr << std::hex;
 370             sstr << "{\"type\":\"static_init\",\"image_address\":\"0x"  << initNode->libraryAddress;
 371             sstr << "\",\"function_address\":\"0x" << initNode->funcAddress << "\"";
 372         } else if (auto initNode  = dynamic_cast<apply_fixups *>(node.get())) {
 373             sstr << "{\"type\":\"apply_fixups\"";
 374         } else if (auto dlcloseNode  = dynamic_cast<dlclose *>(node.get())) {
 375             sstr << std::hex << "{\"type\":\"dlclose\",\"handle\":\"0x";
 376             sstr << dlcloseNode->handle << "\",\"result\":\"0x" << dlcloseNode->result << "\"";
 377         } else if (auto dladdrNode  = dynamic_cast<dladdr *>(node.get())) {
 378             sstr << std::hex << "{\"type\":\"dladdr\",\"address\":\"0x" << dladdrNode->address << "\",\"result\":\"0x";
 379             sstr << dladdrNode->result << "\",\"symbol_address\":\"0x" << dladdrNode->symbolAddress;
 380             sstr << "\",\"image_address\":\"0x" << dladdrNode->imageAddress << "\"";
 381         } else {
 382             sstr << "{\"type\":\"unknown\"";
 383         }
 384
 385         if (!node->children().empty()) {
 386             bool firstChild = true;
 387             sstr << ",\"children\":[";
 388             for (const auto& child : node->children()) {
 389                 if (!firstChild) {
 390                     sstr << ",";
 391                 }
 392                 firstChild = false;
 393                 outputJSON(child, sstr);
 394             }
 395             sstr << "]";
 396         }
 397         sstr << std::dec << ",\"start_nano\":\"" << mach_to_nano(node->startTimestamp());
 398         sstr << "\",\"end_nano\":\"" << mach_to_nano(node->endTimestamp()) << "\"}";
 399     }
 400
 401     void outputTracingJSON(std::shared_ptr<event_pair> node, std::ostringstream& sstr) {
 402         auto emitEventInfo = [&](bool isStart) {
 403             if (auto dlopenNode = dynamic_cast<dlopen *>(node.get())) {
 404                 sstr << "{\"name\": \"dlopen(" << dlopenNode->path << ")\", \"cat\": \"" << "dlopen" << "\"";
 405             } else if (auto dlopenPreflightNode = dynamic_cast<dlopen_preflight *>(node.get())) {
 406                 sstr << "{\"name\": \"dlopen_preflight(" << dlopenPreflightNode->path << ")\", \"cat\": \"" << "dlopen_preflight" << "\"";
 407             } else if (auto dlsymNode = dynamic_cast<dlsym *>(node.get())) {
 408                 sstr << "{\"name\": \"dlsym(" << dlsymNode->symbol << ")\", \"cat\": \"" << "dlsym" << "\"";
 409             } else if (auto mapImageNode = dynamic_cast<map_image *>(node.get())) {
 410                 sstr << "{\"name\": \"map_image(" << mapImageNode->path << ")\", \"cat\": \"" << "map_image" << "\"";
 411             } else if (auto sigNode = dynamic_cast<attach_signature *>(node.get())) {
 412                 sstr << "{\"name\": \"" << "attach_codesignature" << "\", \"cat\": \"" << "attach_codesignature" << "\"";
 413             } else if (auto buildClosureNode = dynamic_cast<build_closure *>(node.get())) {
 414                 sstr << "{\"name\": \"" << "build_closure" << "\", \"cat\": \"" << "build_closure" << "\"";
 415             } else if (auto launchNode = dynamic_cast<app_launch *>(node.get())) {
 416                 sstr << "{\"name\": \"" << "app_launch" << "\", \"cat\": \"" << "app_launch" << "\"";
 417             } else if (auto initNode  = dynamic_cast<static_init *>(node.get())) {
 418                 sstr << "{\"name\": \"" << "static_init" << "\", \"cat\": \"" << "static_init" << "\"";
 419             } else if (auto initNode  = dynamic_cast<apply_fixups *>(node.get())) {
 420                 sstr << "{\"name\": \"" << "apply_fixups" << "\", \"cat\": \"" << "apply_fixups" << "\"";
 421             } else if (auto dlcloseNode  = dynamic_cast<dlclose *>(node.get())) {
 422                 sstr << "{\"name\": \"" << "dlclose" << "\", \"cat\": \"" << "dlclose" << "\"";
 423             } else if (auto dladdrNode  = dynamic_cast<dladdr *>(node.get())) {
 424                 sstr << "{\"name\": \"" << "dladdr" << "\", \"cat\": \"" << "dladdr" << "\"";
 425             } else if (auto addImageNode  = dynamic_cast<add_image_callback *>(node.get())) {
 426                 sstr << "{\"name\": \"" << "add_image" << "\", \"cat\": \"" << "add_image" << "\"";
 427             } else if (auto removeImageNode  = dynamic_cast<remove_image_callback *>(node.get())) {
 428                 sstr << "{\"name\": \"" << "remove_image" << "\", \"cat\": \"" << "remove_image" << "\"";
 429             } else if (auto objcInitNode  = dynamic_cast<objc_image_init *>(node.get())) {
 430                 sstr << "{\"name\": \"" << "objc_init" << "\", \"cat\": \"" << "objc_init" << "\"";
 431             } else if (auto objcMapNode  = dynamic_cast<objc_images_map *>(node.get())) {
 432                 sstr << "{\"name\": \"" << "objc_map" << "\", \"cat\": \"" << "objc_map" << "\"";
 433             } else {
 434                 sstr << "{\"name\": \"" << "unknown" << "\", \"cat\": \"" << node->eventCode() << "\"";
 435             }
 436             if (isStart) {
 437                 sstr << ", \"ph\": \"B\", \"pid\": " << _pid << ", \"tid\": " << _threadid << ", \"ts\": " << mach_to_nano(node->startTimestamp()) << "},";
 438             } else {
 439                 sstr << ", \"ph\": \"E\", \"pid\": " << _pid << ", \"tid\": " << _threadid << ", \"ts\": " << mach_to_nano(node->endTimestamp()) << "}";
 440             }
 441         };
 442
 443         emitEventInfo(true);
 444         emitEventInfo(false);
 445
 446         if (!node->children().empty()) {
 447             for (const auto& child : node->children()) {
 448                 sstr << ", ";
 449                 outputTracingJSON(child, sstr);
 450             }
 451         }
 452     }
 453
 454     const std::vector<std::shared_ptr<event_pair>>& rootEvents() const { return _rootEvents; }
 455
 456 private:
 457
 458     void output(std::shared_ptr<event_pair> root) {
 459         std::ostringstream ostream;
 460         if (JSON_flag) {
 461             ostream << "{\"command\":\"" << _commandName << "\",\"pid\":\"" << _pid << "\",\"thread\":\"";
 462             ostream << _threadid << "\", \"event\":";
 463             outputJSON(root, ostream);
 464             ostream << "}" << std::endl;
 465         } else if (JSON_Tracing_flag) {
 466             _rootEvents.push_back(root);
 467         } else {
 468             outputConsole(root, columns, ostream, 0);
 469         }
 470         std::cout << ostream.str();
 471         if (!RAW_flag)
 472             fflush(stdout);
 473     }
 474
 475     struct dlopen : event_pair {
 476     dlopen(ktrace_event_t E) : event_pair(E), path(stringForID(E->arg2)), flags((int)E->arg3) {}
 477         std::string flagString() {
 478             std::vector<std::string> flagStrs;
 479             uint64_t flagCheck = 0;
 480             std::string flagString;
 481
 482             if (flags & RTLD_LAZY) {
 483                 flagStrs.push_back("RTLD_LAZY");
 484                 flagCheck |= RTLD_LAZY;
 485             }
 486             if (flags & RTLD_NOW) {
 487                 flagStrs.push_back("RTLD_NOW");
 488                 flagCheck |= RTLD_NOW;
 489             }
 490             if (flags & RTLD_LOCAL) {
 491                 flagStrs.push_back("RTLD_LOCAL");
 492                 flagCheck |= RTLD_LOCAL;
 493             }
 494             if (flags & RTLD_GLOBAL) {
 495                 flagStrs.push_back("RTLD_GLOBAL");
 496                 flagCheck |= RTLD_GLOBAL;
 497             }
 498             if (flags & RTLD_NOLOAD) {
 499                 flagStrs.push_back("RTLD_NOLOAD");
 500                 flagCheck |= RTLD_NOLOAD;
 501             }
 502             if (flags & RTLD_NODELETE) {
 503                 flagStrs.push_back("RTLD_NODELETE");
 504                 flagCheck |= RTLD_NODELETE;
 505             }
 506             if (flags & RTLD_FIRST) {
 507                 flagStrs.push_back("RTLD_FIRST");
 508                 flagCheck |= RTLD_FIRST;
 509             }
 510
 511             if (flagCheck == flags) {
 512                 for (auto& flagStr : flagStrs) {
 513                     if (!flagString.empty()) {
 514                         flagString += "|";
 515                     }
 516                     flagString += flagStr;
 517                 }
 518             }
 519
 520             return flagString;
 521         }
 522         std::string path;
 523         int flags;
 524         uint64_t result;
 525     };
 526
 527     struct dlopen_preflight : event_pair {
 528     dlopen_preflight(ktrace_event_t E) : event_pair(E), path(stringForID(E->arg2)) {}
 529         std::string path;
 530         uint64_t result;
 531     };
 532
 533     struct dlsym : event_pair {
 534         dlsym(ktrace_event_t E) : event_pair(E), handle(E->arg2), symbol(stringForID(E->arg3)) {}
 535         std::string symbol;
 536         uint64_t handle;
 537         uint64_t result;
 538     };
 539
 540     struct dladdr : event_pair {
 541         dladdr(ktrace_event_t E) : event_pair(E), address(E->arg2), imageAddress(0), symbolAddress(0)  {}
 542         uint64_t address;
 543         uint64_t imageAddress;
 544         uint64_t symbolAddress;
 545         int result;
 546     };
 547
 548     struct dlclose : event_pair {
 549         dlclose(ktrace_event_t E) : event_pair(E), handle(E->arg2) {}
 550         uint64_t handle;
 551         int result;
 552     };
 553
 554     struct app_launch : event_pair {
 555         app_launch(ktrace_event_t E) : event_pair(E), address(E->arg2) {}
 556         uint64_t address;
 557         uint64_t launchMode;
 558         std::vector<event_pair *> _children;
 559     };
 560
 561     struct static_init : event_pair {
 562         static_init(ktrace_event_t E) : event_pair(E), libraryAddress(E->arg2), funcAddress(E->arg3) {}
 563         uint64_t libraryAddress;
 564         uint64_t funcAddress;
 565     };
 566
 567     struct map_image : event_pair {
 568         map_image(ktrace_event_t E) : event_pair(E), path(stringForID(E->arg2)) {}
 569         std::string path;
 570         uint64_t result;
 571     };
 572
 573     struct apply_fixups : event_pair {
 574         apply_fixups(ktrace_event_t E) : event_pair(E) {}
 575     };
 576
 577     struct attach_signature : event_pair {
 578         attach_signature(ktrace_event_t E) : event_pair(E) {}
 579     };
 580
 581     struct build_closure : event_pair {
 582         build_closure(ktrace_event_t E) : event_pair(E), closureBuildState(0) {}
 583         uint64_t closureBuildState;
 584
 585         std::string buildStateString() const {
 586             switch ((dyld3::DyldTimingBuildClosure)closureBuildState) {
 587                 case dyld3::DyldTimingBuildClosure::ClosureBuildFailure:
 588                     return "failed to build closure";
 589                 case dyld3::DyldTimingBuildClosure::LaunchClosure_Built:
 590                     return "built launch closure";
 591                 case dyld3::DyldTimingBuildClosure::DlopenClosure_UsedSharedCacheDylib:
 592                     return "used shared cache dylib closure";
 593                 case dyld3::DyldTimingBuildClosure::DlopenClosure_UsedSharedCacheOther:
 594                     return "used shared cache dlopen closure";
 595                 case dyld3::DyldTimingBuildClosure::DlopenClosure_NoLoad:
 596                     return "dlopen was no load";
 597                 case dyld3::DyldTimingBuildClosure::DlopenClosure_Built:
 598                     return "built dlopen closure";
 599             }
 600         };
 601     };
 602
 603     struct add_image_callback : event_pair {
 604         add_image_callback(ktrace_event_t E) : event_pair(E), libraryAddress(E->arg2), funcAddress(E->arg3) {}
 605         uint64_t libraryAddress;
 606         uint64_t funcAddress;
 607     };
 608
 609     struct remove_image_callback : event_pair {
 610         remove_image_callback(ktrace_event_t E) : event_pair(E), libraryAddress(E->arg2), funcAddress(E->arg3) {}
 611         uint64_t libraryAddress;
 612         uint64_t funcAddress;
 613
 614     };
 615
 616     struct objc_image_init : event_pair {
 617         objc_image_init(ktrace_event_t E) : event_pair(E), libraryAddress(E->arg2) {}
 618         uint64_t libraryAddress;
 619     };
 620
 621     struct objc_images_map : event_pair {
 622         objc_images_map(ktrace_event_t E) : event_pair(E) {}
 623     };
 624
 625     std::shared_ptr<event_pair> _currentRootEvent;
 626     std::vector<std::shared_ptr<event_pair>> _eventStack;
 627     std::vector<std::shared_ptr<event_pair>> _rootEvents;
 628 };
 629
 630 struct OutputManager {
 631     std::map<unsigned long, std::unique_ptr<output_renderer>> sOutputRenders;
 632
 633     void flush() {
 634         if (JSON_Tracing_flag) {
 635             std::ostringstream ostream;
 636             ostream << "{\"displayTimeUnit\":\"ns\"";
 637             ostream << ", \"traceEvents\": [";
 638             bool firstEvent = true;
 639             for (const auto& renderer : sOutputRenders) {
 640                 for (const auto& root : renderer.second->rootEvents()) {
 641                     if (firstEvent)
 642                         firstEvent = false;
 643                     else
 644                         ostream << ", ";
 645                     renderer.second->outputTracingJSON(root, ostream);
 646                 }
 647             }
 648             ostream << "]";
 649             ostream << "}" << std::endl;
 650             std::cout << ostream.str();
 651             if (!RAW_flag)
 652                 fflush(stdout);
 653         }
 654     }
 655 };
 656
 657 static OutputManager sOutputManager;
 658
 659 void
 660 setup_ktrace_callbacks(void)
 661 {
 662     ktrace_events_single(s, TRACEDBG_CODE(DBG_TRACE_STRING, TRACE_STRING_GLOBAL), ^(ktrace_event_t event){
 663         char argChars[33] = {0};
 664         memset(&argChars[0], 0, 33);
 665         if ((event->debugid & DBG_FUNC_START) == DBG_FUNC_START) {
 666             uint64_t str_id = event->arg2;
 667             if (((event->debugid & DBG_FUNC_END) == DBG_FUNC_END)
 668                 && str_id != 0) {
 669                 auto i = gActiveStrings.find(str_id);
 670                 if (i != gActiveStrings.end()) {
 671                     gActiveStrings.erase(i);
 672                 }
 673             }
 674             *((uint64_t*)&argChars[0]) = event->arg3;
 675             *((uint64_t*)&argChars[8]) = event->arg4;
 676             gActiveStringIDs.insert(std::make_pair(event->threadid, str_id));
 677             gActiveStrings.insert(std::make_pair(str_id, argChars));
 678         } else {
 679             // Not a start, so lets grab our data
 680             *((uint64_t*)&argChars[0]) = event->arg1;
 681             *((uint64_t*)&argChars[8]) = event->arg2;
 682             *((uint64_t*)&argChars[16]) = event->arg3;
 683             *((uint64_t*)&argChars[24]) = event->arg4;
 684
 685             auto i = gActiveStringIDs.find(event->threadid);
 686             if (i != gActiveStringIDs.end()) {
 687                 auto j = gActiveStrings.find(i->second);
 688                 if (j != gActiveStrings.end()) {
 689                     j->second += argChars;
 690                 }
 691             }
 692         }
 693
 694         if ((event->debugid & DBG_FUNC_END) == DBG_FUNC_END) {
 695             auto i = gActiveStringIDs.find(event->threadid);
 696             if (i != gActiveStringIDs.end()) {
 697                 gActiveStringIDs.erase(i);
 698             }
 699         };
 700     });
 701
 702     // Event though our events are paired, we process them individually so we can
 703     // render nested events
 704     ktrace_events_range(s, KDBG_EVENTID(DBG_DYLD, DBG_DYLD_INTERNAL_SUBCLASS, 0), KDBG_EVENTID(DBG_DYLD, DBG_DYLD_API_SUBCLASS+1, 0), ^(ktrace_event_t event){
 705         if ((event->debugid & KDBG_FUNC_MASK) == 0)
 706             return;
 707         auto i = sOutputManager.sOutputRenders.find((size_t)(event->threadid));
 708         if (i == sOutputManager.sOutputRenders.end()) {
 709             sOutputManager.sOutputRenders.emplace(std::make_pair(event->threadid, std::make_unique<output_renderer>(s, event)));
 710             i = sOutputManager.sOutputRenders.find((size_t)(event->threadid));
 711         }
 712         i->second->recordEvent(event);
 713         if (i->second->empty()) {
 714             sOutputManager.sOutputRenders.erase(i);
 715         }
 716     });
 717 }
 718
 719 int
 720 main(int argc, char *argv[])
 721 {
 722     char ch;
 723     int rv = 0;
 724     bool exclude_pids = false;
 725     uint64_t time_limit_ns = 0;
 726
 727     get_screenwidth();
 728
 729     s = ktrace_session_create();
 730     assert(s);
 731
 732     while ((ch = getopt(argc, argv, "jJeR:t:")) != -1) {
 733         switch (ch) {
 734             case 'j':
 735                 JSON_flag = true;
 736                 break;
 737             case 'J':
 738                 JSON_Tracing_flag = true;
 739                 break;
 740             case 'e':
 741                 exclude_pids = true;
 742                 break;
 743             case 't':
 744                 time_limit_ns = (uint64_t)(NSEC_PER_SEC * atof(optarg));
 745                 if (time_limit_ns == 0) {
 746                     fprintf(stderr, "ERROR: could not set time limit to %s\n",
 747                             optarg);
 748                     exit(1);
 749                 }
 750                 break;
 751             case 'R':
 752                 RAW_flag = true;
 753                 rv = ktrace_set_file(s, optarg);
 754                 if (rv) {
 755                     fprintf(stderr, "ERROR: reading trace from '%s' failed (%s)\n", optarg, strerror(errno));
 756                     exit(1);
 757                 }
 758                 break;
 759             default:
 760                 exit_usage();
 761         }
 762     }
 763
 764     argc -= optind;
 765     argv += optind;
 766
 767     if (time_limit_ns > 0) {
 768         if (RAW_flag) {
 769             fprintf(stderr, "NOTE: time limit ignored when a raw file is specified\n");
 770         } else {
 771             dispatch_after(dispatch_time(DISPATCH_TIME_NOW, time_limit_ns),
 772                            dispatch_get_global_queue(QOS_CLASS_USER_INITIATED, 0),
 773                            ^{
 774                                ktrace_end(s, 0);
 775                            });
 776         }
 777     }
 778
 779     if (!RAW_flag) {
 780         if (geteuid() != 0) {
 781             fprintf(stderr, "'dyld_usage' must be run as root...\n");
 782             exit(1);
 783         }
 784
 785         /*
 786          * ktrace can't both *in*clude and *ex*clude pids, so: if we are
 787          * already excluding pids, or if we are not explicitly including
 788          * or excluding any pids, then exclude the defaults.
 789          *
 790          * if on the other hand we are explicitly including pids, we'll
 791          * filter the defaults out naturally.
 792          */
 793         if (exclude_pids || argc == 0) {
 794             ktrace_exclude_process(s, "dyld_usage");
 795             ktrace_exclude_process(s, "Terminal");
 796             ktrace_exclude_process(s, "telnetd");
 797             ktrace_exclude_process(s, "telnet");
 798             ktrace_exclude_process(s, "sshd");
 799             ktrace_exclude_process(s, "rlogind");
 800             ktrace_exclude_process(s, "tcsh");
 801             ktrace_exclude_process(s, "csh");
 802             ktrace_exclude_process(s, "sh");
 803             ktrace_exclude_process(s, "zsh");
 804 #if TARGET_OS_EMBEDDED
 805             ktrace_exclude_process(s, "dropbear");
 806 #endif /* TARGET_OS_EMBEDDED */
 807         }
 808     }
 809
 810     /*
 811      * Process the list of specified pids, and in/exclude them as
 812      * appropriate.
 813      */
 814     while (argc > 0) {
 815         pid_t pid;
 816         char *name;
 817         char *endptr;
 818
 819         name = argv[0];
 820         pid = (pid_t)strtoul(name, &endptr, 10);
 821
 822         if (*name != '\0' && *endptr == '\0') {
 823             if (exclude_pids) {
 824                 rv = ktrace_exclude_pid(s, pid);
 825             } else {
 826                 if (pid != 0)
 827                     rv = ktrace_filter_pid(s, pid);
 828             }
 829         } else {
 830             if (exclude_pids) {
 831                 rv = ktrace_exclude_process(s, name);
 832             } else {
 833                 if (strcmp(name, "kernel_task"))
 834                     rv = ktrace_filter_process(s, name);
 835             }
 836         }
 837
 838         if (rv == EINVAL) {
 839             fprintf(stderr, "ERROR: cannot both include and exclude simultaneously\n");
 840             exit(1);
 841         } else {
 842             assert(!rv);
 843         }
 844
 845         argc--;
 846         argv++;
 847     }
 848     /* provides SIGINT, SIGHUP, SIGPIPE, SIGTERM handlers */
 849     ktrace_set_signal_handler(s);
 850     ktrace_set_completion_handler(s, ^{
 851         sOutputManager.flush();
 852         exit(0);
 853     });
 854
 855     signal(SIGWINCH, SIG_IGN);
 856     sigwinch_source = dispatch_source_create(DISPATCH_SOURCE_TYPE_SIGNAL, SIGWINCH, 0, dispatch_get_main_queue());
 857     dispatch_source_set_event_handler(sigwinch_source, ^{
 858         get_screenwidth();
 859     });
 860     dispatch_activate(sigwinch_source);
 861
 862     setup_ktrace_callbacks();
 863
 864     ktrace_set_dropped_events_handler(s, ^{
 865         fprintf(stderr, "dyld_usage: buffer overrun, events generated too quickly\n");
 866
 867         /* clear any state that is now potentially invalid */
 868     });
 869
 870     ktrace_set_execnames_enabled(s, KTRACE_FEATURE_LAZY);
 871     ktrace_set_vnode_paths_enabled(s, false);
 872     /* no need to symbolicate addresses */
 873     ktrace_set_uuid_map_enabled(s, KTRACE_FEATURE_DISABLED);
 874
 875     rv = ktrace_start(s, dispatch_get_main_queue());
 876
 877     if (rv) {
 878         perror("ktrace_start");
 879         exit(1);
 880     }
 881
 882     dispatch_main();
 883
 884     return 0;
 885 }