1 /* -*- c-basic-offset: 4 indent-tabs-mode: nil -*- vi:set ts=8 sts=4 sw=4: */
2
3 /*
4 Rosegarden
5 A MIDI and audio sequencer and musical notation editor.
6 Copyright 2000-2021 the Rosegarden development team.
7
8 Other copyrights also apply to some parts of this work. Please
9 see the AUTHORS file and individual file headers for details.
10
11 This program is free software; you can redistribute it and/or
12 modify it under the terms of the GNU General Public License as
13 published by the Free Software Foundation; either version 2 of the
14 License, or (at your option) any later version. See the file
15 COPYING included with this distribution for more information.
16 */
17
18 #include <iostream>
19 #include "Profiler.h"
20
21 #include <vector>
22 #include <algorithm>
23 #include <set>
24 #include <map>
25
26 #include <stdio.h>
27
28 using std::cerr;
29 using std::endl;
30
31 namespace Rosegarden {
32
33 Profiles* Profiles::m_instance = nullptr;
34
getInstance()35 Profiles* Profiles::getInstance()
36 {
37 if (!m_instance) m_instance = new Profiles();
38
39 return m_instance;
40 }
41
Profiles()42 Profiles::Profiles()
43 {
44 }
45
~Profiles()46 Profiles::~Profiles()
47 {
48 dump();
49 }
50
accumulate(const char * id,clock_t time,RealTime rt)51 void Profiles::accumulate(
52 #ifndef NO_TIMING
53 const char* id, clock_t time, RealTime rt
54 #else
55 const char*, clock_t, RealTime
56 #endif
57 )
58 {
59 #ifndef NO_TIMING
60 ProfilePair &pair(m_profiles[id]);
61 ++pair.first;
62 pair.second.first += time;
63 pair.second.second = pair.second.second + rt;
64
65 TimePair &lastPair(m_lastCalls[id]);
66 lastPair.first = time;
67 lastPair.second = rt;
68
69 TimePair &worstPair(m_worstCalls[id]);
70 if (time > worstPair.first) {
71 worstPair.first = time;
72 }
73 if (rt > worstPair.second) {
74 worstPair.second = rt;
75 }
76 #endif
77 }
78
dump() const79 void Profiles::dump() const
80 {
81 #ifndef NO_TIMING
82
83 fprintf(stderr, "Profiling points:\n");
84
85 fprintf(stderr, "\nBy name:\n");
86
87 typedef std::set<const char *, std::less<std::string> > StringSet;
88
89 StringSet profileNames;
90 for (ProfileMap::const_iterator i = m_profiles.begin();
91 i != m_profiles.end(); ++i) {
92 profileNames.insert(i->first);
93 }
94
95 for (StringSet::const_iterator i = profileNames.begin();
96 i != profileNames.end(); ++i) {
97
98 ProfileMap::const_iterator j = m_profiles.find(*i);
99
100 if (j == m_profiles.end()) continue;
101
102 const ProfilePair &pp(j->second);
103
104 fprintf(stderr, "%s(%d):\n", *i, pp.first);
105
106 fprintf(stderr, "\tCPU: \t%.9g ms/call \t[%d ms total]\n",
107 (((double)pp.second.first * 1000.0 /
108 (double)pp.first) / CLOCKS_PER_SEC),
109 int((pp.second.first * 1000.0) / CLOCKS_PER_SEC));
110
111 fprintf(stderr, "\tReal: \t%s ms \t[%s ms total]\n",
112 ((pp.second.second / pp.first) * 1000).toString().c_str(),
113 (pp.second.second * 1000).toString().c_str());
114
115 WorstCallMap::const_iterator k = m_worstCalls.find(*i);
116 if (k == m_worstCalls.end()) continue;
117
118 const TimePair &wc(k->second);
119
120 fprintf(stderr, "\tWorst:\t%s ms/call \t[%d ms CPU]\n",
121 (wc.second * 1000).toString().c_str(),
122 int((wc.first * 1000.0) / CLOCKS_PER_SEC));
123 }
124
125 typedef std::multimap<RealTime, const char *> TimeRMap;
126 typedef std::multimap<int, const char *> IntRMap;
127
128 TimeRMap totmap, avgmap, worstmap;
129 IntRMap ncallmap;
130
131 for (ProfileMap::const_iterator i = m_profiles.begin();
132 i != m_profiles.end(); ++i) {
133 totmap.insert(TimeRMap::value_type(i->second.second.second, i->first));
134 avgmap.insert(TimeRMap::value_type(i->second.second.second /
135 i->second.first, i->first));
136 ncallmap.insert(IntRMap::value_type(i->second.first, i->first));
137 }
138
139 for (WorstCallMap::const_iterator i = m_worstCalls.begin();
140 i != m_worstCalls.end(); ++i) {
141 worstmap.insert(TimeRMap::value_type(i->second.second,
142 i->first));
143 }
144
145
146 fprintf(stderr, "\nBy total:\n");
147 for (TimeRMap::const_iterator i = totmap.end(); i != totmap.begin(); ) {
148 --i;
149 fprintf(stderr, "%-40s %s ms\n", i->second,
150 (i->first * 1000).toString().c_str());
151 }
152
153 fprintf(stderr, "\nBy average:\n");
154 for (TimeRMap::const_iterator i = avgmap.end(); i != avgmap.begin(); ) {
155 --i;
156 fprintf(stderr, "%-40s %s ms\n", i->second,
157 (i->first * 1000).toString().c_str());
158 }
159
160 fprintf(stderr, "\nBy worst case:\n");
161 for (TimeRMap::const_iterator i = worstmap.end(); i != worstmap.begin(); ) {
162 --i;
163 fprintf(stderr, "%-40s %s ms\n", i->second,
164 (i->first * 1000).toString().c_str());
165 }
166
167 fprintf(stderr, "\nBy number of calls:\n");
168 for (IntRMap::const_iterator i = ncallmap.end(); i != ncallmap.begin(); ) {
169 --i;
170 fprintf(stderr, "%-40s %d\n", i->second, i->first);
171 }
172
173 #endif
174 }
175
176 #ifndef NO_TIMING
177
Profiler(const char * c,bool showOnDestruct)178 Profiler::Profiler(const char* c, bool showOnDestruct) :
179 m_c(c),
180 m_showOnDestruct(showOnDestruct),
181 m_ended(false)
182 {
183 m_startCPU = clock();
184
185 struct timeval tv;
186 (void)gettimeofday(&tv, nullptr);
187 m_startTime = RealTime::fromTimeval(tv);
188 }
189
190 void
update() const191 Profiler::update() const
192 {
193 clock_t elapsedCPU = clock() - m_startCPU;
194
195 struct timeval tv;
196 (void)gettimeofday(&tv, nullptr);
197 RealTime elapsedTime = RealTime::fromTimeval(tv) - m_startTime;
198
199 cerr << "Profiler : id = " << m_c
200 << " - elapsed so far = " << ((elapsedCPU * 1000) / CLOCKS_PER_SEC)
201 << "ms CPU, " << elapsedTime << " real" << endl;
202 }
203
~Profiler()204 Profiler::~Profiler()
205 {
206 if (!m_ended) end();
207 }
208
209 void
end()210 Profiler::end()
211 {
212 clock_t elapsedCPU = clock() - m_startCPU;
213
214 struct timeval tv;
215 (void)gettimeofday(&tv, nullptr);
216 RealTime elapsedTime = RealTime::fromTimeval(tv) - m_startTime;
217
218 Profiles::getInstance()->accumulate(m_c, elapsedCPU, elapsedTime);
219
220 if (m_showOnDestruct)
221 cerr << "Profiler : id = " << m_c
222 << " - elapsed = " << ((elapsedCPU * 1000) / CLOCKS_PER_SEC)
223 << "ms CPU, " << elapsedTime << " real" << endl;
224
225 m_ended = true;
226 }
227
228 #endif
229
230 }
231
232