2 * Copyright (c) 1993, 1994 Barton P. Miller, Jeff Hollingsworth,
3 * Bruce Irvin, Jon Cargille, Krishna Kunchithapadam, Karen
4 * Karavanic, Tia Newhall, Mark Callaghan. All rights reserved.
6 * This software is furnished under the condition that it may not be
7 * provided or otherwise made available to, or used by, any other
8 * person, except as provided for by the terms of applicable license
9 * agreements. No title to or ownership of the software is hereby
10 * transferred. The name of the principals may not be used in any
11 * advertising or publicity related to this software without specific,
12 * written prior authorization. Any use of this software must include
13 * the above copyright notice.
21 /************************************************************************
22 * RTposix.c: runtime instrumentation functions for generic posix.
23 ************************************************************************/
29 /************************************************************************
31 ************************************************************************/
47 #include "rtinst/h/rtinst.h"
48 #include "rtinst/h/trace.h"
54 /************************************************************************
56 ************************************************************************/
58 static const double MILLION = 1000000.0;
64 /************************************************************************
66 ************************************************************************/
68 extern void DYNINSTos_init(void);
69 extern time64 DYNINSTgetCPUtime(void);
70 extern time64 DYNINSTgetWalltime(void);
76 /************************************************************************
77 * time64 DYNINSTgetUserTime(void)
79 * get the user time for "an" LWP of the monitored process.
80 ************************************************************************/
83 DYNINSTgetUserTime(void) {
84 return DYNINSTgetCPUtime();
91 /************************************************************************
92 * void DYNINSTbreakPoint(void)
95 ************************************************************************/
98 DYNINSTbreakPoint(void) {
99 kill(getpid(), SIGSTOP);
106 /************************************************************************
107 * void DYNINSTstartProcessTimer(tTimer* timer)
108 ************************************************************************/
111 DYNINSTstartProcessTimer(tTimer* timer) {
112 if (timer->counter == 0) {
113 timer->start = DYNINSTgetUserTime();
114 timer->normalize = MILLION;
123 /************************************************************************
124 * void DYNINSTstopProcessTimer(tTimer* timer)
125 ************************************************************************/
128 DYNINSTstopProcessTimer(tTimer* timer) {
129 if (!timer->counter) {
133 if (timer->counter == 1) {
134 time64 now = DYNINSTgetUserTime();
136 timer->snapShot = now - timer->start + timer->total;
139 timer->total = DYNINSTgetUserTime() - timer->start + timer->total;
142 if (now < timer->start) {
143 printf("id=%d, snapShot=%f total=%f, \n start=%f now=%f\n",
144 timer->id.id, (double)timer->snapShot, (double)timer->total,
145 (double)timer->start, (double)now);
146 printf("process timer rollback\n"); fflush(stdout);
159 /************************************************************************
160 * void DYNINSTstartWallTimer(tTimer* timer)
161 ************************************************************************/
164 DYNINSTstartWallTimer(tTimer* timer) {
165 if (timer->counter == 0) {
166 timer->start = DYNINSTgetWalltime();
167 timer->normalize = MILLION;
176 /************************************************************************
177 * void DYNINSTstopWallTimer(tTimer* timer)
178 ************************************************************************/
181 DYNINSTstopWallTimer(tTimer* timer) {
182 if (!timer->counter) {
186 if (timer->counter == 1) {
187 time64 now = DYNINSTgetWalltime();
189 timer->snapShot = now - timer->start + timer->total;
192 timer->total = DYNINSTgetWalltime() - timer->start + timer->total;
195 if (now < timer->start) {
196 printf("wall timer rollback\n"); fflush(stdout);
209 /************************************************************************
210 * void DYNINSTpauseProcess(void)
211 * void DYNINSTcontinueProcess(void)
213 * pause and continue process.
214 ************************************************************************/
216 static volatile int DYNINSTpauseDone = 0;
219 DYNINSTpauseProcess(void) {
220 DYNINSTpauseDone = 0;
221 while (!DYNINSTpauseDone) {
226 DYNINSTcontinueProcess(void) {
227 DYNINSTpauseDone = 1;
234 /************************************************************************
235 * void DYNINST_install_ualarm(unsigned value, unsigned interval)
237 * an implementation of "ualarm" using the "setitimer" syscall.
238 ************************************************************************/
241 DYNINST_install_ualarm(unsigned value, unsigned interval) {
244 it.it_value.tv_sec = value / 1000000;
245 it.it_value.tv_usec = value % 1000000;
246 it.it_interval.tv_sec = interval / 1000000;
247 it.it_interval.tv_usec = interval % 1000000;
249 if (setitimer(ITIMER_REAL, &it, 0) == -1) {
259 /************************************************************************
260 * global data for DYNINST functions.
261 ************************************************************************/
263 double DYNINSTdata[SYN_INST_BUF_SIZE/sizeof(double)];
264 double DYNINSTglobalData[SYN_INST_BUF_SIZE/sizeof(double)];
270 /************************************************************************
271 * float DYNINSTcyclesPerSecond(void)
273 * need a well-defined method for finding the CPU cycle speed
275 ************************************************************************/
277 #define NOPS_4 asm("nop"); asm("nop"); asm("nop"); asm("nop")
278 #define NOPS_16 NOPS_4; NOPS_4; NOPS_4; NOPS_4
281 DYNINSTcyclesPerSecond(void) {
287 const unsigned LOOP_LIMIT = 50000;
289 start_cpu = DYNINSTgetCPUtime();
290 for (i = 0; i < LOOP_LIMIT; i++) {
291 NOPS_16; NOPS_16; NOPS_16; NOPS_16;
292 NOPS_16; NOPS_16; NOPS_16; NOPS_16;
293 NOPS_16; NOPS_16; NOPS_16; NOPS_16;
294 NOPS_16; NOPS_16; NOPS_16; NOPS_16;
296 end_cpu = DYNINSTgetCPUtime();
297 elapsed = (double) end_cpu - start_cpu;
298 speed = (MILLION*256*LOOP_LIMIT)/elapsed;
300 /* printf("elapsed = %f\n", elapsed); */
301 /* printf("speed = %f\n", speed); */
310 /************************************************************************
311 * void saveFPUstate(float* base)
312 * void restoreFPUstate(float* base)
314 * save and restore state of FPU on signals. these are null functions
315 * for most well designed and implemented systems.
316 ************************************************************************/
319 saveFPUstate(float* base) {
323 restoreFPUstate(float* base) {
329 /* The current observed cost since the last call to
330 * DYNINSTgetObservedCycles(false)
332 unsigned DYNINSTobsCostLow;
334 /************************************************************************
335 * int64 DYNINSTgetObservedCycles(RT_Boolean in_signal)
337 * report the observed cost of instrumentation in machine cycles.
339 * We keep cost as a 64 bit int, but the code generated by dyninst is
340 * a 32 bit counter (for speed). So this function also converts the
341 * cost into a 64 bit value.
342 ************************************************************************/
343 static int64 DYNINSTgetObservedCycles(RT_Boolean in_signal)
345 static int64 value = 0;
351 /* update the 64 bit version of the counter */
352 value += DYNINSTobsCostLow;
354 /* reset the low counter */
355 DYNINSTobsCostLow = 0;
363 /************************************************************************
364 * void DYNINSTsampleValues(void)
366 * dummy function for sampling timers and counters. the actual code
367 * is added by dynamic instrumentation from the paradyn daemons.
368 ************************************************************************/
370 static int DYNINSTnumReported = 0;
373 DYNINSTsampleValues(void) {
374 DYNINSTnumReported++;
381 /************************************************************************
382 * void DYNINSTflushTrace(void)
384 * flush any accumalated traces.
385 ************************************************************************/
387 static FILE* DYNINSTtraceFp = 0;
390 DYNINSTflushTrace(void) {
391 if (DYNINSTtraceFp) fflush(DYNINSTtraceFp);
398 /************************************************************************
399 * void DYNINSTgenerateTraceRecord(traceStream sid, short type,
400 * short length, void* data, int flush)
401 ************************************************************************/
403 static time64 startWall = 0;
406 DYNINSTgenerateTraceRecord(traceStream sid, short type, short length,
407 void *eventData, int flush) {
409 static unsigned pipe_gone = 0;
418 header.wall = DYNINSTgetWalltime() - startWall;
419 header.process = DYNINSTgetCPUtime();
421 length = ALIGN_TO_WORDSIZE(length);
424 header.length = length;
427 memcpy(&buffer[count], &sid, sizeof(traceStream));
428 count += sizeof(traceStream);
430 memcpy(&buffer[count], &header, sizeof(header));
431 count += sizeof(header);
433 count = ALIGN_TO_WORDSIZE(count);
434 memcpy(&buffer[count], eventData, length);
439 if (!DYNINSTtraceFp || (type == TR_EXIT)) {
440 DYNINSTtraceFp = fdopen(dup(CONTROLLER_FD), "w");
443 ret = fwrite(buffer, count, 1, DYNINSTtraceFp);
445 printf("unable to write trace record, errno=%d\n", errno);
446 printf("disabling further data logging, pid=%d\n", (int) getpid());
450 if (flush) DYNINSTflushTrace();
457 /************************************************************************
458 * void DYNINSTreportBaseTramps(void)
460 * report the cost of base trampolines.
461 ************************************************************************/
463 static float DYNINSTcyclesToUsec = 0;
464 static time64 DYNINSTlastWallTime = 0;
465 static time64 DYNINSTlastCPUTime = 0;
468 DYNINSTreportBaseTramps() {
472 time64 elapsedWallTime;
473 time64 currentPauseTime;
475 sample.slotsExecuted = 0;
476 sample.observedCost = ((double) DYNINSTgetObservedCycles(1)) *
477 (DYNINSTcyclesToUsec / MILLION);
480 currentCPU = DYNINSTgetCPUtime();
481 currentWall = DYNINSTgetWalltime();
482 elapsedWallTime = currentWall - DYNINSTlastWallTime;
483 currentPauseTime = elapsedWallTime - (currentCPU - DYNINSTlastCPUTime);
485 sample.pauseTime = ((double) currentPauseTime);
486 sample.pauseTime /= 1000000.0;
488 DYNINSTlastWallTime = currentWall;
489 DYNINSTlastCPUTime = currentCPU;
491 DYNINSTgenerateTraceRecord(0, TR_COST_UPDATE, sizeof(sample), &sample, 0);
498 /************************************************************************
499 * void DYNINSTalarmExpire(void)
501 * called periodically by signal handlers. report sampled data back
502 * to the paradyn daemons. when the program exits, DYNINSTsampleValues
503 * should be called directly.
504 ************************************************************************/
508 static volatile int DYNINSTsampleMultiple = 1;
509 static int DYNINSTnumSampled = 0;
510 static int DYNINSTtotalAlarmExpires = 0;
511 static time64 DYNINSTtotalSampleTime = 0;
514 DYNINSTalarmExpire(int signo) {
517 static int in_sample = 0;
518 float fp_context[N_FP_REGS];
525 DYNINSTtotalAlarmExpires++;
526 if ((++DYNINSTnumSampled % DYNINSTsampleMultiple) == 0) {
527 saveFPUstate(fp_context);
528 start_cpu = DYNINSTgetCPUtime();
530 /* to keep observed cost accurate due to 32-cycle rollover */
531 (void) DYNINSTgetObservedCycles(0);
533 DYNINSTsampleValues();
534 DYNINSTreportBaseTramps();
537 end_cpu = DYNINSTgetCPUtime();
538 DYNINSTtotalSampleTime += (end_cpu - start_cpu);
539 restoreFPUstate(fp_context);
549 /************************************************************************
550 * void DYNINSTinit(int doskip)
552 * initialize the DYNINST library. this function is called at the start
553 * of the application program.
555 * the first this to do is to call the os specific initialization
557 ************************************************************************/
559 static float DYNINSTsamplingRate = 0;
560 static int DYNINSTtotalSamples = 0;
561 static tTimer DYNINSTelapsedCPUTime;
562 static tTimer DYNINSTelapsedTime;
565 DYNINSTinit(int doskip) {
566 struct sigaction act;
568 const char* interval;
574 DYNINSTcyclesToUsec = MILLION/DYNINSTcyclesPerSecond();
575 DYNINSTlastCPUTime = DYNINSTgetCPUtime();
576 DYNINSTlastWallTime = DYNINSTgetWalltime();
578 act.sa_handler = DYNINSTalarmExpire;
580 #if defined(SA_INTERRUPT)
581 act.sa_flags |= SA_INTERRUPT;
582 #endif /* defined(SA_INTERRUPT) */
583 sigfillset(&act.sa_mask);
585 if (sigaction(SIGALRM, &act, 0) == -1) {
586 perror("sigaction(SIGALRM)");
591 interval = getenv("DYNINSTsampleInterval");
593 val = atoi(interval);
595 DYNINSTsamplingRate = val/MILLION;
597 DYNINST_install_ualarm(val, val);
599 /* printf("Time at main %g us\n", (double) DYNINSTgetCPUtime()); */
604 DYNINSTstartWallTimer(&DYNINSTelapsedTime);
605 DYNINSTstartProcessTimer(&DYNINSTelapsedCPUTime);
612 /************************************************************************
613 * void DYNINSTexit(void)
615 * handle `exit' in the application. current nothing is done.
616 ************************************************************************/
626 /************************************************************************
627 * void DYNINSTreportTimer(tTimer* timer)
629 * report the timer `timer' to the paradyn daemon.
630 ************************************************************************/
633 DYNINSTreportTimer(tTimer *timer) {
639 total = timer->snapShot;
641 else if (timer->counter) {
642 /* timer is running */
643 if (timer->type == processTime) {
644 now = DYNINSTgetUserTime();
646 now = DYNINSTgetWalltime();
648 total = now - timer->start + timer->total;
651 total = timer->total;
654 if (total < timer->lastValue) {
655 if (timer->type == processTime) {
661 printf("time regressed timer %d, total = %f, last = %f\n",
662 timer->id.id, (float) total, (float) timer->lastValue);
663 if (timer->counter) {
664 printf("timer was active\n");
666 printf("timer was inactive\n");
668 printf("mutex=%d, counter=%d, sampled=%d, snapShot=%f\n",
669 (int) timer->mutex, (int) timer->counter, (int) timer->sampled,
670 (double) timer->snapShot);
671 printf("now = %f, start = %f, total = %f\n",
672 (double) now, (double) timer->start, (double) timer->total);
677 timer->lastValue = total;
679 sample.id = timer->id;
680 sample.value = ((double) total) / (double) timer->normalize;
681 DYNINSTtotalSamples++;
683 DYNINSTgenerateTraceRecord(0, TR_SAMPLE, sizeof(sample), &sample, 0);
684 /* printf("raw sample %d = %f\n", sample.id.id, sample.value); */
691 /************************************************************************
692 * void DYNINSTfork(void* arg, int pid)
694 * track a fork() system call, and report to the paradyn daemon.
695 ************************************************************************/
698 DYNINSTfork(void* arg, int pid) {
702 printf("fork called with pid = %d\n", pid);
705 forkRec.ppid = getpid();
709 DYNINSTgenerateTraceRecord(sid,TR_FORK,sizeof(forkRec), &forkRec, 1);
719 /************************************************************************
720 * void DYNINSTprintCost(void)
722 * print a detailed summary of the cost of the application's run.
723 ************************************************************************/
726 DYNINSTprintCost(void) {
730 struct endStatsRec stats;
732 DYNINSTstopProcessTimer(&DYNINSTelapsedCPUTime);
733 DYNINSTstopWallTimer(&DYNINSTelapsedTime);
735 value = DYNINSTgetObservedCycles(0);
736 stats.instCycles = value;
738 value *= DYNINSTcyclesToUsec;
740 stats.alarms = DYNINSTtotalAlarmExpires;
741 stats.numReported = DYNINSTnumReported;
742 stats.instTime = ((double) value)/MILLION;
743 stats.handlerCost = ((double) DYNINSTtotalSampleTime)/MILLION;
745 now = DYNINSTgetCPUtime();
746 stats.totalCpuTime = ((double) DYNINSTelapsedCPUTime.total)/MILLION;
747 stats.totalWallTime = ((double) DYNINSTelapsedTime.total/MILLION);
749 stats.samplesReported = DYNINSTtotalSamples;
750 stats.samplingRate = DYNINSTsamplingRate;
755 fp = fopen("stats.out", "w");
757 fprintf(fp, "DYNINSTtotalAlarmExpires %d\n", stats.alarms);
758 fprintf(fp, "DYNINSTnumReported %d\n", stats.numReported);
759 fprintf(fp,"Raw cycle count = %f\n", (double) stats.instCycles);
760 fprintf(fp,"Total instrumentation cost = %f\n", stats.instTime);
761 fprintf(fp,"Total handler cost = %f\n", stats.handlerCost);
762 fprintf(fp,"Total cpu time of program %f\n", stats.totalCpuTime);
763 fprintf(fp,"Elapsed wall time of program %f\n",
764 stats.totalWallTime/1000000.0);
765 fprintf(fp,"total data samples %d\n", stats.samplesReported);
766 fprintf(fp,"sampling rate %f\n", stats.samplingRate);
767 fprintf(fp,"Application program ticks %d\n", stats.userTicks);
768 fprintf(fp,"Instrumentation ticks %d\n", stats.instTicks);
772 /* record that we are done -- should be somewhere better. */
773 DYNINSTgenerateTraceRecord(0, TR_EXIT, sizeof(stats), &stats, 1);
780 /************************************************************************
781 * void DYNINSTrecordTag(int tag)
783 * mark a new tag in tag list.
784 ************************************************************************/
786 static int DYNINSTtagCount = 0;
787 static int DYNINSTtagLimit = 1000;
788 static int DYNINSTtags[1000];
791 DYNINSTrecordTag(int tag) {
794 for (i=0; i < DYNINSTtagCount; i++) {
795 if (DYNINSTtags[i] == tag) return;
798 if (DYNINSTtagCount == DYNINSTtagLimit) abort();
799 DYNINSTtags[DYNINSTtagCount++] = tag;
806 /************************************************************************
807 * void DYNINSTreportNewTags(void)
809 * inform the paradyn daemons of new message tags.
810 ************************************************************************/
813 DYNINSTreportNewTags(void) {
815 static int lastTagCount;
816 struct _newresource newRes;
818 for (i=lastTagCount; i < DYNINSTtagCount; i++) {
819 memset(&newRes, '\0', sizeof(newRes));
820 sprintf(newRes.name, "SyncObject/MsgTag/%d", DYNINSTtags[i]);
821 strcpy(newRes.abstraction, "BASE");
822 DYNINSTgenerateTraceRecord(0, TR_NEW_RESOURCE,
823 sizeof(struct _newresource), &newRes, 1);
825 lastTagCount = DYNINSTtagCount;
832 /************************************************************************
833 * void DYNINSTreportCounter(intCounter* counter)
835 * report value of counter to paradynd.
836 ************************************************************************/
839 DYNINSTreportCounter(intCounter* counter) {
842 sample.value = counter->value;
843 sample.id = counter->id;
844 DYNINSTtotalSamples++;
846 DYNINSTgenerateTraceRecord(0, TR_SAMPLE, sizeof(sample), &sample, 0);
853 /************************************************************************
854 * DYNINST test functions.
855 ************************************************************************/
857 void DYNINSTsimplePrint(void) {
858 printf("inside dynamic inst function\n");
861 void DYNINSTentryPrint(int arg) {
862 printf("enter %d\n", arg);
865 void DYNINSTcallFrom(int arg) {
866 printf("call from %d\n", arg);
869 void DYNINSTcallReturn(int arg) {
870 printf("return to %d\n", arg);
873 void DYNINSTexitPrint(int arg) {
874 printf("exit %d\n", arg);
881 /************************************************************************
882 * void DYNINSTreportCost(intCounter* counter)
884 * report the cost (from the cost model).
885 ************************************************************************/
888 DYNINSTreportCost(intCounter *counter) {
891 static double prev_cost = 0;
894 value = DYNINSTgetObservedCycles(1);
895 cost = ((double) value) * (DYNINSTcyclesToUsec / MILLION);
896 if (cost < prev_cost) {
897 fprintf(stderr, "Fatal Error: cost counter went backwards\n");
905 sample.id = counter->id;
906 DYNINSTtotalSamples++;
908 DYNINSTgenerateTraceRecord(0, TR_SAMPLE, sizeof sample, &sample, 0);