tests/kernel_mtx_perf.c

   1 #ifdef T_NAMESPACE
   2 #undef T_NAMESPACE
   3 #endif
   4
   5 #include <darwintest.h>
   6 #include <darwintest_multiprocess.h>
   7 #include <darwintest_utils.h>
   8 #include <pthread.h>
   9 #include <launch.h>
  10 #include <servers/bootstrap.h>
  11 #include <stdlib.h>
  12 #include <sys/event.h>
  13 #include <unistd.h>
  14 #include <crt_externs.h>
  15 #include <sys/sysctl.h>
  16 #include <sys/types.h>
  17 #include <unistd.h>
  18 #include <spawn.h>
  19
  20 T_GLOBAL_META(T_META_NAMESPACE("xnu.kernel_mtx_perf_test"));
  21
  22 #define ITER 100000
  23 #define TEST_MTX_MAX_STATS              8
  24 #define FULL_CONTENDED 0
  25 #define HALF_CONTENDED 1
  26 #define MAX_CONDENDED  2
  27
  28
  29 #define TEST_MTX_LOCK_STATS             0
  30 #define TEST_MTX_UNLOCK_MTX_STATS       6
  31
  32 static void
  33 test_from_kernel_lock_unlock_contended(void)
  34 {
  35         int i, ret;
  36         unsigned long name_size;
  37         uint64_t avg, run, tot;
  38         size_t size;
  39         char iter[35];
  40         char *buff, *buff_p, *avg_p, *name, *end_name;
  41
  42         T_LOG("Testing locking/unlocking mutex from kernel with contention.\n");
  43         T_LOG("Requesting test with %d iterations\n", ITER);
  44
  45         size = 2000;
  46         buff = calloc(size, sizeof(char));
  47         T_QUIET; T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
  48
  49         snprintf(iter, sizeof(iter), "%d", ITER);
  50         ret = sysctlbyname("kern.test_mtx_contended", buff, &size, iter, sizeof(iter));
  51         T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_contended");
  52
  53         T_LOG("\n%s stats :\n%s\n", __func__, buff);
  54
  55         buff_p = buff;
  56         int t;
  57         for (t = 0; t < MAX_CONDENDED; t++) {
  58                 char *type;
  59                 if (t == FULL_CONTENDED) {
  60                         type = "FULL_CONTENDED ";
  61                 } else {
  62                         type = "HALF_CONTENDED ";
  63                 }
  64
  65                 /* first line is "STATS INNER LOOP" */
  66                 while (*buff_p != '\n') {
  67                         buff_p++;
  68                 }
  69                 buff_p++;
  70
  71                 /*
  72                  * Sequence of statistic lines like
  73                  * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
  74                  * for all TEST_MTX_MAX_STATS statistics
  75                  */
  76                 for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
  77                         avg_p = strstr(buff_p, "avg ");
  78
  79                         /* contended test records statistics only for lock/unlock for now */
  80                         if (i == TEST_MTX_LOCK_STATS || i == TEST_MTX_UNLOCK_MTX_STATS) {
  81                                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "contended %i average not found", i);
  82                                 sscanf(avg_p, "avg %llu", &avg);
  83
  84                                 name = strstr(buff_p, "TEST_MTX_");
  85                                 end_name = strstr(buff_p, "_STATS");
  86                                 name_size = (unsigned long) end_name - (unsigned long) name - strlen("TEST_MTX_") + 1;
  87
  88                                 char name_string[40];
  89                                 char avg_name_string[50];
  90                                 char *pre_string = "contended ";
  91                                 snprintf(name_string, name_size + strlen(pre_string) + strlen(type), "%s%s%s", pre_string, type, &name[strlen("TEST_MTX_")]);
  92                                 pre_string = "avg contended ";
  93                                 snprintf(avg_name_string, name_size + strlen(pre_string) + strlen(type), "%s%s%s", pre_string, type, &name[strlen("TEST_MTX_")]);
  94                                 T_PERF(name_string, avg, "ns", avg_name_string);
  95                         }
  96
  97                         buff_p = avg_p;
  98                         while (*buff_p != '\n') {
  99                                 buff_p++;
 100                         }
 101                         buff_p++;
 102                 }
 103
 104                 while (*buff_p != '\n') {
 105                         buff_p++;
 106                 }
 107                 buff_p++;
 108
 109                 /* next line is "STATS OUTER LOOP" */
 110                 while (*buff_p != '\n') {
 111                         buff_p++;
 112                 }
 113                 buff_p++;
 114
 115                 /* contended test records statistics only for lock/unlock for now */
 116                 avg_p = strstr(buff_p, "run time ");
 117                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "contended %d loop run time not found", 0);
 118                 sscanf(avg_p, "run time %llu", &run);
 119
 120                 avg_p = strstr(buff_p, "total time ");
 121                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", 0);
 122                 sscanf(avg_p, "total time %llu", &tot);
 123
 124                 if (run < tot) {
 125                         avg = run;
 126                 } else {
 127                         avg = tot;
 128                 }
 129
 130                 name = strstr(buff_p, "TEST_MTX_");
 131                 end_name = strstr(buff_p, "_STATS");
 132                 name_size = (unsigned long) end_name - (unsigned long) name - strlen("TEST_MTX_") + 1;
 133
 134                 char name_string[50];
 135                 char avg_name_string[60];
 136                 char *pre_string = "contended loop ";
 137                 snprintf(name_string, name_size + strlen(pre_string) + strlen(type), "%s%s%s", pre_string, type, &name[strlen("TEST_MTX_")]);
 138                 pre_string = "avg time contended loop ";
 139                 snprintf(avg_name_string, name_size + strlen(pre_string) + strlen(type), "%s%s%s", pre_string, type, &name[strlen("TEST_MTX_")]);
 140                 T_PERF(name_string, avg / ITER, "ns", avg_name_string);
 141         }
 142
 143         free(buff);
 144 }
 145
 146 static void
 147 test_from_kernel_lock_unlock_uncontended(void)
 148 {
 149         int i, ret;
 150         unsigned long name_size;
 151         uint64_t avg, run, tot;
 152         size_t size;
 153         char iter[35];
 154         char *buff, *buff_p, *avg_p, *name, *end_name;
 155
 156         T_LOG("Testing locking/unlocking mutex from kernel without contention.\n");
 157         T_LOG("Requesting test with %d iterations\n", ITER);
 158
 159         size = 2000;
 160         buff = calloc(size, sizeof(char));
 161         T_QUIET; T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
 162
 163         snprintf(iter, sizeof(iter), "%d", ITER);
 164         ret = sysctlbyname("kern.test_mtx_uncontended", buff, &size, iter, sizeof(iter));
 165         T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_uncontended");
 166
 167         T_LOG("%s stats:\n%s\n", __func__, buff);
 168
 169         /* first line is "STATS INNER LOOP" */
 170         buff_p = buff;
 171         while (*buff_p != '\n') {
 172                 buff_p++;
 173         }
 174         buff_p++;
 175
 176         /*
 177          * Sequence of statistic lines like
 178          * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
 179          * for all TEST_MTX_MAX_STATS statistics
 180          */
 181         for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
 182                 avg_p = strstr(buff_p, "avg ");
 183                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %i average not found", i);
 184                 sscanf(avg_p, "avg %llu", &avg);
 185
 186                 name = strstr(buff_p, "TEST_MTX_");
 187                 end_name = strstr(buff_p, "_STATS");
 188                 name_size = (unsigned long) end_name - (unsigned long) name - strlen("TEST_MTX_") + 1;
 189
 190                 char name_string[40];
 191                 char avg_name_string[50];
 192                 char *pre_string = "uncontended ";
 193                 snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 194                 pre_string = "avg time uncontended ";
 195                 snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 196                 T_PERF(name_string, avg, "ns", avg_name_string);
 197
 198                 buff_p = avg_p;
 199                 while (*buff_p != '\n') {
 200                         buff_p++;
 201                 }
 202                 buff_p++;
 203         }
 204
 205         while (*buff_p != '\n') {
 206                 buff_p++;
 207         }
 208         buff_p++;
 209
 210         /* next line is "STATS OUTER LOOP" */
 211         while (*buff_p != '\n') {
 212                 buff_p++;
 213         }
 214         buff_p++;
 215
 216         /*
 217          * Sequence of statistic lines like
 218          * total time 4040673 ns total run time 3981080 ns TEST_MTX_LOCK_STATS
 219          * for all TEST_MTX_MAX_STATS statistics exept UNLOCK
 220          */
 221         for (i = 0; i < TEST_MTX_MAX_STATS - 2; i++) {
 222                 avg_p = strstr(buff_p, "run time ");
 223                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop run time not found", i);
 224                 sscanf(avg_p, "run time %llu", &run);
 225
 226                 avg_p = strstr(buff_p, "total time ");
 227                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", i);
 228                 sscanf(avg_p, "total time %llu", &tot);
 229
 230                 if (run < tot) {
 231                         avg = run;
 232                 } else {
 233                         avg = tot;
 234                 }
 235
 236                 name = strstr(buff_p, "TEST_MTX_");
 237                 end_name = strstr(buff_p, "_STATS");
 238                 name_size = (unsigned long) end_name - (unsigned long) name - strlen("TEST_MTX_") + 1;
 239
 240                 char name_string[50];
 241                 char avg_name_string[60];
 242                 char *pre_string = "uncontended loop ";
 243                 snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 244                 pre_string = "avg time uncontended loop ";
 245                 snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 246                 T_PERF(name_string, avg / ITER, "ns", avg_name_string);
 247
 248                 buff_p = avg_p;
 249                 while (*buff_p != '\n') {
 250                         buff_p++;
 251                 }
 252                 buff_p++;
 253         }
 254         free(buff);
 255 }
 256
 257 #if !(TARGET_OS_IPHONE && !TARGET_OS_SIMULATOR)
 258 static bool
 259 get_freq(float val, char scale, int *int_val)
 260 {
 261         switch (scale) {
 262         case 'M':
 263         case 'm':
 264                 *int_val = (int) val;
 265                 break;
 266         case 'G':
 267         case 'g':
 268                 *int_val = (int) (val * 1000);
 269                 break;
 270         default:
 271                 return FALSE;
 272         }
 273         return TRUE;
 274 }
 275
 276 static bool
 277 parse_freq(char* buff, int buff_size, const char* string_start, int string_start_size, char* to_parse)
 278 {
 279         char* start;
 280         float val;
 281         char scale;
 282         int int_val;
 283
 284         start = strstr(to_parse, string_start);
 285         if (start == NULL) {
 286                 return FALSE;
 287         }
 288
 289         if (strstr(start, "Hz") != NULL) {
 290                 sscanf(start + string_start_size, "%f%cHz", &val, &scale);
 291         } else {
 292                 if (strstr(start, "hz") != NULL) {
 293                         sscanf(start + string_start_size, "%f%chz", &val, &scale);
 294                 } else {
 295                         return FALSE;
 296                 }
 297         }
 298
 299         if (!get_freq(val, scale, &int_val)) {
 300                 return FALSE;
 301         }
 302
 303         snprintf(buff, buff_size, "%d", int_val);
 304
 305         return TRUE;
 306 }
 307
 308 static bool freq_fixed = FALSE;
 309 static char str_val_min[10];
 310 static char str_val_max[10];
 311
 312 static bool
 313 get_previous_freq_values(void)
 314 {
 315         FILE *fp;
 316         char out_xcpm[1035];
 317         bool min_scan = FALSE;
 318         bool max_scan = FALSE;
 319
 320         memset(str_val_min, 0, sizeof(str_val_min));
 321         memset(str_val_max, 0, sizeof(str_val_max));
 322
 323         fp = popen("/usr/local/bin/xcpm limits", "r");
 324         if (fp == NULL) {
 325                 return FALSE;
 326         }
 327
 328         while (fgets(out_xcpm, sizeof(out_xcpm) - 1, fp) != NULL && (!max_scan || !min_scan)) {
 329                 if (!max_scan) {
 330                         max_scan = parse_freq(str_val_max, sizeof(str_val_max), "Max frequency:", sizeof("Max frequency:"), out_xcpm);
 331                 }
 332                 if (!min_scan) {
 333                         min_scan = parse_freq(str_val_min, sizeof(str_val_min), "Min frequency:", sizeof("Min frequency:"), out_xcpm);
 334                 }
 335         }
 336
 337         pclose(fp);
 338
 339         if (!max_scan || !min_scan) {
 340                 return FALSE;
 341         }
 342
 343         return TRUE;
 344 }
 345 #endif
 346
 347 static void
 348 fix_cpu_frequency(void)
 349 {
 350 #if (TARGET_OS_IPHONE && !TARGET_OS_SIMULATOR)
 351         int spawn_ret, pid;
 352         char *const clpcctrl_args[] = {"/usr/local/bin/clpcctrl", "-f", "5000", NULL};
 353
 354         T_LOG("Setting cpu frequency to %d\n", 5000);
 355
 356         spawn_ret = posix_spawn(&pid, clpcctrl_args[0], NULL, NULL, clpcctrl_args, *_NSGetEnviron());
 357         T_QUIET; T_ASSERT_POSIX_ZERO(spawn_ret, "posix_spawn");
 358         T_QUIET; T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, "waitpid failed");
 359         T_QUIET; T_ASSERT_EQ(spawn_ret, 0, " clpcctrl failed");
 360
 361 #else /*(TARGET_OS_IPHONE && !TARGET_OS_SIMULATOR)*/
 362
 363         int spawn_ret, pid;
 364         int ret;
 365         size_t len;
 366         char *buffer;
 367         char str_val[10];
 368
 369         if (!get_previous_freq_values()) {
 370                 T_LOG("Impossible to parse freq values from xcpm");
 371                 freq_fixed = FALSE;
 372                 return;
 373         }
 374
 375         ret = sysctlbyname("machdep.cpu.brand_string", NULL, &len, NULL, 0);
 376         T_QUIET; T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
 377
 378         buffer = calloc(len + 2, sizeof(char));
 379         ret = sysctlbyname("machdep.cpu.brand_string", buffer, &len, NULL, 0);
 380         T_QUIET; T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
 381         buffer[len + 1] = '\0';
 382
 383         memset(str_val, 0, sizeof(str_val));
 384         if (!parse_freq(str_val, sizeof(str_val), "CPU @", sizeof("CPU @"), buffer)) {
 385                 T_LOG("Impossible to parse freq values from machdep.cpu.brand_string (string was %s)", buffer);
 386                 freq_fixed = FALSE;
 387                 return;
 388         }
 389
 390         T_LOG("Previous min and max cpu frequency (%s) (%s)\n", str_val_min, str_val_max);
 391         T_LOG("Setting min and max cpu frequency to (%s)\n", str_val);
 392         char *xcpm_args[] = {"/usr/local/bin/xcpm", "limits", str_val, str_val, NULL};
 393         spawn_ret = posix_spawn(&pid, xcpm_args[0], NULL, NULL, xcpm_args, *_NSGetEnviron());
 394         T_QUIET; T_ASSERT_POSIX_ZERO(spawn_ret, "posix_spawn");
 395         T_QUIET; T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, "waitpid failed");
 396         T_QUIET; T_ASSERT_EQ(spawn_ret, 0, "xcpm limits failed");
 397
 398         freq_fixed = TRUE;
 399
 400         free(buffer);
 401         return;
 402 #endif /*(TARGET_OS_IPHONE && !TARGET_OS_SIMULATOR)*/
 403 }
 404
 405 static void
 406 cleanup_cpu_freq(void)
 407 {
 408 #if (TARGET_OS_IPHONE && !TARGET_OS_SIMULATOR)
 409         int spawn_ret, pid;
 410         char *const clpcctrl_args[] = {"/usr/local/bin/clpcctrl", "-d", NULL};
 411         spawn_ret = posix_spawn(&pid, clpcctrl_args[0], NULL, NULL, clpcctrl_args, *_NSGetEnviron());
 412         T_QUIET; T_ASSERT_POSIX_ZERO(spawn_ret, "posix_spawn");
 413         T_QUIET; T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, "waitpid failed");
 414         T_QUIET; T_ASSERT_EQ(spawn_ret, 0, "clpcctrl failed");
 415
 416 #else
 417         if (freq_fixed) {
 418                 int spawn_ret, pid;
 419                 char *xcpm_args[] = {"/usr/local/bin/xcpm", "limits", str_val_min, str_val_max, NULL};
 420                 spawn_ret = posix_spawn(&pid, xcpm_args[0], NULL, NULL, xcpm_args, *_NSGetEnviron());
 421                 T_QUIET; T_ASSERT_POSIX_ZERO(spawn_ret, "posix_spawn");
 422                 T_QUIET; T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, "waitpid failed");
 423                 T_QUIET; T_ASSERT_EQ(spawn_ret, 0, "xcpm limits failed");
 424         }
 425 #endif
 426 }
 427
 428 T_DECL(kernel_mtx_perf_test,
 429     "Kernel mutex performance test",
 430     T_META_ASROOT(YES), T_META_CHECK_LEAKS(NO))
 431 {
 432         fix_cpu_frequency();
 433
 434         T_ATEND(cleanup_cpu_freq);
 435
 436         test_from_kernel_lock_unlock_uncontended();
 437         test_from_kernel_lock_unlock_contended();
 438 }