tests/telemetry.c

   1 /* Copyright (c) 2018 Apple Inc.  All rights reserved. */
   2
   3 #include <CoreFoundation/CoreFoundation.h>
   4 #include <darwintest.h>
   5 #include <dispatch/dispatch.h>
   6 #include <ktrace/ktrace.h>
   7 #include <kperf/kperf.h>
   8 #include <kern/debug.h>
   9 #include <notify.h>
  10 #include <sys/kdebug.h>
  11 #include <sys/sysctl.h>
  12 #include <TargetConditionals.h>
  13
  14 #include "ktrace_helpers.h"
  15
  16 enum telemetry_pmi {
  17         TELEMETRY_PMI_NONE,
  18         TELEMETRY_PMI_INSTRS,
  19         TELEMETRY_PMI_CYCLES,
  20 };
  21 #define TELEMETRY_CMD_PMI_SETUP 3
  22
  23 T_GLOBAL_META(T_META_NAMESPACE("xnu.debugging.telemetry"),
  24     T_META_CHECK_LEAKS(false),
  25     T_META_ASROOT(true));
  26
  27 extern int __telemetry(uint64_t cmd, uint64_t deadline, uint64_t interval,
  28     uint64_t leeway, uint64_t arg4, uint64_t arg5);
  29
  30 /*
  31  * Microstackshots based on PMI are only supported on devices with monotonic
  32  * support.
  33  */
  34
  35 static void
  36 skip_if_pmi_unsupported(void)
  37 {
  38         int supported = 0;
  39         int ret = sysctlbyname("kern.monotonic.supported", &supported,
  40             &(size_t){ sizeof(supported), }, NULL, 0);
  41         if (ret < 0) {
  42                 T_SKIP("monotonic sysctl generated an error: %d (%s)", errno,
  43                     strerror(errno));
  44         }
  45         if (!supported) {
  46                 T_SKIP("monotonic must be supported for microstackshots");
  47         }
  48 }
  49
  50 /*
  51  * Data Analytics (da) also has a microstackshot configuration -- set a PMI
  52  * cycle interval of 0 to force it to disable microstackshot on PMI.
  53  */
  54
  55 static void
  56 set_da_microstackshot_period(CFNumberRef num)
  57 {
  58         CFPreferencesSetValue(CFSTR("microstackshotPMICycleInterval"), num,
  59             CFSTR("com.apple.da"),
  60 #if TARGET_OS_IPHONE
  61             CFSTR("mobile"),
  62 #else // TARGET_OS_IPHONE
  63             CFSTR("root"),
  64 #endif // !TARGET_OS_IPHONE
  65             kCFPreferencesCurrentHost);
  66
  67         notify_post("com.apple.da.tasking_changed");
  68 }
  69
  70 static void
  71 disable_da_microstackshots(void)
  72 {
  73         int64_t zero = 0;
  74         CFNumberRef num = CFNumberCreate(NULL, kCFNumberSInt64Type, &zero);
  75         set_da_microstackshot_period(num);
  76         T_LOG("notified da of tasking change, sleeping");
  77 #if TARGET_OS_WATCH
  78         sleep(8);
  79 #else /* TARGET_OS_WATCH */
  80         sleep(3);
  81 #endif /* !TARGET_OS_WATCH */
  82 }
  83
  84 /*
  85  * Unset the preference to allow da to reset its configuration.
  86  */
  87 static void
  88 reenable_da_microstackshots(void)
  89 {
  90         set_da_microstackshot_period(NULL);
  91 }
  92
  93 /*
  94  * Clean up the test's configuration and allow da to activate again.
  95  */
  96 static void
  97 telemetry_cleanup(void)
  98 {
  99         (void)__telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_NONE, 0, 0, 0, 0);
 100         reenable_da_microstackshots();
 101 }
 102
 103 /*
 104  * Make sure da hasn't configured the microstackshots -- otherwise the PMI
 105  * setup command will return EBUSY.
 106  */
 107 static void
 108 telemetry_init(void)
 109 {
 110         disable_da_microstackshots();
 111         T_LOG("installing cleanup handler");
 112         T_ATEND(telemetry_cleanup);
 113 }
 114
 115 volatile static bool spinning = true;
 116
 117 static void *
 118 thread_spin(__unused void *arg)
 119 {
 120         while (spinning) {
 121         }
 122         return NULL;
 123 }
 124
 125 #define MT_MICROSTACKSHOT KDBG_EVENTID(DBG_MONOTONIC, 2, 1)
 126 #define MS_RECORD MACHDBG_CODE(DBG_MACH_STACKSHOT, \
 127                 MICROSTACKSHOT_RECORD)
 128 #if defined(__arm64__) || defined(__arm__)
 129 #define INSTRS_PERIOD (100ULL * 1000 * 1000)
 130 #else /* defined(__arm64__) || defined(__arm__) */
 131 #define INSTRS_PERIOD (1ULL * 1000 * 1000 * 1000)
 132 #endif /* !defined(__arm64__) && !defined(__arm__) */
 133 #define SLEEP_SECS 10
 134
 135 T_DECL(microstackshot_pmi, "attempt to configure microstackshots on PMI")
 136 {
 137         skip_if_pmi_unsupported();
 138         start_controlling_ktrace();
 139
 140         T_SETUPBEGIN;
 141         ktrace_session_t s = ktrace_session_create();
 142         T_QUIET; T_WITH_ERRNO; T_ASSERT_NOTNULL(s, "session create");
 143
 144         __block int pmi_events = 0;
 145         __block int microstackshot_record_events = 0;
 146         __block int pmi_records = 0;
 147         __block int io_records = 0;
 148         __block int interrupt_records = 0;
 149         __block int timer_arm_records = 0;
 150         __block int unknown_records = 0;
 151         __block int empty_records = 0;
 152
 153         ktrace_events_single(s, MT_MICROSTACKSHOT, ^(__unused struct trace_point *tp) {
 154                 pmi_events++;
 155         });
 156         ktrace_events_single_paired(s, MS_RECORD,
 157             ^(struct trace_point *start, __unused struct trace_point *end) {
 158                 if (start->arg1 & kPMIRecord) {
 159                         pmi_records++;
 160                 }
 161                 if (start->arg1 & kIORecord) {
 162                         io_records++;
 163                 }
 164                 if (start->arg1 & kInterruptRecord) {
 165                         interrupt_records++;
 166                 }
 167                 if (start->arg1 & kTimerArmingRecord) {
 168                         timer_arm_records++;
 169                 }
 170
 171                 if (start->arg2 == end->arg2) {
 172                         /*
 173                          * The buffer didn't grow for this record -- there was
 174                          * an error.
 175                          */
 176                         empty_records++;
 177                 }
 178
 179                 const uint8_t any_record = kPMIRecord | kIORecord | kInterruptRecord |
 180                 kTimerArmingRecord;
 181                 if ((start->arg1 & any_record) == 0) {
 182                         unknown_records++;
 183                 }
 184
 185                 microstackshot_record_events++;
 186         });
 187
 188         ktrace_set_completion_handler(s, ^{
 189                 ktrace_session_destroy(s);
 190                 T_EXPECT_GT(pmi_events, 0,
 191                 "saw non-zero PMIs (%g/sec)", pmi_events / (double)SLEEP_SECS);
 192                 T_EXPECT_GT(pmi_records, 0, "saw non-zero PMI record events (%g/sec)",
 193                 pmi_records / (double)SLEEP_SECS);
 194                 T_EXPECT_EQ(unknown_records, 0, "saw zero unknown record events");
 195                 T_EXPECT_GT(microstackshot_record_events, 0,
 196                 "saw non-zero microstackshot record events (%d -- %g/sec)",
 197                 microstackshot_record_events,
 198                 microstackshot_record_events / (double)SLEEP_SECS);
 199                 T_EXPECT_NE(empty_records, microstackshot_record_events,
 200                 "saw non-empty records (%d empty)", empty_records);
 201
 202                 if (interrupt_records > 0) {
 203                         T_LOG("saw %g interrupt records per second",
 204                         interrupt_records / (double)SLEEP_SECS);
 205                 } else {
 206                         T_LOG("saw no interrupt records");
 207                 }
 208                 if (io_records > 0) {
 209                         T_LOG("saw %g I/O records per second",
 210                         io_records / (double)SLEEP_SECS);
 211                 } else {
 212                         T_LOG("saw no I/O records");
 213                 }
 214                 if (timer_arm_records > 0) {
 215                         T_LOG("saw %g timer arming records per second",
 216                         timer_arm_records / (double)SLEEP_SECS);
 217                 } else {
 218                         T_LOG("saw no timer arming records");
 219                 }
 220
 221                 T_END;
 222         });
 223
 224         T_SETUPEND;
 225
 226         telemetry_init();
 227
 228         /*
 229          * Start sampling via telemetry on the instructions PMI.
 230          */
 231         int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
 232             INSTRS_PERIOD, 0, 0, 0);
 233         T_ASSERT_POSIX_SUCCESS(ret,
 234             "telemetry syscall succeeded, started microstackshots");
 235
 236         pthread_t thread;
 237         int error = pthread_create(&thread, NULL, thread_spin, NULL);
 238         T_ASSERT_POSIX_ZERO(error, "started thread to spin");
 239
 240         error = ktrace_start(s, dispatch_get_main_queue());
 241         T_ASSERT_POSIX_ZERO(error, "started tracing");
 242
 243         dispatch_after(dispatch_time(DISPATCH_TIME_NOW, SLEEP_SECS * NSEC_PER_SEC),
 244             dispatch_get_main_queue(), ^{
 245                 spinning = false;
 246                 ktrace_end(s, 0);
 247                 (void)pthread_join(thread, NULL);
 248                 T_LOG("ending trace session after %d seconds", SLEEP_SECS);
 249         });
 250
 251         dispatch_main();
 252 }
 253
 254 T_DECL(error_handling,
 255     "ensure that error conditions for the telemetry syscall are observed")
 256 {
 257         skip_if_pmi_unsupported();
 258
 259         telemetry_init();
 260
 261         int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
 262             1, 0, 0, 0);
 263         T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every instruction");
 264
 265         ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
 266             1000 * 1000, 0, 0, 0);
 267         T_EXPECT_EQ(ret, -1,
 268             "telemetry shouldn't allow PMI every million instructions");
 269
 270         ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
 271             1, 0, 0, 0);
 272         T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every cycle");
 273
 274         ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
 275             1000 * 1000, 0, 0, 0);
 276         T_EXPECT_EQ(ret, -1,
 277             "telemetry shouldn't allow PMI every million cycles");
 278
 279         ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
 280             UINT64_MAX, 0, 0, 0);
 281         T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every UINT64_MAX cycles");
 282
 283         ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
 284             (1ULL << 55), 0, 0, 0);
 285         T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI with extremely long periods");
 286 }