|
| 1 | +/* |
| 2 | + *pg_test_timing.c |
| 3 | + *tests overhead of timing calls and their monotonicity: that |
| 4 | + * they always move forward |
| 5 | + */ |
| 6 | + |
| 7 | +#include"postgres_fe.h" |
| 8 | + |
| 9 | +#include"getopt_long.h" |
| 10 | +#include"portability/instr_time.h" |
| 11 | + |
| 12 | +staticconstchar*progname; |
| 13 | + |
| 14 | +staticint32test_duration=3; |
| 15 | + |
| 16 | +staticvoidhandle_args(intargc,char*argv[]); |
| 17 | +staticvoidtest_timing(int32); |
| 18 | + |
| 19 | +int |
| 20 | +main(intargc,char*argv[]) |
| 21 | +{ |
| 22 | +progname=get_progname(argv[0]); |
| 23 | + |
| 24 | +handle_args(argc,argv); |
| 25 | + |
| 26 | +test_timing(test_duration); |
| 27 | + |
| 28 | +return0; |
| 29 | +} |
| 30 | + |
| 31 | +staticvoid |
| 32 | +handle_args(intargc,char*argv[]) |
| 33 | +{ |
| 34 | +staticstructoptionlong_options[]= { |
| 35 | +{"duration",required_argument,NULL,'d'}, |
| 36 | +{NULL,0,NULL,0} |
| 37 | +}; |
| 38 | +intoption;/* Command line option */ |
| 39 | +intoptindex=0;/* used by getopt_long */ |
| 40 | + |
| 41 | +if (argc>1) |
| 42 | +{ |
| 43 | +if (strcmp(argv[1],"--help")==0||strcmp(argv[1],"-h")==0|| |
| 44 | +strcmp(argv[1],"-?")==0) |
| 45 | +{ |
| 46 | +printf("Usage: %s [-d DURATION]\n",progname); |
| 47 | +exit(0); |
| 48 | +} |
| 49 | +if (strcmp(argv[1],"--version")==0||strcmp(argv[1],"-V")==0) |
| 50 | +{ |
| 51 | +puts("pg_test_timing (PostgreSQL) "PG_VERSION); |
| 52 | +exit(0); |
| 53 | +} |
| 54 | +} |
| 55 | + |
| 56 | +while ((option=getopt_long(argc,argv,"d:", |
| 57 | +long_options,&optindex))!=-1) |
| 58 | +{ |
| 59 | +switch (option) |
| 60 | +{ |
| 61 | +case'd': |
| 62 | +test_duration=atoi(optarg); |
| 63 | +break; |
| 64 | + |
| 65 | +default: |
| 66 | +fprintf(stderr,"Try \"%s --help\" for more information.\n", |
| 67 | +progname); |
| 68 | +exit(1); |
| 69 | +break; |
| 70 | +} |
| 71 | +} |
| 72 | + |
| 73 | +if (argc>optind) |
| 74 | +{ |
| 75 | +fprintf(stderr, |
| 76 | +"%s: too many command-line arguments (first is \"%s\")\n", |
| 77 | +progname,argv[optind]); |
| 78 | +fprintf(stderr,"Try \"%s --help\" for more information.\n", |
| 79 | +progname); |
| 80 | +exit(1); |
| 81 | +} |
| 82 | + |
| 83 | +if (test_duration>0) |
| 84 | +{ |
| 85 | +printf("Testing timing overhead for %d seconds.\n",test_duration); |
| 86 | +} |
| 87 | +else |
| 88 | +{ |
| 89 | +fprintf(stderr, |
| 90 | +"%s: duration must be a positive integer (duration is \"%d\")\n", |
| 91 | +progname,test_duration); |
| 92 | +fprintf(stderr,"Try \"%s --help\" for more information.\n", |
| 93 | +progname); |
| 94 | +exit(1); |
| 95 | +} |
| 96 | +} |
| 97 | + |
| 98 | +staticvoid |
| 99 | +test_timing(int32duration) |
| 100 | +{ |
| 101 | +uint64total_time; |
| 102 | +int64time_elapsed=0; |
| 103 | +uint64loop_count=0; |
| 104 | +uint64prev,cur; |
| 105 | +int32diff,i,bits,found; |
| 106 | + |
| 107 | +instr_timestart_time,end_time,temp; |
| 108 | + |
| 109 | +staticint64histogram[32]; |
| 110 | + |
| 111 | +total_time=duration>0 ?duration*1000000 :0; |
| 112 | + |
| 113 | +INSTR_TIME_SET_CURRENT(start_time); |
| 114 | +cur=INSTR_TIME_GET_MICROSEC(start_time); |
| 115 | + |
| 116 | +while (time_elapsed<total_time) |
| 117 | +{ |
| 118 | +prev=cur; |
| 119 | +INSTR_TIME_SET_CURRENT(temp); |
| 120 | +cur=INSTR_TIME_GET_MICROSEC(temp); |
| 121 | +diff=cur-prev; |
| 122 | + |
| 123 | +if (diff<0) |
| 124 | +{ |
| 125 | +printf("Detected clock going backwards in time.\n"); |
| 126 | +printf("Time warp: %d microseconds\n",diff); |
| 127 | +exit(1); |
| 128 | +} |
| 129 | + |
| 130 | +bits=0; |
| 131 | +while (diff) |
| 132 | +{ |
| 133 | +diff >>=1; |
| 134 | +bits++; |
| 135 | +} |
| 136 | +histogram[bits]++; |
| 137 | + |
| 138 | +loop_count++; |
| 139 | +INSTR_TIME_SUBTRACT(temp,start_time); |
| 140 | +time_elapsed=INSTR_TIME_GET_MICROSEC(temp); |
| 141 | +} |
| 142 | + |
| 143 | +INSTR_TIME_SET_CURRENT(end_time); |
| 144 | + |
| 145 | +INSTR_TIME_SUBTRACT(end_time,start_time); |
| 146 | + |
| 147 | +printf("Per loop time including overhead: %0.2f nsec\n", |
| 148 | +INSTR_TIME_GET_DOUBLE(end_time)*1e9 /loop_count); |
| 149 | +printf("Histogram of timing durations:\n"); |
| 150 | +printf("%9s: %10s %9s\n","< usec","count","percent"); |
| 151 | + |
| 152 | +found=0; |
| 153 | +for (i=31;i >=0;i--) |
| 154 | + { |
| 155 | +if (found||histogram[i]) |
| 156 | + { |
| 157 | +found=1; |
| 158 | +printf("%9ld: %10ld %8.5f%%\n",1l <<i,histogram[i], |
| 159 | + (double)histogram[i]*100 /loop_count); |
| 160 | + } |
| 161 | + } |
| 162 | +} |