1 | /*
|
2 | * Souffle - A Datalog Compiler
|
3 | * Copyright (c) 2018, The Souffle Developers. All rights reserved.
|
4 | * Licensed under the Universal Permissive License v 1.0 as shown at:
|
5 | * - https://opensource.org/licenses/UPL
|
6 | * - <souffle root>/licenses/SOUFFLE-UPL.txt
|
7 | */
|
8 |
|
9 | /************************************************************************
|
10 | *
|
11 | * @file ProfileEvent.h
|
12 | *
|
13 | * Declares classes for profile events
|
14 | *
|
15 | ***********************************************************************/
|
16 |
|
17 | #pragma once
|
18 |
|
19 | #include "souffle/profile/EventProcessor.h"
|
20 | #include "souffle/profile/ProfileDatabase.h"
|
21 | #include "souffle/utility/MiscUtil.h"
|
22 | #include <atomic>
|
23 | #include <chrono>
|
24 | #include <condition_variable>
|
25 | #include <cstdint>
|
26 | #include <ctime>
|
27 | #include <iostream>
|
28 | #include <mutex>
|
29 | #include <sstream>
|
30 | #include <string>
|
31 | #include <thread>
|
32 | #ifdef WIN32
|
33 | #include <Psapi.h>
|
34 | #else
|
35 | #include <sys/resource.h>
|
36 | #include <sys/time.h>
|
37 | #endif // WIN32
|
38 |
|
39 | namespace souffle {
|
40 |
|
41 | /**
|
42 | * Profile Event Singleton
|
43 | */
|
44 | class ProfileEventSingleton {
|
45 | /** profile database */
|
46 | profile::ProfileDatabase database{};
|
47 | std::string filename{""};
|
48 |
|
49 | ProfileEventSingleton(){};
|
50 |
|
51 | public:
|
52 | ~ProfileEventSingleton() {
|
53 | stopTimer();
|
54 | dump();
|
55 | }
|
56 |
|
57 | /** get instance */
|
58 | static ProfileEventSingleton& instance() {
|
59 | static std::unique_ptr<ProfileEventSingleton> singleton(new ProfileEventSingleton);
|
60 | return *singleton;
|
61 | }
|
62 |
|
63 | /** create config record */
|
64 | void makeConfigRecord(const std::string& key, const std::string& value) {
|
65 | profile::EventProcessorSingleton::instance().process(database, "@config", key.c_str(), value.c_str());
|
66 | }
|
67 |
|
68 | /** create time event */
|
69 | void makeTimeEvent(const std::string& txt) {
|
70 | profile::EventProcessorSingleton::instance().process(
|
71 | database, txt.c_str(), std::chrono::duration_cast<microseconds>(now().time_since_epoch()));
|
72 | }
|
73 |
|
74 | /** create an event for recording start and end times */
|
75 | void makeTimingEvent(const std::string& txt, time_point start, time_point end, std::size_t startMaxRSS,
|
76 | std::size_t endMaxRSS, std::size_t size, std::size_t iteration) {
|
77 | microseconds start_ms = std::chrono::duration_cast<microseconds>(start.time_since_epoch());
|
78 | microseconds end_ms = std::chrono::duration_cast<microseconds>(end.time_since_epoch());
|
79 | profile::EventProcessorSingleton::instance().process(
|
80 | database, txt.c_str(), start_ms, end_ms, startMaxRSS, endMaxRSS, size, iteration);
|
81 | }
|
82 |
|
83 | /** create quantity event */
|
84 | void makeQuantityEvent(const std::string& txt, std::size_t number, int iteration) {
|
85 | profile::EventProcessorSingleton::instance().process(database, txt.c_str(), number, iteration);
|
86 | }
|
87 |
|
88 | void makeNonRecursiveCountEvent(const std::string& txt, double joinSize) {
|
89 | profile::EventProcessorSingleton::instance().process(database, txt.c_str(), joinSize);
|
90 | }
|
91 |
|
92 | void makeRecursiveCountEvent(const std::string& txt, double joinSize, std::size_t iteration) {
|
93 | profile::EventProcessorSingleton::instance().process(database, txt.c_str(), joinSize, iteration);
|
94 | }
|
95 |
|
96 | /** create utilisation event */
|
97 | void makeUtilisationEvent(const std::string& txt) {
|
98 | /* current time */
|
99 | microseconds time = std::chrono::duration_cast<microseconds>(now().time_since_epoch());
|
100 |
|
101 | #ifdef WIN32
|
102 | HANDLE hProcess = GetCurrentProcess();
|
103 | FILETIME systemFileTime, userFileTime;
|
104 | GetProcessTimes(hProcess, nullptr, nullptr, &systemFileTime, &userFileTime);
|
105 | /* system CPU time and user CPU time are both expected to be in
|
106 | microseconds below, GetProcessTime gives us a value which is a
|
107 | counter of 100 nanosecond units. */
|
108 | /* system CPU time used */
|
109 | uint64_t systemTime = systemFileTime.dwHighDateTime;
|
110 | systemTime = (systemTime << 32) | systemFileTime.dwLowDateTime;
|
111 | systemTime /= 1000;
|
112 | /* user CPU time used */
|
113 | uint64_t userTime = userFileTime.dwHighDateTime;
|
114 | userTime = (userTime << 32) | userFileTime.dwLowDateTime;
|
115 | userTime /= 1000;
|
116 | PROCESS_MEMORY_COUNTERS processMemoryCounters;
|
117 | GetProcessMemoryInfo(hProcess, &processMemoryCounters, sizeof(processMemoryCounters));
|
118 | /* Maximum resident set size (kb) */
|
119 | std::size_t maxRSS = processMemoryCounters.PeakWorkingSetSize / 1000;
|
120 | #else
|
121 | /* system CPU time used */
|
122 | struct rusage ru {};
|
123 | getrusage(RUSAGE_SELF, &ru);
|
124 | /* system CPU time used */
|
125 | uint64_t systemTime = ru.ru_stime.tv_sec * 1000000 + ru.ru_stime.tv_usec;
|
126 | /* user CPU time used */
|
127 | uint64_t userTime = ru.ru_utime.tv_sec * 1000000 + ru.ru_utime.tv_usec;
|
128 | /* Maximum resident set size (kb) */
|
129 | std::size_t maxRSS = ru.ru_maxrss;
|
130 | #endif // WIN32
|
131 |
|
132 | profile::EventProcessorSingleton::instance().process(
|
133 | database, txt.c_str(), time, systemTime, userTime, maxRSS);
|
134 | }
|
135 |
|
136 | void setOutputFile(std::string outputFilename) {
|
137 | filename = outputFilename;
|
138 | }
|
139 | /** Dump all events */
|
140 | void dump() {
|
141 | if (!filename.empty()) {
|
142 | std::ofstream os(filename);
|
143 | if (!os.is_open()) {
|
144 | std::cerr << "Cannot open profile log file <" + filename + ">";
|
145 | } else {
|
146 | database.print(os);
|
147 | }
|
148 | }
|
149 | }
|
150 |
|
151 | /** Start timer */
|
152 | void startTimer() {
|
153 | timer.start();
|
154 | }
|
155 |
|
156 | /** Stop timer */
|
157 | void stopTimer() {
|
158 | timer.stop();
|
159 | }
|
160 |
|
161 | void resetTimerInterval(uint32_t interval = 1) {
|
162 | timer.resetTimerInterval(interval);
|
163 | }
|
164 | const profile::ProfileDatabase& getDB() const {
|
165 | return database;
|
166 | }
|
167 |
|
168 | void setDBFromFile(const std::string& databaseFilename) {
|
169 | database = profile::ProfileDatabase(databaseFilename);
|
170 | }
|
171 |
|
172 | private:
|
173 | /** Profile Timer */
|
174 | class ProfileTimer {
|
175 | private:
|
176 | /** time interval between per utilisation read */
|
177 | uint32_t t;
|
178 |
|
179 | /** timer is running */
|
180 | std::atomic<bool> running{false};
|
181 |
|
182 | /** thread timer runs on */
|
183 | std::thread th;
|
184 |
|
185 | std::condition_variable conditionVariable;
|
186 | std::mutex timerMutex;
|
187 |
|
188 | /** number of utilisation events */
|
189 | std::atomic<uint32_t> runCount{0};
|
190 |
|
191 | /** run method for thread th */
|
192 | void run() {
|
193 | ProfileEventSingleton::instance().makeUtilisationEvent("@utilisation");
|
194 | ++runCount;
|
195 | if (runCount % 128 == 0) {
|
196 | increaseInterval();
|
197 | }
|
198 | }
|
199 |
|
200 | uint32_t getInterval() {
|
201 | return t;
|
202 | }
|
203 |
|
204 | /** Increase value of time interval by factor of 2 */
|
205 | void increaseInterval() {
|
206 | // Don't increase time interval past 60 seconds
|
207 | if (t < 60000) {
|
208 | t = t * 2;
|
209 | }
|
210 | }
|
211 |
|
212 | public:
|
213 | /*
|
214 | * @param interval the size of the timing interval in milliseconds
|
215 | */
|
216 | ProfileTimer(uint32_t interval = 10) : t(interval) {}
|
217 |
|
218 | /** start timer on the thread th */
|
219 | void start() {
|
220 | if (running) {
|
221 | return;
|
222 | }
|
223 | running = true;
|
224 |
|
225 | th = std::thread([this]() {
|
226 | while (running) {
|
227 | run();
|
228 | std::unique_lock<std::mutex> lock(timerMutex);
|
229 | conditionVariable.wait_for(lock, std::chrono::milliseconds(getInterval()));
|
230 | }
|
231 | });
|
232 | }
|
233 |
|
234 | /** stop timer on the thread th */
|
235 | void stop() {
|
236 | running = false;
|
237 | conditionVariable.notify_all();
|
238 | if (th.joinable()) {
|
239 | th.join();
|
240 | }
|
241 | }
|
242 |
|
243 | /** Reset timer interval.
|
244 | *
|
245 | * The timer interval increases as the program executes. Resetting the interval is useful to
|
246 | * ensure that detailed usage information is gathered even in long running programs, if desired.
|
247 | *
|
248 | * @param interval the size of the timing interval in milliseconds
|
249 | */
|
250 | void resetTimerInterval(uint32_t interval = 10) {
|
251 | t = interval;
|
252 | runCount = 0;
|
253 | conditionVariable.notify_all();
|
254 | }
|
255 | };
|
256 |
|
257 | ProfileTimer timer;
|
258 | };
|
259 |
|
260 | } // namespace souffle
|