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