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