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