1 /*========================== begin_copyright_notice ============================
2
3 Copyright (C) 2017-2021 Intel Corporation
4
5 SPDX-License-Identifier: MIT
6
7 ============================= end_copyright_notice ===========================*/
8
9 #include "Option.h"
10 #include "Timer.h"
11
12 #include <iostream>
13 #include <fstream>
14 #include <string>
15 #ifdef _WIN32
16 #include "Windows.h"
17 #endif
18 #include <cassert>
19
20 #undef DEF_TIMER
21 #define DEF_TIMER(ENUM, DESCR) DESCR,
22 static const char* timerNames[static_cast<int>(TimerID::NUM_TIMERS)] =
23 {
24 #include "TimerDefs.h"
25 };
26
27 #ifdef MEASURE_COMPILATION_TIME
28
29 #define CLOCK_TYPE CLOCK_MONOTONIC
30
31 #if !defined(_WIN32)
QueryPerformanceFrequency(LARGE_INTEGER * lpFrequency)32 bool QueryPerformanceFrequency(LARGE_INTEGER *lpFrequency)
33 {
34 struct timespec Res;
35 INT iRet;
36
37 if ((iRet = clock_getres(CLOCK_TYPE, &Res)) != 0)
38 {
39 return ERROR;
40 }
41
42 // resolution (precision) can't be in seconds for current machine and OS
43 if (Res.tv_sec != 0)
44 {
45 return ERROR;
46 }
47 lpFrequency->QuadPart = 1000000000LL / Res.tv_nsec;
48
49 return SUCCEED;
50 }
51
QueryPerformanceCounter(LARGE_INTEGER * lpPerformanceCount)52 bool QueryPerformanceCounter(LARGE_INTEGER *lpPerformanceCount)
53 {
54 struct timespec Res;
55 struct timespec t;
56 INT iRet;
57
58 if ((iRet = clock_getres(CLOCK_TYPE, &Res)) != 0)
59 {
60 return ERROR;
61 }
62 if (Res.tv_sec != 0)
63 { // resolution (precision) can't be in seconds for current machine and OS
64 return ERROR;
65 }
66 if ((iRet = clock_gettime(CLOCK_TYPE, &t)) != 0)
67 {
68 return ERROR;
69 }
70 lpPerformanceCount->QuadPart = (1000000000LL * t.tv_sec +
71 t.tv_nsec) / Res.tv_nsec;
72
73 return SUCCEED;
74 }
75
76 #endif
77 #endif // MEASURE_COMPILATION_TIME
78
79
80 struct Timer {
81 double time;
82 LONGLONG currentStart;
83 const char* name;
84 LONGLONG ticks;
85 bool started;
86 unsigned int hits;
87 };
88
89 static _THREAD Timer timers[static_cast<int>(TimerID::NUM_TIMERS)];
90 static _THREAD LARGE_INTEGER proc_freq;
91 static _THREAD int numTimers = static_cast<int>(TimerID::NUM_TIMERS);
92
initTimer()93 void initTimer() {
94
95 #ifdef MEASURE_COMPILATION_TIME
96 numTimers = 0;
97 for (int i = 0; i < static_cast<int>(TimerID::NUM_TIMERS); i++)
98 {
99 timers[i].time = 0;
100 timers[i].currentStart = 0;
101 timers[i].name = NULL;
102 timers[i].ticks = 0;
103 timers[i].started = false;
104 timers[i].hits = 0;
105 createNewTimer(timerNames[i]);
106 }
107 QueryPerformanceFrequency(&proc_freq);
108 #endif
109 }
110
resetPerKernel()111 void resetPerKernel()
112 {
113 for (int i = 0; i < static_cast<int>(TimerID::NUM_TIMERS); i++)
114 {
115 TimerID ti = static_cast<TimerID>(i);
116 if (ti == TimerID::TOTAL ||
117 ti == TimerID::BUILDER ||
118 ti == TimerID::VISA_BUILDER_APPEND_INST ||
119 ti == TimerID::VISA_BUILDER_CREATE_VAR ||
120 ti == TimerID::VISA_BUILDER_CREATE_OPND ||
121 ti == TimerID::VISA_BUILDER_IR_CONSTRUCTION)
122 {
123 continue;
124 }
125 timers[i].time = 0;
126 timers[i].currentStart = 0;
127 timers[i].ticks = 0;
128 timers[i].started = false;
129 timers[i].hits = 0;
130 }
131 }
132
createNewTimer(const char * name)133 int createNewTimer(const char* name)
134 {
135 timers[numTimers].name = name;
136 return numTimers++;
137 }
138
startTimer(TimerID timerId)139 void startTimer(TimerID timerId)
140 {
141 int timer = static_cast<int>(timerId);
142 #ifdef MEASURE_COMPILATION_TIME
143 if (timer < static_cast<int>(TimerID::NUM_TIMERS))
144 {
145 #if defined(_DEBUG) && defined(CHECK_TIMER)
146 if (timers[timer].started)
147 {
148 std::cerr << "***********************************************\n";
149 std::cerr << "Timer already started.\n";
150 assert(false);
151 }
152 #endif
153 LARGE_INTEGER start;
154 QueryPerformanceCounter(&start);
155 timers[timer].currentStart= start.QuadPart;
156 timers[timer].hits++;
157 #if defined(_DEBUG) && defined(CHECK_TIMER)
158 timers[timer].started = true;
159 #endif
160 }
161 else
162 {
163 #ifdef _DEBUG
164 std::cerr << "***********************************************\n";
165 std::cerr << "Invalid index used when invoking startTimer\n";
166 #endif
167 }
168 #endif
169 }
170
stopTimer(TimerID timerId)171 void stopTimer(TimerID timerId)
172 {
173 int timer = static_cast<int>(timerId);
174 #ifdef MEASURE_COMPILATION_TIME
175 if (timer < static_cast<int>(TimerID::NUM_TIMERS))
176 {
177 LARGE_INTEGER stop;
178 QueryPerformanceCounter(&stop);
179 timers[timer].time += (stop.QuadPart - timers[timer].currentStart) / (double)proc_freq.QuadPart;
180 timers[timer].ticks += (stop.QuadPart - timers[timer].currentStart);
181 timers[timer].currentStart = 0;
182 #if defined(_DEBUG) && defined(CHECK_TIMER)
183 timers[timer].started = false;
184 #endif
185 }
186 else
187 {
188 #ifdef _DEBUG
189 std::cerr << "***********************************************\n";
190 std::cerr << "Invalid index used when invoking stopTimer\n";
191 #endif
192 }
193 #endif
194 }
195
getTotalTimers()196 extern "C" unsigned int getTotalTimers()
197 {
198 return numTimers;
199 }
200
getTimerCounts(unsigned int idx)201 extern "C" double getTimerCounts(unsigned int idx)
202 {
203 return timers[idx].time;
204 }
205
getTimerTicks(unsigned int idx)206 extern "C" int64_t getTimerTicks(unsigned int idx)
207 {
208 return timers[idx].ticks;
209 }
210
getTimerHits(unsigned int idx)211 extern "C" unsigned int getTimerHits(unsigned int idx)
212 {
213 return timers[idx].hits;
214 }
215
216 // static double getTimerUS(unsigned int idx)
217 // {
218 // return (timers[idx].ticks * 1000000) / (double)proc_freq.QuadPart;
219 // }
220
dumpAllTimers(const char * asmFileName,bool outputTime)221 void dumpAllTimers(const char *asmFileName, bool outputTime)
222 {
223 // This generates output like this:
224 // TIMER1 TIMER2 TIMER3 ...
225 // num1 num2 num3 ...
226 std::ofstream krnlOutput;
227 krnlOutput.open("jit_time.txt", std::ios_base::app);
228
229 double totalTime = timers[static_cast<int>(TimerID::TOTAL)].time;
230 for (unsigned int i = 0; i < getTotalTimers(); i++)
231 {
232 #ifndef TIME_BUILDER
233 TimerID ti = static_cast<TimerID>(i);
234 if (ti == TimerID::VISA_BUILDER_APPEND_INST ||
235 ti == TimerID::VISA_BUILDER_IR_CONSTRUCTION ||
236 ti == TimerID::VISA_BUILDER_CREATE_VAR ||
237 ti == TimerID::VISA_BUILDER_CREATE_OPND)
238 {
239 continue;
240 }
241 #endif
242 krnlOutput << std::left << std::setw(24) << timerNames[i] << "\t";
243 if (outputTime)
244 {
245 krnlOutput << std::left << std::setw(12) << std::setprecision(6) << timers[i].time << "\t";
246 }
247 else
248 {
249 krnlOutput << timers[i].ticks << "\t";
250 }
251 krnlOutput << std::setprecision(4) << (timers[i].time / totalTime * 100) << "%";
252 krnlOutput << "\n";
253 }
254
255 krnlOutput.close();
256
257 // Print timers like this:
258 // TIMER1:num1
259 // TIMER2:num2
260 // ...
261 std::ofstream timerFile;
262 std::stringstream ss;
263 ss << "timers." << asmFileName;
264 timerFile.open(ss.str(), std::ios_base::out);
265 for (unsigned i = 0, e = getTotalTimers(); i < e; i++) {
266 timerFile << timerNames[i] << ":";
267 if (outputTime) {
268 timerFile << timers[i].time << std::endl;
269 } else {
270 timerFile << timers[i].ticks << std::endl;
271 }
272 }
273 timerFile.close();
274 }
275