OILS / vendor / souffle / profile / ProfileEvent.h View on Github | oilshell.org

260 lines, 135 significant
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
39namespace souffle {
40
41/**
42 * Profile Event Singleton
43 */
44class ProfileEventSingleton {
45 /** profile database */
46 profile::ProfileDatabase database{};
47 std::string filename{""};
48
49 ProfileEventSingleton(){};
50
51public:
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
172private:
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