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
  25 #define TEST_MTX_LOCK_STATS             0
  26 #define TEST_MTX_UNLOCK_MTX_STATS       6
  27
  28 static void
  29 test_from_kernel_lock_unlock_contended(void)
  30 {
  31         int i, ret, name_size;
  32         uint64_t avg, run, tot;
  33         size_t size;
  34         char iter[35];
  35         char *buff, *buff_p, *avg_p, *name, *end_name;
  36
  37         T_LOG("Testing locking/unlocking mutex from kernel with contention.\n");
  38         T_LOG("Requesting test with %d iterations\n", ITER);
  39
  40         size = 1000;
  41         buff = calloc(size, sizeof(char));
  42         T_QUIET; T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
  43
  44         snprintf(iter, sizeof(iter), "%d", ITER);
  45         ret = sysctlbyname("kern.test_mtx_contended", buff, &size, iter, sizeof(iter));
  46         T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_contended");
  47
  48         T_LOG("%s stats:\n%s\n", __func__, buff);
  49
  50         /* first line is "STATS INNER LOOP" */
  51         buff_p = buff;
  52         while (*buff_p != '\n') {
  53                 buff_p++;
  54         }
  55         buff_p++;
  56
  57         /*
  58          * Sequence of statistic lines like
  59          * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
  60          * for all TEST_MTX_MAX_STATS statistics
  61          */
  62         for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
  63                 avg_p = strstr(buff_p, "avg ");
  64
  65                 /* contended test records statistics only for lock/unlock for now */
  66                 if (i == TEST_MTX_LOCK_STATS || i == TEST_MTX_UNLOCK_MTX_STATS) {
  67                         T_QUIET; T_ASSERT_NOTNULL(avg_p, "contended %i average not found", i);
  68                         sscanf(avg_p, "avg %llu", &avg);
  69
  70                         name = strstr(buff_p, "TEST_MTX_");
  71                         end_name = strstr(buff_p, "_STATS");
  72                         name_size = end_name - name - strlen("TEST_MTX_") + 1;
  73
  74                         char name_string[40];
  75                         char avg_name_string[50];
  76                         char *pre_string = "contended ";
  77                         snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
  78                         pre_string = "avg contended ";
  79                         snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
  80                         T_PERF(name_string, avg, "ns", avg_name_string);
  81                 }
  82
  83                 buff_p = avg_p;
  84                 while (*buff_p != '\n') {
  85                         buff_p++;
  86                 }
  87                 buff_p++;
  88         }
  89
  90         while (*buff_p != '\n') {
  91                 buff_p++;
  92         }
  93         buff_p++;
  94
  95         /* next line is "STATS OUTER LOOP" */
  96         while (*buff_p != '\n') {
  97                 buff_p++;
  98         }
  99         buff_p++;
 100
 101         /* contended test records statistics only for lock/unlock for now */
 102         avg_p = strstr(buff_p, "run time ");
 103         T_QUIET; T_ASSERT_NOTNULL(avg_p, "contended %d loop run time not found", 0);
 104         sscanf(avg_p, "run time %llu", &run);
 105
 106         avg_p = strstr(buff_p, "total time ");
 107         T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", 0);
 108         sscanf(avg_p, "total time %llu", &tot);
 109
 110         if (run < tot) {
 111                 avg = run;
 112         } else {
 113                 avg = tot;
 114         }
 115
 116         name = strstr(buff_p, "TEST_MTX_");
 117         end_name = strstr(buff_p, "_STATS");
 118         name_size = end_name - name - strlen("TEST_MTX_") + 1;
 119
 120         char name_string[50];
 121         char avg_name_string[60];
 122         char *pre_string = "contended loop ";
 123         snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 124         pre_string = "avg time contended loop ";
 125         snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 126         T_PERF(name_string, avg / ITER, "ns", avg_name_string);
 127
 128         free(buff);
 129 }
 130
 131 static void
 132 test_from_kernel_lock_unlock_uncontended(void)
 133 {
 134         int i, ret, name_size;
 135         uint64_t avg, run, tot;
 136         size_t size;
 137         char iter[35];
 138         char *buff, *buff_p, *avg_p, *name, *end_name;
 139
 140         T_LOG("Testing locking/unlocking mutex from kernel without contention.\n");
 141         T_LOG("Requesting test with %d iterations\n", ITER);
 142
 143         size = 2000;
 144         buff = calloc(size, sizeof(char));
 145         T_QUIET; T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
 146
 147         snprintf(iter, sizeof(iter), "%d", ITER);
 148         ret = sysctlbyname("kern.test_mtx_uncontended", buff, &size, iter, sizeof(iter));
 149         T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_uncontended");
 150
 151         T_LOG("%s stats:\n%s\n", __func__, buff);
 152
 153         /* first line is "STATS INNER LOOP" */
 154         buff_p = buff;
 155         while (*buff_p != '\n') {
 156                 buff_p++;
 157         }
 158         buff_p++;
 159
 160         /*
 161          * Sequence of statistic lines like
 162          * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
 163          * for all TEST_MTX_MAX_STATS statistics
 164          */
 165         for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
 166                 avg_p = strstr(buff_p, "avg ");
 167                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %i average not found", i);
 168                 sscanf(avg_p, "avg %llu", &avg);
 169
 170                 name = strstr(buff_p, "TEST_MTX_");
 171                 end_name = strstr(buff_p, "_STATS");
 172                 name_size = end_name - name - strlen("TEST_MTX_") + 1;
 173
 174                 char name_string[40];
 175                 char avg_name_string[50];
 176                 char *pre_string = "uncontended ";
 177                 snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 178                 pre_string = "avg time uncontended ";
 179                 snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 180                 T_PERF(name_string, avg, "ns", avg_name_string);
 181
 182                 buff_p = avg_p;
 183                 while (*buff_p != '\n') {
 184                         buff_p++;
 185                 }
 186                 buff_p++;
 187         }
 188
 189         while (*buff_p != '\n') {
 190                 buff_p++;
 191         }
 192         buff_p++;
 193
 194         /* next line is "STATS OUTER LOOP" */
 195         while (*buff_p != '\n') {
 196                 buff_p++;
 197         }
 198         buff_p++;
 199
 200         /*
 201          * Sequence of statistic lines like
 202          * total time 4040673 ns total run time 3981080 ns TEST_MTX_LOCK_STATS
 203          * for all TEST_MTX_MAX_STATS statistics exept UNLOCK
 204          */
 205         for (i = 0; i < TEST_MTX_MAX_STATS - 2; i++) {
 206                 avg_p = strstr(buff_p, "run time ");
 207                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop run time not found", i);
 208                 sscanf(avg_p, "run time %llu", &run);
 209
 210                 avg_p = strstr(buff_p, "total time ");
 211                 T_QUIET; T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", i);
 212                 sscanf(avg_p, "total time %llu", &tot);
 213
 214                 if (run < tot) {
 215                         avg = run;
 216                 } else {
 217                         avg = tot;
 218                 }
 219
 220                 name = strstr(buff_p, "TEST_MTX_");
 221                 end_name = strstr(buff_p, "_STATS");
 222                 name_size = end_name - name - strlen("TEST_MTX_") + 1;
 223
 224                 char name_string[50];
 225                 char avg_name_string[60];
 226                 char *pre_string = "uncontended loop ";
 227                 snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 228                 pre_string = "avg time uncontended loop ";
 229                 snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
 230                 T_PERF(name_string, avg / ITER, "ns", avg_name_string);
 231
 232                 buff_p = avg_p;
 233                 while (*buff_p != '\n') {
 234                         buff_p++;
 235                 }
 236                 buff_p++;
 237         }
 238         free(buff);
 239 }
 240
 241 extern char **environ;
 242 static void
 243 fix_cpu_frequency(void)
 244 {
 245 #if CONFIG_EMBEDDED
 246         int spawn_ret, pid;
 247         char *const clpcctrl_args[] = {"/usr/local/bin/clpcctrl", "-f", "5000", NULL};
 248
 249         T_LOG("Setting cpu frequency to %d\n", 5000);
 250
 251         spawn_ret = posix_spawn(&pid, clpcctrl_args[0], NULL, NULL, clpcctrl_args, environ);
 252         waitpid(pid, &spawn_ret, 0);
 253
 254 #else /*CONFIG_EMBEDDED*/
 255
 256         int spawn_ret, pid;
 257         int ret, nom_freq;
 258         size_t len;
 259         float val;
 260         char scale;
 261         char *buffer, *cpu_freq;
 262         char str_val[10];
 263
 264         ret = sysctlbyname("machdep.cpu.brand_string", NULL, &len, NULL, 0);
 265         T_QUIET; T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
 266
 267         buffer = malloc(len + 2);
 268         ret = sysctlbyname("machdep.cpu.brand_string", buffer, &len, NULL, 0);
 269         T_QUIET; T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
 270         buffer[len + 1] = '\0';
 271
 272         cpu_freq = strstr(buffer, "CPU @ ");
 273         if (cpu_freq == NULL) {
 274                 T_LOG("Could not fix frequency, %s field not present\n", "CPU @ ");
 275                 goto out;
 276         }
 277
 278         if (strstr(cpu_freq, "Hz") != NULL) {
 279                 sscanf(cpu_freq, "CPU @ %f%cHz", &val, &scale);
 280         } else {
 281                 if (strstr(cpu_freq, "hz") != NULL) {
 282                         sscanf(cpu_freq, "CPU @ %f%chz", &val, &scale);
 283                 } else {
 284                         T_LOG("Could not fix frequency, %s field not present\n", "Hz");
 285                         goto out;
 286                 }
 287         }
 288
 289         switch (scale) {
 290         case 'M':
 291         case 'm':
 292                 nom_freq = (int) val;
 293                 break;
 294         case 'G':
 295         case 'g':
 296                 nom_freq = (int) (val * 1000);
 297                 break;
 298         default:
 299                 T_LOG("Could not fix frequency, scale field is %c\n", scale);
 300                 goto out;
 301         }
 302
 303         snprintf(str_val, 10, "%d", nom_freq);
 304         T_LOG("Setting min and max cpu frequency to %d (%s)\n", nom_freq, str_val);
 305         char *xcpm_args[] = {"/usr/local/bin/xcpm", "limits", str_val, str_val, NULL};
 306         spawn_ret = posix_spawn(&pid, xcpm_args[0], NULL, NULL, xcpm_args, environ);
 307         waitpid(pid, &spawn_ret, 0);
 308
 309 out:
 310         free(buffer);
 311         return;
 312 #endif /*CONFIG_EMBEDDED*/
 313 }
 314
 315 T_DECL(kernel_mtx_perf_test,
 316     "Kernel mutex performance test",
 317     T_META_ASROOT(YES), T_META_CHECK_LEAKS(NO))
 318 {
 319         fix_cpu_frequency();
 320
 321         test_from_kernel_lock_unlock_uncontended();
 322         test_from_kernel_lock_unlock_contended();
 323 }