Made Boolean type RT_Boolean to prevent picking up a different boolean
[dyninst.git] / rtinst / src / RTunix.c
1 /*
2  * This file contains the implementation of runtime dynamic instrumentation
3  *   functions for a processor running UNIX.
4  *
5  * $Log: RTunix.c,v $
6  * Revision 1.22  1995/02/16 09:07:33  markc
7  * Made Boolean type RT_Boolean to prevent picking up a different boolean
8  * definition.
9  *
10  * Revision 1.21  1994/11/11  10:39:14  markc
11  * Commented out non-emergency printfs
12  *
13  * Revision 1.20  1994/10/09  21:26:05  hollings
14  * Fixed cycles to time conversion.
15  *
16  * Revision 1.19  1994/09/20  18:26:51  hollings
17  * added DYNINSTcyclesPerSecond to get cost values no matter the clock speed.
18  *
19  * removed a race condition in DYNINSTcyclesPerSecond.
20  *
21  * Revision 1.18  1994/08/22  16:05:37  markc
22  * Removed lastValue array.
23  * Added lastValue variable to timer structure.
24  * Added error messages for timer regression.
25  * Removed lastValue array.
26  * Added lastValue variable to timer structure.
27  * Added error messages for timer regression.
28  *
29  * Revision 1.17  1994/08/17  17:16:45  markc
30  * Increased the size of the lastValue and lastTime arrays.  lastValue is
31  * referenced by the timer id, which can be greater than 200.  There should
32  * be some way of enforcing a limit between paradynd and rtinst.
33  *
34  * Revision 1.16  1994/08/02  18:18:57  hollings
35  * added code to save/restore FP state on entry/exit to signal handle
36  * (really jcargill, but commited by hollings).
37  *
38  * changed comparisons on time regression to use 64 bit int compares rather
39  * than floats to prevent fp rounding error from causing false alarms.
40  *
41  * Revision 1.15  1994/07/26  20:04:48  hollings
42  * removed slots used variables.
43  *
44  * Revision 1.14  1994/07/22  19:24:54  hollings
45  * added actual paused time for CM-5.
46  *
47  * Revision 1.13  1994/07/16  03:39:31  hollings
48  * stopped using assembly version of clocks (temporary).
49  *
50  * Revision 1.12  1994/07/14  23:35:36  hollings
51  * added return of cost model record.
52  *
53  * Revision 1.11  1994/07/11  22:47:51  jcargill
54  * Major CM5 commit: include syntax changes, some timer changes, removal
55  * of old aggregation code, old pause code, added signal-driven sampling
56  * within node processes
57  *
58  * Revision 1.10  1994/07/05  03:25:11  hollings
59  * obsereved cost model.
60  *
61  * Revision 1.9  1994/05/18  00:53:28  hollings
62  * added flush's after error printfs to force data out pipes on the way
63  * to paradyn.
64  *
65  * Revision 1.8  1994/04/07  01:21:30  markc
66  * Cleaned up writes.  Writes interrupted by system calls get retried, others
67  * do not.
68  *
69  * Revision 1.7  1994/03/25  16:03:11  markc
70  * Added retry to write which could be interrupted by a signal.
71  *
72  * Revision 1.6  1994/02/16  00:07:24  hollings
73  * Added a default sampling interval of 500msec.  Previous default was not
74  * to collect any data.
75  *
76  * Revision 1.5  1994/02/02  00:46:14  hollings
77  * Changes to make it compile with the new tree.
78  *
79  * Revision 1.4  1993/12/13  19:48:12  hollings
80  * force records to be word aligned.
81  *
82  * Revision 1.3  1993/10/19  15:29:58  hollings
83  * new simpler primitives.
84  *
85  * Revision 1.2  1993/08/26  19:43:17  hollings
86  * added uarea mapping code.
87  *
88  * Revision 1.1  1993/07/02  21:49:35  hollings
89  * Initial revision
90  *
91  *
92  */
93 #include <stdio.h>
94 #include <string.h>
95 #include <sys/time.h>
96 #include <sys/resource.h>
97 #include <sys/param.h>
98 #include <signal.h>
99 #include <errno.h>
100 #include <fcntl.h>
101 #include <assert.h>
102 #include <nlist.h>
103 #include <unistd.h>
104
105 #include "kludges.h"
106 #include "rtinst/h/rtinst.h"
107 #include "rtinst/h/trace.h"
108
109 #define MILLION 1000000
110 extern int DYNINSTmappedUarea;
111 extern float DYNINSTcyclesToUsec;
112 extern int DYNINSTnumReported;
113 extern int DYNINSTtotalAlaramExpires;
114 extern int DYNINSTtotalSamples;
115 extern float DYNINSTsamplingRate;
116 extern time64 DYNINSTtotalSampleTime;
117 extern time64 DYNINSTlastCPUTime;
118 extern time64 DYNINSTlastWallTime;
119
120
121 FILE *DYNINSTtraceFp;
122 tTimer DYNINSTelapsedTime;
123 tTimer DYNINSTelapsedCPUTime;
124 int64 DYNINSTgetObservedCycles(RT_Boolean);
125 time64 DYNINSTtotalSampleTime;
126 int64 DYNINSTgetObservedCycles();
127
128 /* clockWord must be volatile becuase it changes on clock interrups. 
129  *    -- added volatile jkh 7/3/94
130  *
131  */
132 typedef volatile unsigned int clockWord;
133 extern clockWord *_p_1, *_p_2;
134
135 /*
136  * Missing stuff.
137  *
138  */
139 extern int getrusage(int who, struct rusage *rusage);
140
141 /*
142  * return cpuTime in useconds.
143  *
144  */
145 time64 DYNINSTgetCPUtime()
146 {
147      time64 now;
148      struct rusage ru;
149
150      getrusage(RUSAGE_SELF, &ru);
151      now = ru.ru_utime.tv_sec;
152      now *= MILLION;
153      now += ru.ru_utime.tv_usec;
154
155      return(now);
156 }
157
158 time64 DYNINSTgetWallTime()
159 {
160      time64 now;
161      struct timeval tv;
162
163      gettimeofday(&tv, NULL);
164      now = tv.tv_sec;
165      now *= (time64) MILLION;
166      now += tv.tv_usec;
167
168      return(now);
169 }
170
171 inline time64 DYNINSTgetUserTime()
172 {
173     int first;
174     time64 now;
175
176     if (DYNINSTmappedUarea) {
177 retry:
178          first = *_p_1;
179          now = first;
180          now *= MILLION;
181          now += *_p_2;
182          if (*_p_1 != first) goto retry;
183      } else {
184          now = DYNINSTgetCPUtime();
185      }
186      return(now);
187 }
188
189
190 void DYNINSTbreakPoint()
191 {
192 /*     printf ("Process %d about to stop self...\n", getpid()); */
193 /*     fflush (stdout); */
194     kill(getpid(), SIGSTOP);
195 /*     printf ("Process %d has been restarted...\n", getpid()); */
196 /*     fflush (stdout); */
197 }
198
199 void DYNINSTstartProcessTimer(tTimer *timer)
200 {
201     time64 temp;
202
203     if (timer->counter == 0) {
204          temp = DYNINSTgetUserTime();
205          timer->start = temp;
206          timer->normalize = MILLION;
207     }
208     /* this must be last to prevent race conditions */
209     timer->counter++;
210 }
211
212 void DYNINSTstopProcessTimer(tTimer *timer)
213 {
214     time64 now;
215     struct rusage ru;
216
217     /* don't stop a counter that is not running */
218     if (!timer->counter) return;
219
220
221     /* Warning - there is a window between setting now, and mutex that
222           can cause time to go backwards by the time to execute the
223           instructions between these two points.  This is not a cummlative error
224           and should not affect samples.  This was done (rather than re-sampling
225           now because the cost of computing now is so high).
226     */
227     if (timer->counter == 1) {
228         now = DYNINSTgetUserTime();
229         timer->snapShot = now - timer->start + timer->total;
230         timer->mutex = 1;
231         timer->counter = 0;
232         /* This next line can have the race condition. */
233         /* timer->total = timer->snapShot; */
234         timer->total = DYNINSTgetUserTime() - timer->start + timer->total;
235         timer->mutex = 0;
236         if (now < timer->start) {
237              getrusage(RUSAGE_SELF, &ru);
238              printf("end before start\n");
239              fflush(stdout);
240              sigpause(0xffff);
241         }
242     } else {
243         timer->counter--;
244     }
245 }
246
247
248 void DYNINSTstartWallTimer(tTimer *timer)
249 {
250     struct timeval tv;
251
252     if (timer->counter == 0) {
253          gettimeofday(&tv, NULL);
254          timer->start = tv.tv_sec;
255          timer->start *= (time64) MILLION;
256          timer->start += tv.tv_usec;
257          timer->normalize = MILLION;
258     }
259     /* this must be last to prevent race conditions */
260     timer->counter++;
261 }
262
263 void DYNINSTstopWallTimer(tTimer *timer)
264 {
265     time64 now;
266     struct timeval tv;
267
268     /* don't stop a counter that is not running */
269     if (!timer->counter) return;
270
271     if (timer->counter == 1) {
272          gettimeofday(&tv, NULL);
273          now = tv.tv_sec;
274          now *= MILLION;
275          now += tv.tv_usec;
276          /* see note before StopProcess time for warning about this mutex */
277          timer->snapShot = timer->total + now - timer->start;
278          timer->mutex = 1;
279          timer->counter = 0;
280          timer->total = timer->snapShot;
281          timer->mutex = 0;
282     } else {
283         timer->counter--;
284     }
285 }
286
287 time64 startWall;
288
289 volatile int DYNINSTpauseDone = 0;
290
291 /*
292  * change the variable to let the process proceed.
293  *
294  */
295 void DYNINSTcontinueProcess()
296 {
297     DYNINSTpauseDone = 1;
298 }
299
300 #ifdef notdef
301 int DYNINSTbufsiz;
302 int DYNINSTprofile;
303 #endif
304
305 /*
306  * pause the process and let only USR2 signal handlers run until a SIGUSR1.
307  *    arrives.
308  *
309  */
310 void DYNINSTpauseProcess()
311 {
312     int mask;
313     int sigs;
314
315     sigs = ((1 << (SIGUSR2-1)) | (1 << (SIGUSR1-1)) | (1 << (SIGTSTP-1)));
316     mask = ~sigs;
317     DYNINSTpauseDone = 0;
318     while (!DYNINSTpauseDone) {
319 #ifdef notdef
320        sigpause(mask);
321        /* temporary busy wait until we figure out what the TSD is up to.  */
322        printf("out of sigpuase\n");
323 #endif
324     }
325 }
326
327
328 void DYNINSTinit(int skipBreakpoint)
329 {
330     int val;
331     char *interval;
332     struct sigvec alarmVector;
333     extern int DYNINSTmapUarea();
334     extern float DYNINSTcyclesPerSecond();
335     extern void DYNINSTalarmExpire();
336
337     startWall = 0;
338
339     /*
340      * clear global base tramp and cycle counters.
341      *
342      */
343 #ifdef notdef
344     asm("mov 0, %g7");
345 #endif
346
347     /* init these before the first alarm can expire */
348     DYNINSTcyclesToUsec = (1.0/DYNINSTcyclesPerSecond()) * 1000000;
349     DYNINSTlastCPUTime = DYNINSTgetCPUtime();
350     DYNINSTlastWallTime = DYNINSTgetWallTime();
351
352     /* define the alarm signal vector. We block all signals while sampling.  
353      *  This prevents race conditions where signal handlers cause timers to 
354      *  be started and stopped.
355      */
356     alarmVector.sv_handler = DYNINSTalarmExpire;
357     alarmVector.sv_mask = ~0;
358     alarmVector.sv_flags = 0;
359
360     sigvec(SIGALRM, &alarmVector, NULL);
361
362     /* All the signal-initiating stuff is now in the paradynd. */
363
364     /* default is 500msec */
365     val = 500000;
366     interval = (char *) getenv("DYNINSTsampleInterval");
367     if (interval) {
368         val = atoi(interval);
369     }
370     DYNINSTsamplingRate = val/1000000.0;
371     sigvec(SIGALRM, &alarmVector, NULL);
372     ualarm(val, val);
373
374     DYNINSTmappedUarea = DYNINSTmapUarea();
375
376     /*
377      * pause the process and wait for additional info.
378      *
379      */
380     printf("Time at main %f\n", ((float) DYNINSTgetCPUtime())/1000000.0);
381     if (!skipBreakpoint) DYNINSTbreakPoint();
382
383     DYNINSTstartWallTimer(&DYNINSTelapsedTime);
384     DYNINSTstartProcessTimer(&DYNINSTelapsedCPUTime);
385
386 }
387
388
389 void DYNINSTexit()
390 {
391 }
392
393 static int pipeGone;
394
395 /*
396  * generate a trace record onto the named stream.
397  *
398  */
399 void DYNINSTgenerateTraceRecord(traceStream sid, short type, short length,
400     void *eventData, int flush)
401 {
402     int ret;
403     int count;
404     struct timeval tv;
405     char buffer[1024];
406     traceHeader header;
407
408     if (pipeGone) return;
409
410     gettimeofday(&tv, NULL);
411     header.wall = tv.tv_sec;
412     header.wall *= (time64) MILLION;
413     header.wall += tv.tv_usec;
414     header.wall -= startWall;
415
416 #ifdef notdef
417     if (DYNINSTmappedUarea) {
418         header.process = *_p_1;
419         header.process *= MILLION;
420         header.process += *_p_2;
421     } else {
422 #endif
423         header.process = DYNINSTgetCPUtime();
424 #ifdef notdef
425     }
426 #endif
427
428     /* round length off to a word aligned unit */
429     length = ALIGN_TO_WORDSIZE(length);
430
431     header.type = type;
432     header.length = length;
433     count = 0;
434     memcpy(&buffer[count], &sid, sizeof(traceStream));
435     count += sizeof(traceStream);
436
437     memcpy(&buffer[count], &header, sizeof(header));
438     count += sizeof(header);
439
440     count = ALIGN_TO_WORDSIZE(count);
441     memcpy(&buffer[count], eventData, length);
442     count += length;
443
444     /* on this platorm, we have a pipe to the controller process */
445     errno = 0;
446
447     if (!DYNINSTtraceFp || (type == TR_EXIT)) {
448         DYNINSTtraceFp = fdopen(dup(CONTROLLER_FD), "w");
449     }
450     ret = fwrite(buffer, count, 1, DYNINSTtraceFp);
451     if (ret != 1) {
452         extern char *sys_errlist[];
453         printf("unable to write trace record %s\n", sys_errlist[errno]);
454         printf("disabling further data logging, pid=%d\n", getpid());
455         fflush(stdout);
456         /* pipeGone = True; */
457     }
458     if (flush) DYNINSTflushTrace();
459 }
460
461 void DYNINSTflushTrace()
462 {
463     if (DYNINSTtraceFp) fflush(DYNINSTtraceFp);
464 }
465
466 /* time64 lastValue[10000]; */
467 double lastTime[200];
468
469 void DYNINSTreportTimer(tTimer *timer)
470 {
471     time64 now;
472     time64 total;
473     struct timeval tv;
474     traceSample sample;
475
476     if (timer->mutex) {
477         total = timer->snapShot;
478     } else if (timer->counter) {
479         /* timer is running */
480         if (timer->type == processTime) {
481             /* now = DYNINSTgetCPUtime(); */
482             /* use mapped time if available */
483             now = DYNINSTgetUserTime();
484         } else {
485             gettimeofday(&tv, NULL);
486             now = tv.tv_sec;
487             now *= MILLION;
488             now += tv.tv_usec;
489         }
490         total = now - timer->start + timer->total;
491     } else {
492         total = timer->total;
493     }
494     if (total < timer->lastValue) {
495          if (timer->type == processTime) {
496              printf("process ");
497          } else {
498              printf("wall ");
499          }
500          printf("time regressed timer %d, total = %f, last = %f\n",
501              timer->id.id, (float) total, (float) timer->lastValue);
502         if (timer->counter) {
503             printf("timer was active\n");
504         } else {
505             printf("timer was inactive\n");
506         }
507         printf("mutex=%d, counter=%d, sampled=%d, snapShot=%f\n\n",
508                (int)timer->mutex, (int)timer->counter, (int)timer->sampled,
509                (double) timer->snapShot);
510         printf("now = %f\n start = %f\n total = %f\n",
511                (double) now, (double) timer->start, (double) timer->total);
512         fflush(stdout);
513         sigpause(0xffff);
514     }
515     timer->lastValue = total;
516
517     sample.id = timer->id;
518     sample.value = ((double) total) / (double) timer->normalize;
519     DYNINSTtotalSamples++;
520
521     DYNINSTgenerateTraceRecord(0, TR_SAMPLE, sizeof(sample), &sample, 0);
522     /* printf("raw sample %d = %f\n", sample.id.id, sample.value); */
523 }
524
525 void DYNINSTfork(void *arg, int pid)
526 {
527     int sid = 0;
528     traceFork forkRec;
529
530     printf("fork called with pid = %d\n", pid);
531     fflush(stdout);
532     if (pid > 0) {
533         forkRec.ppid = getpid();
534         forkRec.pid = pid;
535         forkRec.npids = 1;
536         forkRec.stride = 0;
537         DYNINSTgenerateTraceRecord(sid,TR_FORK,sizeof(forkRec), &forkRec, 1);
538     } else {
539         /* set up signals and stop at a break point */
540         DYNINSTinit(1);
541         sigpause(0);
542     }
543 }
544
545
546 void DYNINSTprintCost()
547 {
548     FILE *fp;
549     time64 now;
550     int64 value;
551     struct rusage ru;
552     struct endStatsRec stats;
553
554     DYNINSTstopProcessTimer(&DYNINSTelapsedCPUTime);
555     DYNINSTstopWallTimer(&DYNINSTelapsedTime);
556
557     value = DYNINSTgetObservedCycles(0);
558     stats.instCycles = value;
559
560     value *= DYNINSTcyclesToUsec;
561
562     stats.alarms = DYNINSTtotalAlaramExpires;
563     stats.numReported = DYNINSTnumReported;
564     stats.instTime = ((double) value)/1000000.0;
565     stats.handlerCost = ((double) DYNINSTtotalSampleTime)/1000000.0;
566
567     now = DYNINSTgetCPUtime();
568     stats.totalCpuTime = ((double) DYNINSTelapsedCPUTime.total)/MILLION;
569     stats.totalWallTime = ((double) DYNINSTelapsedTime.total/MILLION);
570
571     stats.samplesReported = DYNINSTtotalSamples;
572     stats.samplingRate = DYNINSTsamplingRate;
573
574     stats.userTicks = 0;
575     stats.instTicks = 0;
576
577     fp = fopen("stats.out", "w");
578
579 #ifdef notdef
580     if (DYNINSTprofile) {
581         int i;
582         int limit;
583         int pageSize;
584         int startInst;
585         extern void DYNINSTreportCounter();
586
587
588         limit = DYNINSTbufsiz/sizeof(short);
589         /* should really be _DYNINSTendUserCode */
590         startInst = (int) &DYNINSTreportCounter;
591         fprintf(fp, "startInst = %x\n", startInst);
592         for (i=0; i < limit; i++) {
593             if (DYNINSTprofBuffer[i])
594                 fprintf(fp, "%x %d\n", i*2, DYNINSTprofBuffer[i]);
595             if (i * 2 > startInst) {
596                 stats.instTicks += DYNINSTprofBuffer[i];
597             } else {
598                 stats.userTicks += DYNINSTprofBuffer[i];
599             }
600         }
601
602         /* fwrite(DYNINSTprofBuffer, DYNINSTbufsiz, 1, fp); */
603         fprintf(fp, "stats.instTicks %d\n", stats.instTicks);
604         fprintf(fp, "stats.userTicks %d\n", stats.userTicks);
605
606     }
607 #endif
608     getrusage(RUSAGE_SELF, &ru);
609
610     fprintf(fp, "DYNINSTtotalAlaramExpires %d\n", stats.alarms);
611     fprintf(fp, "DYNINSTnumReported %d\n", stats.numReported);
612     fprintf(fp,"Raw cycle count = %f\n", (double) stats.instCycles);
613     fprintf(fp,"Total instrumentation cost = %f\n", stats.instTime);
614     fprintf(fp,"Total handler cost = %f\n", stats.handlerCost);
615     fprintf(fp,"Total cpu time of program %f\n", stats.totalCpuTime);
616     fprintf(fp,"Total system time of program %f\n", 
617          ru.ru_stime.tv_sec * 1000000.0 + ru.ru_stime.tv_usec);
618     fprintf(fp,"Elapsed wall time of program %f\n",
619         stats.totalWallTime/1000000.0);
620     fprintf(fp,"total data samples %d\n", stats.samplesReported);
621     fprintf(fp,"sampling rate %f\n", stats.samplingRate);
622     fprintf(fp,"Application program ticks %d\n", stats.userTicks);
623     fprintf(fp,"Instrumentation ticks %d\n", stats.instTicks);
624
625     fclose(fp);
626
627     /* record that we are done -- should be somewhere better. */
628     DYNINSTgenerateTraceRecord(0, TR_EXIT, sizeof(stats), &stats, 1);
629 }
630
631
632 /*
633  * These are null routines for Unix: signal handler semantics
634  * guarantee that the FPU state is saved/restored.  Not so on CM5 nodes! 
635  */
636
637 void saveFPUstate(float *base)
638 {
639 }
640
641
642 void restoreFPUstate(float *base)
643 {
644 }
645
646
647 /*
648  * If we can't read it, try to guess it.
649  */
650 static float guessClock()
651 {
652     return(0.0);
653 }
654
655 #define PATTERN "\tclock-frequency:"
656 /*
657  * find the number of cycles per second on this machine.
658  */
659 float DYNINSTcyclesPerSecond()
660 {
661     FILE *fp;
662     char *ptr;
663     int speed;
664     char line[80];
665
666     fp = popen("/usr/etc/devinfo -vp", "r");
667     if (!fp) {
668         /* can't run command so guess the clock rate. */
669     } else {
670         while (fgets(line, sizeof(line), fp)) {
671             if (!strncmp(PATTERN, line, strlen(PATTERN))) {
672                 ptr = strchr(line, ' ');
673                 if (!ptr) return(guessClock());
674                 speed = strtol(ptr, NULL, 16);
675                 break;
676             }
677         }
678     }
679     pclose(fp);
680     /* printf(line, "Clock = %d\n", speed); */
681     return(speed);
682 }