]> git.ipfire.org Git - thirdparty/squid.git/blame - src/ProfStats.cc
Portability fix: u_int*_t types are deprecated, replaced with uint*_t
[thirdparty/squid.git] / src / ProfStats.cc
CommitLineData
88bfe092 1
2/*
262a0e14 3 * $Id$
88bfe092 4 *
507d0a78 5 * DEBUG: section 81 CPU Profiling Routines
88bfe092 6 * AUTHOR: Andres Kroonmaa
7 *
8 * SQUID Internet Object Cache http://squid.nlanr.net/Squid/
9 * ----------------------------------------------------------
10 *
11 * Squid is the result of efforts by numerous individuals from the
12 * Internet community. Development is led by Duane Wessels of the
13 * National Laboratory for Applied Network Research and funded by the
14 * National Science Foundation. Squid is Copyrighted (C) 1998 by
15 * the Regents of the University of California. Please see the
16 * COPYRIGHT file for full details. Squid incorporates software
17 * developed and/or copyrighted by other sources. Please see the
18 * CREDITS file for full details.
19 *
20 * This program is free software; you can redistribute it and/or modify
21 * it under the terms of the GNU General Public License as published by
22 * the Free Software Foundation; either version 2 of the License, or
23 * (at your option) any later version.
26ac0430 24 *
88bfe092 25 * This program is distributed in the hope that it will be useful,
26 * but WITHOUT ANY WARRANTY; without even the implied warranty of
27 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
28 * GNU General Public License for more details.
26ac0430 29 *
88bfe092 30 * You should have received a copy of the GNU General Public License
31 * along with this program; if not, write to the Free Software
32 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
33 *
34 */
35
36#include "squid.h"
37
32d002cb 38#if USE_XPROF_STATS
a98bcbee
AJ
39
40#include "CacheManager.h"
41#include "event.h"
42#include "SquidMath.h"
e6ccf245 43#include "Store.h"
88bfe092 44
45/* Private stuff */
46
47#define MAX_SORTLIST 200
48
49static hrtime_t xprof_delta = 0;
50static hrtime_t xprof_start_t = 0;
51static hrtime_t xprof_verystart = 0;
52static hrtime_t xprof_average_delta = 0;
53static int xprof_events = 0;
54static int xprof_inited = 0;
55static xprof_stats_data Totals;
56
57static TimersArray *xprof_stats_avg1sec = NULL;
58static TimersArray *xprof_stats_avg5sec = NULL;
59static TimersArray *xprof_stats_avg30sec = NULL;
60static TimersArray *xprof_stats_avg1min = NULL;
61static TimersArray *xprof_stats_avg5min = NULL;
62static TimersArray *xprof_stats_avg30min = NULL;
63static TimersArray *xprof_stats_avg1hour = NULL;
64static TimersArray *xprof_stats_avg5hour = NULL;
65static TimersArray *xprof_stats_avg24hour = NULL;
66
67static xprof_stats_node *sortlist[XPROF_LAST + 2];
43ae1d95 68static void xprof_summary(StoreEntry * sentry);
88bfe092 69
70static void
71xprof_reset(xprof_stats_data * head)
72{
73 head->summ = 0;
74 head->count = 0;
75 head->delta = 0;
76 head->best = XP_NOBEST;
77 head->worst = 0;
78 head->start = 0;
79 head->stop = 0;
80}
81
82static void
83xprof_move(xprof_stats_data * head, xprof_stats_data * hist)
84{
85 memcpy(hist, head, sizeof(xprof_stats_data));
86}
87
88static int
89xprof_comp(xprof_stats_node ** ii, xprof_stats_node ** jj)
90{
91 if ((*ii)->hist.summ < (*jj)->hist.summ)
62e76326 92 return (1);
93
88bfe092 94 if ((*ii)->hist.summ > (*jj)->hist.summ)
62e76326 95 return (-1);
88bfe092 96
97 return (0);
98}
99
100static void
101xprof_sorthist(TimersArray * xprof_list)
102{
103 int i;
104
105 for (i = 0; i < XPROF_LAST; i++) {
62e76326 106 sortlist[i] = xprof_list[i];
88bfe092 107 }
62e76326 108
88bfe092 109 qsort(&sortlist[XPROF_hash_lookup], XPROF_LAST - XPROF_hash_lookup, sizeof(xprof_stats_node *), (QS *) xprof_comp);
110}
111
112static double time_frame;
113
114static void
115xprof_show_item(StoreEntry * sentry, const char *name, xprof_stats_data * hist)
116{
117 storeAppendPrintf(sentry,
e2b35d08 118 "%s\t %" PRIu64 "\t %" PRIu64 "\t %" PRIu64 "\t %" PRIu64 "\t %" PRIu64 "\t %.2f\t %6.3f\t\n",
62e76326 119 name,
120 hist->count,
121 hist->summ,
122 (hist->best != XP_NOBEST ? hist->best : 0),
123 hist->count ? hist->summ / hist->count : 0,
124 hist->worst,
125 hist->count / time_frame,
a98bcbee 126 Math::doublePercent((double) hist->summ, (double) hist->delta));
88bfe092 127}
128
129static void
43ae1d95 130xprof_summary_item(StoreEntry * sentry, char const *descr, TimersArray * list)
88bfe092 131{
132 int i;
133 xprof_stats_node **hist;
134 xprof_stats_data *show;
135 xprof_reset(&Totals);
136 xprof_sorthist(list);
137 hist = &sortlist[0];
138
139 show = &hist[0]->hist;
62e76326 140
88bfe092 141 if (!hist[0]->hist.delta)
62e76326 142 show = &hist[0]->accu;
88bfe092 143
144 time_frame = (double) show->delta / (double) xprof_average_delta;
145
146 storeAppendPrintf(sentry, "\n%s:", descr);
62e76326 147
e2b35d08 148 storeAppendPrintf(sentry, " (Cumulated time: %" PRIu64 ", %.2f sec)\n",
62e76326 149 show->delta,
150 time_frame
151 );
152
88bfe092 153 storeAppendPrintf(sentry,
62e76326 154 "Probe Name\t Events\t cumulated time \t best case \t average \t worst case\t Rate / sec \t %% in int\n");
88bfe092 155
156 for (i = 0; i < XPROF_LAST; i++) {
62e76326 157 if (!hist[i]->name)
158 continue;
159
160 show = &hist[i]->hist;
161
162 if (!show->count)
163 continue;
164
165 xprof_show_item(sentry, hist[i]->name, show);
166
167 Totals.count += show->count;
168
169 Totals.summ += show->summ;
170
171 Totals.best += (show->best != XP_NOBEST ? show->best : 0);
172
173 Totals.worst += show->worst;
174
175 Totals.delta = (show->delta > Totals.delta ? show->delta : Totals.delta);
88bfe092 176 }
62e76326 177
88bfe092 178 xprof_show_item(sentry, "TOTALS", &Totals);
179}
180
181static void
182xprof_average(TimersArray ** list, int secs)
183{
184 int i;
185 TimersArray *head = xprof_Timers;
186 TimersArray *hist;
187 hrtime_t now;
188 hrtime_t keep;
189 int doavg = (xprof_events % secs);
190
191 if (!*list)
62e76326 192 *list = (TimersArray *)xcalloc(XPROF_LAST, sizeof(xprof_stats_node));
88bfe092 193
194 hist = *list;
62e76326 195
88bfe092 196 now = get_tick();
197
198 for (i = 0; i < XPROF_LAST; i++) {
62e76326 199 hist[i]->name = head[i]->name;
200 hist[i]->accu.summ += head[i]->accu.summ;
201 hist[i]->accu.count += head[i]->accu.count; /* accumulate multisec */
202
203 if (!hist[i]->accu.best)
204 hist[i]->accu.best = head[i]->accu.best;
205
206 if (hist[i]->accu.best > head[i]->accu.best)
207 hist[i]->accu.best = head[i]->accu.best;
208
209 if (hist[i]->accu.worst < head[i]->accu.worst)
210 hist[i]->accu.worst = head[i]->accu.worst;
211
212 hist[i]->accu.delta += xprof_delta;
213
214 if (!doavg) {
215 /* we have X seconds accumulated */
216 xprof_move(&hist[i]->accu, &hist[i]->hist);
217 xprof_reset(&hist[i]->accu);
218
219 hist[i]->accu.start = now;
220 }
221
222 /* reset 0sec counters */
223 if (secs == 1) {
224 keep = head[i]->accu.start;
225 xprof_move(&head[i]->accu, &head[i]->hist);
226 xprof_reset(&head[i]->accu);
227 hist[i]->accu.delta = 0;
228 head[i]->accu.start = keep;
229 }
88bfe092 230 }
231}
232
233void
234xprof_summary(StoreEntry * sentry)
235{
236 hrtime_t now = get_tick();
237
238 storeAppendPrintf(sentry, "CPU Profiling Statistics:\n");
239 storeAppendPrintf(sentry,
62e76326 240 " (CPU times are in arbitrary units, most probably in CPU clock ticks)\n");
88bfe092 241 storeAppendPrintf(sentry,
62e76326 242 "Probe Name\t Event Count\t last Interval \t Avg Interval \t since squid start \t (since system boot) \n");
e2b35d08 243 storeAppendPrintf(sentry, "Total\t %lu\t %" PRIu64 " \t %" PRIu64 " \t %" PRIu64 " \t %" PRIu64 "\n",
62e76326 244 (long unsigned) xprof_events,
245 xprof_delta,
246 xprof_average_delta,
247 now - xprof_verystart,
248 now);
88bfe092 249
250 xprof_summary_item(sentry, "Last 1 sec averages", xprof_stats_avg1sec);
251 xprof_summary_item(sentry, "Last 5 sec averages", xprof_stats_avg5sec);
252 xprof_summary_item(sentry, "Last 30 sec averages", xprof_stats_avg30sec);
253 xprof_summary_item(sentry, "Last 1 min averages", xprof_stats_avg1min);
254 xprof_summary_item(sentry, "Last 5 min averages", xprof_stats_avg5min);
255 xprof_summary_item(sentry, "Last 30 min averages", xprof_stats_avg30min);
256 xprof_summary_item(sentry, "Last 1 hour averages", xprof_stats_avg1hour);
257 xprof_summary_item(sentry, "Last 5 hour averages", xprof_stats_avg5hour);
258 xprof_summary_item(sentry, "Last 24 hour averages", xprof_stats_avg24hour);
259}
260
261static inline void
262xprof_chk_overhead(int samples)
263{
264 while (samples--) {
62e76326 265 PROF_start(PROF_OVERHEAD);
266 PROF_stop(PROF_OVERHEAD);
88bfe092 267 }
268}
269
6b7d87bb
FC
270static void
271xprofRegisterWithCacheManager(void)
272{
273 CacheManager::GetInstance()->
26ac0430 274 registerAction("cpu_profile", "CPU Profiling Stats", xprof_summary, 0, 1);
6b7d87bb
FC
275}
276
26ac0430 277// FIXME:
6852be71
FC
278// this gets colled once per event. This doesn't seem to make much sense,
279// does it?
88bfe092 280static hrtime_t now;
281static void
282xprof_Init(void)
283{
284 if (xprof_inited)
62e76326 285 return;
88bfe092 286
287 xprof_delta = xprof_verystart = xprof_start_t = now;
288
289 xprof_inited = 1;
6852be71
FC
290
291 xprofRegisterWithCacheManager(); //moved here so it's not double-init'ed
62ee09ca 292}
62e76326 293
88bfe092 294void
295xprof_event(void *data)
296{
297 now = get_tick();
298 xprof_Init();
299 xprof_delta = now - xprof_start_t;
300 xprof_start_t = now;
301 xprof_events++;
302
303 if (!xprof_average_delta)
62e76326 304 xprof_average_delta = xprof_delta;
305
88bfe092 306 if (xprof_average_delta > (xprof_delta >> 1))
62e76326 307 xprof_average_delta = xprof_average_delta - (xprof_average_delta >> 8) + (xprof_delta >> 8);
88bfe092 308
88bfe092 309 xprof_chk_overhead(2);
62e76326 310
88bfe092 311 xprof_average(&xprof_stats_avg24hour, 24 * 3600);
62e76326 312
88bfe092 313 xprof_average(&xprof_stats_avg5hour, 5 * 3600);
62e76326 314
88bfe092 315 xprof_average(&xprof_stats_avg1hour, 3600);
62e76326 316
88bfe092 317 xprof_average(&xprof_stats_avg30min, 1800);
62e76326 318
88bfe092 319 xprof_average(&xprof_stats_avg5min, 300);
62e76326 320
88bfe092 321 xprof_average(&xprof_stats_avg1min, 60);
62e76326 322
88bfe092 323 xprof_average(&xprof_stats_avg30sec, 30);
62e76326 324
88bfe092 325 xprof_average(&xprof_stats_avg5sec, 5);
62e76326 326
88bfe092 327 xprof_average(&xprof_stats_avg1sec, 1);
62e76326 328
88bfe092 329 xprof_chk_overhead(30);
62e76326 330
88bfe092 331 eventAdd("cpuProfiling", xprof_event, NULL, 1.0, 1);
332}
333
334#endif /* USE_XPROF_STATS */