src/timing/timing.c

   1 /*
   2  * rpt.c       08/09/29
   3  *
   4  * License      : GNU GPL v.2
   5  * Description  : PowerPC timestamping function
   6  * Author       : Martin Zidek
   7  */
   8
   9 #include <stdbool.h>
  10 #include <stdio.h>
  11 #include <stdlib.h>
  12 #include <stdint.h>
  13 #include <timing.h>
  14 #include <time.h>
  15 #include <timing_config.h>
  16 #include <math.h>
  17
  18 #define TS_SIZE 4500000
  19 #define TB_TO_NS_SHIFT 5
  20
  21 //#define mulhdu(a,b) ((uint64_t)((double)a * (double)b)>>64)
  22 #define tb_to_sched_clock(tb,shift) (tb << shift)
  23
  24 #ifdef CONFIG_TIMING_IPOINT_ASM
  25 typedef struct timestamp_str {
  26         uint32_t tbu, tbl;
  27         uint16_t id;
  28 } timestamp_t;
  29 #endif
  30
  31 #ifdef CONFIG_TIMING_IPOINT_CLOCK_GETTIME
  32 typedef struct timestamp_str {
  33         struct timespec ts;
  34         uint16_t id;
  35 } timestamp_t;
  36 #endif
  37
  38 unsigned long long tb_to_ns_scale = 0xf26c9b26c9b26c9bULL;
  39
  40 clockid_t clk_id = -1;
  41 timestamp_t ts[TS_SIZE];
  42 timestamp_t *timestamp_ptr = ts;
  43 timestamp_t *timestamp_buff_end = &ts[TS_SIZE];
  44 bool timestamp_enabled = true;
  45 static int cnt=0;
  46 struct timespec meas_start_ts;
  47 FILE *file;
  48 static pid_t pid=-1;
  49
  50 void timing_statistics_asm(void);
  51 void timing_output_trace_screen(void);
  52 void timing_output_trace_file(void);
  53 void timing_statistics_clock_gettime(void);
  54
  55 uint64_t mulhdu(uint64_t a, uint64_t b)
  56 {
  57         long double res;
  58         res = ((long double)a*(long double)b)/pow(2.0,64.0);
  59         return (uint64_t)res;
  60 //      asm volatile (
  61 //              "        cmpwi   6,0\n"
  62 //              "        cmpwi   cr1,3,0\n"
  63 //              "        mr      10,4\n"
  64 //              "        mulhwu  4,4,5\n"
  65 //              "        beq     1f\n"
  66 //              "        mulhwu  0,10,6\n"
  67 //              "        mullw   7,10,5\n"
  68 //              "        addc    7,0,7\n"
  69 //              "        addze   4,4\n"
  70 //              "1:      beqlr   cr1\n"             /* all done if high part of A is 0 */
  71 //              "        mr      10,3\n"
  72 //              "        mullw   9,3,5\n"
  73 //              "        mulhwu  3,3,5\n"
  74 //              "        beq     2f\n"
  75 //              "        mullw   0,10,6\n"
  76 //              "        mulhwu  8,10,6\n"
  77 //              "        addc    7,0,7\n"
  78 //              "        adde    4,4,8\n"
  79 //              "        addze   3,3\n"
  80 //              "2:      addc    4,4,9\n"
  81 //              "        addze   3,3\n"
  82 //              "        blr\n"
  83 //              :
  84 //              :
  85 //              :"cr1"
  86 //
  87 //      );
  88 }
  89
  90 #ifdef CONFIG_TIMING_IPOINT_ASM
  91 uint64_t restore_tb(uint32_t tbu, uint32_t tbl)
  92 {
  93         uint64_t tb;
  94
  95         tb = tbu;
  96         tb <<= 32;
  97         tb |= tbl;
  98
  99         return tb;
 100 }
 101
 102 uint64_t get_boot_tb(void)
 103 {
 104         FILE *f;
 105         uint64_t boot_tb;
 106
 107         f = fopen("boot_tb","r");
 108         if(fscanf(f, "%llu", &boot_tb)==0)
 109                 printf("timing: boot_tb not read successfuly!\n");
 110
 111         return boot_tb;
 112 }
 113
 114 void print_tstamp_to_schedclock(timestamp_t *ts)
 115 {
 116         uint64_t tb;
 117         uint64_t sched_clock;
 118         unsigned long int sec, usec;
 119
 120         tb = restore_tb(ts->tbu, ts->tbl);
 121 //      printf("tb=%llu\n",tb);
 122 //      printf("mulhdu=%llu\n",mulhdu(tb - get_boot_tb(), tb_to_ns_scale));
 123         sched_clock = (uint64_t)((long double)(mulhdu(tb - get_boot_tb(), tb_to_ns_scale))*pow(2.0,5.0));
 124 //      printf("sched_clock=%llu\n",sched_clock);
 125
 126         sched_clock+=500;
 127         sched_clock=sched_clock / 1000;
 128
 129         sec = (uint32_t) (sched_clock/1000000);
 130         usec = (sched_clock % 1000000ULL);
 131
 132 #ifdef CONFIG_TIMING_OUTPUT_SCREEN
 133         printf("%d %5lu.%06lu\n", ts->id, sec, usec);
 134 #endif
 135 #ifdef CONFIG_TIMING_OUTPUT_FILE
 136         fprintf(file, "%5lu.%06lu\t%d\t%d\tR\t%llu\n", sec, usec, pid, ts->id, tb);
 137 #endif
 138 }
 139 #endif
 140
 141 timestamp_t * timestamp_handle_overflow(void)
 142 {
 143         static bool first_overflow = true;
 144         /* Here we can also implement atomic wrap-around and return
 145          * true. */
 146         timestamp_enabled = false;
 147         if(first_overflow) {
 148                 printf("timestamp overflow\n");
 149                 first_overflow = false;
 150         }
 151         cnt++;
 152         return 0;
 153 }
 154
 155 void timing_ipoint_dummy(unsigned char id)
 156 {
 157         printf("timing: Instrumentation point type not set!\n");
 158 }
 159
 160 #ifdef CONFIG_TIMING_IPOINT_ASM
 161 void timing_ipoint_asm(unsigned char id)
 162 {
 163         timestamp_t *p, *pinc;
 164         uint32_t tbu, tb, tbu2;
 165
 166         /* Store current TB */
 167         asm volatile (
 168                 "1:\n"
 169                 "       mftbu %0\n"
 170                 "       mftb  %1\n"
 171                 "       mftbu %2\n"
 172                 "       cmpw  0,%0,%2\n"
 173                 "       bne-  1b\n"
 174                 : "=r" (tbu), "=r" (tb), "=r" (tbu2) /* Outputs */
 175                 : /* No inputs */
 176                 : "cr0" ); /* CR0 changes */
 177
 178         asm volatile (
 179                 "1:       lwarx   %0,0,%4\n"
 180                 "         addi    %1,%0,%3\n"
 181                 "         stwcx.  %1,0,%4\n"
 182                 "         bne-    1b\n"
 183                 : "=&b" (p), "=&b" (pinc), "=m" (timestamp_ptr)
 184                 : "n" (sizeof(timestamp_t)), "b" (&timestamp_ptr)
 185                 : "cr0");
 186
 187         if (p >= timestamp_buff_end) {
 188                 p = timestamp_handle_overflow();
 189                 if (!p)
 190                         return;
 191         }
 192
 193         p->id = id;
 194         p->tbu = tbu;
 195         p->tbl = tb;
 196 }
 197 #endif
 198
 199 #ifdef CONFIG_TIMING_IPOINT_CLOCK_GETTIME
 200 void timing_ipoint_clock_gettime(unsigned char id)
 201 {
 202         timestamp_t *p, *pinc;
 203
 204         p = timestamp_ptr;
 205
 206         clock_gettime(clk_id, &(p->ts));
 207 //      pinc = p+1;
 208 //      timestamp_ptr = pinc;
 209         if (p >= timestamp_buff_end) {
 210                 p = timestamp_handle_overflow();
 211                 if (!p)
 212                         return;
 213         }
 214         else {
 215                 p->id = id;
 216                 timestamp_ptr++;
 217         }
 218 }
 219 #endif
 220
 221 void timing_init(void)
 222 {
 223         printf("Timing analysis turned on - initialising\n");
 224
 225         /*just for case no ipoint function configured during compile-time*/
 226         timing_ipoint = timing_ipoint_dummy;
 227 #ifdef CONFIG_TIMING_IPOINT_ASM
 228         timing_ipoint = timing_ipoint_asm;
 229         timing_statistics = timing_statistics_asm;
 230 #endif
 231 #ifdef CONFIG_TIMING_IPOINT_CLOCK_GETTIME
 232         timing_ipoint = timing_ipoint_clock_gettime;
 233         timing_statistics = timing_statistics_clock_gettime;
 234 #endif
 235         system("mount -t debugfs trace /debug");
 236         system("echo sched_switch > /debug/tracing/current_tracer");
 237
 238 #ifdef CONFIG_CLOCK_RT
 239         clk_id = CLOCK_REALTIME;
 240 #endif
 241 #ifdef CONFIG_CLOCK_MONOTONIC
 242         clk_id = CLOCK_MONOTONIC;
 243 #endif
 244 #ifdef CONFIG_CLOCK_MONOTONIC_RAW
 245         clk_id = CLOCK_MONOTONIC_RAW;
 246 #endif
 247 #ifdef CONFIG_CLOCK_PROCESS
 248         clk_id = CLOCK_PROCESS_CPUTIME_ID;
 249 #endif
 250 #ifdef CONFIG_CLOCK_THREAD
 251         clk_id = CLOCK_THREAD_CPUTIME_ID;
 252 #endif
 253         if(clk_id == -1) {
 254                 printf("timing: Clock source not set during compile time! Unable to perform timestamping!\n");
 255                 return;
 256         }
 257
 258 #ifdef CONFIG_TIMING_OUTPUT_SCREEN
 259         timing_output_trace = timing_output_trace_screen;
 260 #endif
 261 #ifdef CONFIG_TIMING_OUTPUT_FILE
 262         timing_output_trace = timing_output_trace_file;
 263 #endif
 264         printf("Timing library initialized!\n");
 265         system("dmesg | grep boot_tb | sed 's#.*boot_tb\\=\\([0-9]*\\).*#\\1#' | tee boot_tb");
 266         system("echo 1 > /debug/tracing/tracing_enabled");
 267         clock_gettime(clk_id, &meas_start_ts);
 268 }
 269
 270 void timing_finish()
 271 {
 272         system("echo 0 > /debug/tracing/tracing_enabled");
 273 #ifdef CONFIG_TIMING_OUTPUT_FILE
 274         system("cat /debug/tracing/trace | tee taskswitch.log");
 275 #endif
 276 #ifdef CONFIG_TIMING_OUTPUT_SCREEN
 277         system("cat /debug/tracing/trace");
 278 #endif
 279         system("echo nop > /debug/tracing/current_tracer");
 280 }
 281
 282 #ifdef CONFIG_TIMING_IPOINT_ASM
 283 void print_ts_asm(timestamp_t *ts)
 284 {
 285         printf("%d %llu\n", ts->id, restore_tb(ts->tbu, ts->tbl));
 286 }
 287 #endif
 288
 289 void timing_output_trace_screen(void)
 290 {
 291         timestamp_t *ts_iter;
 292         int i=0;
 293         printf("Timing analysis application trace\n");
 294         ts_iter = ts;
 295         if(timestamp_enabled)
 296         while(ts_iter != (timestamp_ptr+1))
 297         {
 298 #ifdef CONFIG_TIMING_IPOINT_ASM
 299 //              print_ts_asm(ts_iter);
 300                 print_tstamp_to_schedclock(ts_iter);
 301 #endif
 302                 ts_iter++;
 303                 i++;
 304         }
 305         else
 306         printf("got %d timestamps over limit\n",cnt);
 307 }
 308
 309 double timespec2sec(struct timespec *tspec)
 310 {
 311         double result;
 312
 313         result = tspec->tv_sec + (tspec->tv_nsec*0.000000001);
 314
 315         return result;
 316 }
 317
 318 void timing_output_trace_file(void)
 319 {
 320         timestamp_t *ts_iter;
 321         int i=0;
 322
 323         file = fopen(CONFIG_TIMING_OUTPUT_FILENAME, "w+");
 324         if(file == NULL) {
 325                 perror("timing file open error");
 326                 return;
 327         }
 328         fprintf(file, "Timing analysis application trace\n");
 329         ts_iter = ts;
 330         if(timestamp_enabled)
 331         while(ts_iter != (timestamp_ptr+1))
 332         {
 333 #ifdef CONFIG_TIMING_IPOINT_ASM
 334                 print_tstamp_to_schedclock(ts_iter);
 335 //              fprintf(file, "%d %llu\n", ts_iter->id, restore_tb(ts_iter->tbu, ts_iter->tbl));
 336 #endif
 337 #ifdef CONFIG_TIMING_IPOINT_CLOCK_GETTIME
 338                 fprintf(file, "%d %.6f\n", ts_iter->id, timespec2sec(&ts_iter->ts));
 339 #endif
 340                 ts_iter++;
 341                 i++;
 342         }
 343         else
 344                 fprintf(file, "got %d timestamps over limit\n",cnt);
 345
 346         fclose(file);
 347 }
 348
 349 #ifdef CONFIG_TIMING_IPOINT_ASM
 350 double sub_timestamps_us(timestamp_t *t1, timestamp_t *t2)
 351 {
 352         double result;
 353         uint64_t t1_val, t2_val;
 354
 355         t1_val = t1->tbu;
 356         t1_val <<= 32;
 357         t1_val |= t1->tbl;
 358         t2_val = t2->tbu;
 359         t2_val <<= 32;
 360         t2_val |= t2->tbl;
 361
 362         result = (double)(t2_val - t1_val)/CONFIG_TIMING_TB_FREQ;
 363         result *= 1000000.0;
 364
 365         return result;
 366 }
 367
 368 void timing_statistics_asm(void)
 369 {
 370         timestamp_t *ts_iter;
 371         int i=1;
 372
 373         printf("Timing Statistics\n");
 374         printf("-----------------\n");
 375         ts_iter = ts;
 376
 377         if(timestamp_enabled)
 378                 while(ts_iter != (timestamp_ptr+1))
 379                 {
 380                         if(i%2 == 0) {
 381                                 printf("%3.2f\n", sub_timestamps_us(ts_iter-1, ts_iter));
 382                         }
 383                         ts_iter++;
 384                         i++;
 385                 }
 386         else
 387         printf("got %d timestamps over limit\n",cnt);
 388 }
 389 #endif
 390
 391 double sub_ts_us(struct timespec start, struct timespec end)
 392 {
 393         struct timespec temp;
 394         double ret;
 395
 396         if ((end.tv_nsec-start.tv_nsec)<0) {
 397                 temp.tv_sec = end.tv_sec-start.tv_sec-1;
 398                 temp.tv_nsec = 1000000000+end.tv_nsec-start.tv_nsec;
 399         } else {
 400                 temp.tv_sec = end.tv_sec-start.tv_sec;
 401                 temp.tv_nsec = end.tv_nsec-start.tv_nsec;
 402         }
 403
 404         ret = (temp.tv_sec * 1000000.0) + (temp.tv_nsec/1000.0);
 405
 406         return ret;
 407 }
 408
 409 #ifdef CONFIG_TIMING_IPOINT_CLOCK_GETTIME
 410 void timing_statistics_clock_gettime(void)
 411 {
 412         timestamp_t *ts_iter;
 413         int i=1;
 414
 415         printf("Highrest_Statistics\n");
 416         ts_iter = ts;
 417
 418         if(timestamp_enabled)
 419                 while(ts_iter != (timestamp_ptr+1))
 420                 {
 421                         if(i%2 == 0) {
 422                                 printf("%3.2f\n", sub_ts_us((ts_iter-1)->ts,(ts_iter)->ts));
 423                         }
 424                         ts_iter++;
 425                         i++;
 426                 }
 427         else
 428                 printf("got %d timestamps over limit\n",cnt);
 429 }
 430 #endif
 431
 432 void timing_set_pid(pid_t set_pid)
 433 {
 434         pid = set_pid;
 435 }