]> git.ipfire.org Git - thirdparty/squid.git/blob - src/stat.cc
1cee649c13b75a1d51ac9e9cf283a50628d114f6
[thirdparty/squid.git] / src / stat.cc
1 /*
2 * Copyright (C) 1996-2019 The Squid Software Foundation and contributors
3 *
4 * Squid software is distributed under GPLv2+ license and includes
5 * contributions from numerous individuals and organizations.
6 * Please see the COPYING and CONTRIBUTORS files for details.
7 */
8
9 /* DEBUG: section 18 Cache Manager Statistics */
10
11 #include "squid.h"
12 #include "CacheDigest.h"
13 #include "CachePeer.h"
14 #include "client_side.h"
15 #include "client_side_request.h"
16 #include "comm/Connection.h"
17 #include "comm/Loops.h"
18 #include "event.h"
19 #include "fde.h"
20 #include "format/Token.h"
21 #include "globals.h"
22 #include "http/Stream.h"
23 #include "HttpRequest.h"
24 #include "IoStats.h"
25 #include "mem/Pool.h"
26 #include "mem_node.h"
27 #include "MemBuf.h"
28 #include "MemObject.h"
29 #include "mgr/CountersAction.h"
30 #include "mgr/FunAction.h"
31 #include "mgr/InfoAction.h"
32 #include "mgr/IntervalAction.h"
33 #include "mgr/IoAction.h"
34 #include "mgr/Registration.h"
35 #include "mgr/ServiceTimesAction.h"
36 #include "neighbors.h"
37 #include "PeerDigest.h"
38 #include "SquidConfig.h"
39 #include "SquidMath.h"
40 #include "SquidTime.h"
41 #include "stat.h"
42 #include "StatCounters.h"
43 #include "Store.h"
44 #include "store_digest.h"
45 #include "StoreClient.h"
46 #include "tools.h"
47 // for tvSubDsec() which should be in SquidTime.h
48 #include "util.h"
49 #if USE_AUTH
50 #include "auth/UserRequest.h"
51 #endif
52 #if USE_DELAY_POOLS
53 #include "DelayId.h"
54 #endif
55 #if USE_OPENSSL
56 #include "ssl/support.h"
57 #endif
58
59 /* these are included because they expose stats calls */
60 /* TODO: provide a self registration mechanism for those classes
61 * to use during static construction
62 */
63 #include "comm.h"
64 #include "StoreSearch.h"
65
66 #define DEBUG_OPENFD 1
67
68 typedef int STOBJFLT(const StoreEntry *);
69
70 class StatObjectsState
71 {
72 CBDATA_CLASS(StatObjectsState);
73
74 public:
75 StoreEntry *sentry;
76 STOBJFLT *filter;
77 StoreSearchPointer theSearch;
78 };
79
80 /* LOCALS */
81 static const char *describeStatuses(const StoreEntry *);
82 static void statAvgTick(void *notused);
83 static void statAvgDump(StoreEntry *, int minutes, int hours);
84 #if STAT_GRAPHS
85 static void statGraphDump(StoreEntry *);
86 #endif
87 static double statPctileSvc(double, int, int);
88 static void statStoreEntry(MemBuf * mb, StoreEntry * e);
89 static double statCPUUsage(int minutes);
90 static OBJH stat_objects_get;
91 static OBJH stat_vmobjects_get;
92 #if DEBUG_OPENFD
93 static OBJH statOpenfdObj;
94 #endif
95 static EVH statObjects;
96 static OBJH statCountersDump;
97 static OBJH statPeerSelect;
98 static OBJH statDigestBlob;
99 static OBJH statUtilization;
100 static OBJH statCountersHistograms;
101 static OBJH statClientRequests;
102 void GetAvgStat(Mgr::IntervalActionData& stats, int minutes, int hours);
103 void DumpAvgStat(Mgr::IntervalActionData& stats, StoreEntry* sentry);
104 void GetInfo(Mgr::InfoActionData& stats);
105 void DumpInfo(Mgr::InfoActionData& stats, StoreEntry* sentry);
106 void DumpMallocStatistics(StoreEntry* sentry);
107 void GetCountersStats(Mgr::CountersActionData& stats);
108 void DumpCountersStats(Mgr::CountersActionData& stats, StoreEntry* sentry);
109 void GetServiceTimesStats(Mgr::ServiceTimesActionData& stats);
110 void DumpServiceTimesStats(Mgr::ServiceTimesActionData& stats, StoreEntry* sentry);
111 void GetIoStats(Mgr::IoActionData& stats);
112 void DumpIoStats(Mgr::IoActionData& stats, StoreEntry* sentry);
113
114 #if XMALLOC_STATISTICS
115 static void info_get_mallstat(int, int, int, void *);
116 static double xm_time;
117 static double xm_deltat;
118 #endif
119
120 StatCounters CountHist[N_COUNT_HIST];
121 static int NCountHist = 0;
122 static StatCounters CountHourHist[N_COUNT_HOUR_HIST];
123 static int NCountHourHist = 0;
124 CBDATA_CLASS_INIT(StatObjectsState);
125
126 extern unsigned int mem_pool_alloc_calls;
127 extern unsigned int mem_pool_free_calls;
128
129 static void
130 statUtilization(StoreEntry * e)
131 {
132 storeAppendPrintf(e, "Cache Utilisation:\n");
133 storeAppendPrintf(e, "\n");
134 storeAppendPrintf(e, "Last 5 minutes:\n");
135
136 if (NCountHist >= 5)
137 statAvgDump(e, 5, 0);
138 else
139 storeAppendPrintf(e, "(no values recorded yet)\n");
140
141 storeAppendPrintf(e, "\n");
142
143 storeAppendPrintf(e, "Last 15 minutes:\n");
144
145 if (NCountHist >= 15)
146 statAvgDump(e, 15, 0);
147 else
148 storeAppendPrintf(e, "(no values recorded yet)\n");
149
150 storeAppendPrintf(e, "\n");
151
152 storeAppendPrintf(e, "Last hour:\n");
153
154 if (NCountHist >= 60)
155 statAvgDump(e, 60, 0);
156 else
157 storeAppendPrintf(e, "(no values recorded yet)\n");
158
159 storeAppendPrintf(e, "\n");
160
161 storeAppendPrintf(e, "Last 8 hours:\n");
162
163 if (NCountHourHist >= 8)
164 statAvgDump(e, 0, 8);
165 else
166 storeAppendPrintf(e, "(no values recorded yet)\n");
167
168 storeAppendPrintf(e, "\n");
169
170 storeAppendPrintf(e, "Last day:\n");
171
172 if (NCountHourHist >= 24)
173 statAvgDump(e, 0, 24);
174 else
175 storeAppendPrintf(e, "(no values recorded yet)\n");
176
177 storeAppendPrintf(e, "\n");
178
179 storeAppendPrintf(e, "Last 3 days:\n");
180
181 if (NCountHourHist >= 72)
182 statAvgDump(e, 0, 72);
183 else
184 storeAppendPrintf(e, "(no values recorded yet)\n");
185
186 storeAppendPrintf(e, "\n");
187
188 storeAppendPrintf(e, "Totals since cache startup:\n");
189
190 statCountersDump(e);
191 }
192
193 void
194 GetIoStats(Mgr::IoActionData& stats)
195 {
196 int i;
197
198 stats.http_reads = IOStats.Http.reads;
199
200 for (i = 0; i < IoStats::histSize; ++i) {
201 stats.http_read_hist[i] = IOStats.Http.read_hist[i];
202 }
203
204 stats.ftp_reads = IOStats.Ftp.reads;
205
206 for (i = 0; i < IoStats::histSize; ++i) {
207 stats.ftp_read_hist[i] = IOStats.Ftp.read_hist[i];
208 }
209
210 stats.gopher_reads = IOStats.Gopher.reads;
211
212 for (i = 0; i < IoStats::histSize; ++i) {
213 stats.gopher_read_hist[i] = IOStats.Gopher.read_hist[i];
214 }
215 }
216
217 void
218 DumpIoStats(Mgr::IoActionData& stats, StoreEntry* sentry)
219 {
220 int i;
221
222 storeAppendPrintf(sentry, "HTTP I/O\n");
223 storeAppendPrintf(sentry, "number of reads: %.0f\n", stats.http_reads);
224 storeAppendPrintf(sentry, "Read Histogram:\n");
225
226 for (i = 0; i < IoStats::histSize; ++i) {
227 storeAppendPrintf(sentry, "%5d-%5d: %9.0f %2.0f%%\n",
228 i ? (1 << (i - 1)) + 1 : 1,
229 1 << i,
230 stats.http_read_hist[i],
231 Math::doublePercent(stats.http_read_hist[i], stats.http_reads));
232 }
233
234 storeAppendPrintf(sentry, "\n");
235 storeAppendPrintf(sentry, "FTP I/O\n");
236 storeAppendPrintf(sentry, "number of reads: %.0f\n", stats.ftp_reads);
237 storeAppendPrintf(sentry, "Read Histogram:\n");
238
239 for (i = 0; i < IoStats::histSize; ++i) {
240 storeAppendPrintf(sentry, "%5d-%5d: %9.0f %2.0f%%\n",
241 i ? (1 << (i - 1)) + 1 : 1,
242 1 << i,
243 stats.ftp_read_hist[i],
244 Math::doublePercent(stats.ftp_read_hist[i], stats.ftp_reads));
245 }
246
247 storeAppendPrintf(sentry, "\n");
248 storeAppendPrintf(sentry, "Gopher I/O\n");
249 storeAppendPrintf(sentry, "number of reads: %.0f\n", stats.gopher_reads);
250 storeAppendPrintf(sentry, "Read Histogram:\n");
251
252 for (i = 0; i < IoStats::histSize; ++i) {
253 storeAppendPrintf(sentry, "%5d-%5d: %9.0f %2.0f%%\n",
254 i ? (1 << (i - 1)) + 1 : 1,
255 1 << i,
256 stats.gopher_read_hist[i],
257 Math::doublePercent(stats.gopher_read_hist[i], stats.gopher_reads));
258 }
259
260 storeAppendPrintf(sentry, "\n");
261 }
262
263 static const char *
264 describeStatuses(const StoreEntry * entry)
265 {
266 LOCAL_ARRAY(char, buf, 256);
267 snprintf(buf, 256, "%-13s %-13s %-12s %-12s",
268 storeStatusStr[entry->store_status],
269 memStatusStr[entry->mem_status],
270 swapStatusStr[entry->swap_status],
271 pingStatusStr[entry->ping_status]);
272 return buf;
273 }
274
275 const char *
276 storeEntryFlags(const StoreEntry * entry)
277 {
278 LOCAL_ARRAY(char, buf, 256);
279 int flags = (int) entry->flags;
280 char *t;
281 buf[0] = '\0';
282
283 if (EBIT_TEST(flags, ENTRY_SPECIAL))
284 strcat(buf, "SPECIAL,");
285
286 if (EBIT_TEST(flags, ENTRY_REVALIDATE_ALWAYS))
287 strcat(buf, "REVALIDATE_ALWAYS,");
288
289 if (EBIT_TEST(flags, DELAY_SENDING))
290 strcat(buf, "DELAY_SENDING,");
291
292 if (EBIT_TEST(flags, RELEASE_REQUEST))
293 strcat(buf, "RELEASE_REQUEST,");
294
295 if (EBIT_TEST(flags, REFRESH_REQUEST))
296 strcat(buf, "REFRESH_REQUEST,");
297
298 if (EBIT_TEST(flags, ENTRY_REVALIDATE_STALE))
299 strcat(buf, "REVALIDATE_STALE,");
300
301 if (EBIT_TEST(flags, ENTRY_DISPATCHED))
302 strcat(buf, "DISPATCHED,");
303
304 if (EBIT_TEST(flags, KEY_PRIVATE))
305 strcat(buf, "PRIVATE,");
306
307 if (EBIT_TEST(flags, ENTRY_FWD_HDR_WAIT))
308 strcat(buf, "FWD_HDR_WAIT,");
309
310 if (EBIT_TEST(flags, ENTRY_NEGCACHED))
311 strcat(buf, "NEGCACHED,");
312
313 if (EBIT_TEST(flags, ENTRY_VALIDATED))
314 strcat(buf, "VALIDATED,");
315
316 if (EBIT_TEST(flags, ENTRY_BAD_LENGTH))
317 strcat(buf, "BAD_LENGTH,");
318
319 if (EBIT_TEST(flags, ENTRY_ABORTED))
320 strcat(buf, "ABORTED,");
321
322 if ((t = strrchr(buf, ',')))
323 *t = '\0';
324
325 return buf;
326 }
327
328 static void
329 statStoreEntry(MemBuf * mb, StoreEntry * e)
330 {
331 MemObject *mem = e->mem_obj;
332 mb->appendf("KEY %s\n", e->getMD5Text());
333 mb->appendf("\t%s\n", describeStatuses(e));
334 mb->appendf("\t%s\n", storeEntryFlags(e));
335 mb->appendf("\t%s\n", e->describeTimestamps());
336 mb->appendf("\t%d locks, %d clients, %d refs\n", (int) e->locks(), storePendingNClients(e), (int) e->refcount);
337 mb->appendf("\tSwap Dir %d, File %#08X\n", e->swap_dirn, e->swap_filen);
338
339 if (mem != NULL)
340 mem->stat (mb);
341
342 mb->append("\n", 1);
343 }
344
345 /* process objects list */
346 static void
347 statObjects(void *data)
348 {
349 StatObjectsState *state = static_cast<StatObjectsState *>(data);
350 StoreEntry *e;
351
352 if (state->theSearch->isDone()) {
353 if (UsingSmp())
354 storeAppendPrintf(state->sentry, "} by kid%d\n\n", KidIdentifier);
355 state->sentry->complete();
356 state->sentry->unlock("statObjects+isDone");
357 delete state;
358 return;
359 } else if (EBIT_TEST(state->sentry->flags, ENTRY_ABORTED)) {
360 state->sentry->unlock("statObjects+aborted");
361 delete state;
362 return;
363 } else if (state->sentry->checkDeferRead(-1)) {
364 state->sentry->flush();
365 eventAdd("statObjects", statObjects, state, 0.1, 1);
366 return;
367 }
368
369 state->sentry->buffer();
370 size_t statCount = 0;
371 MemBuf mb;
372 mb.init();
373
374 while (statCount++ < static_cast<size_t>(Config.Store.objectsPerBucket) && state->
375 theSearch->next()) {
376 e = state->theSearch->currentItem();
377
378 if (state->filter && 0 == state->filter(e))
379 continue;
380
381 statStoreEntry(&mb, e);
382 }
383
384 if (mb.size)
385 state->sentry->append(mb.buf, mb.size);
386 mb.clean();
387
388 eventAdd("statObjects", statObjects, state, 0.0, 1);
389 }
390
391 static void
392 statObjectsStart(StoreEntry * sentry, STOBJFLT * filter)
393 {
394 StatObjectsState *state = new StatObjectsState;
395 state->sentry = sentry;
396 state->filter = filter;
397
398 sentry->lock("statObjects");
399 state->theSearch = Store::Root().search();
400
401 eventAdd("statObjects", statObjects, state, 0.0, 1);
402 }
403
404 static void
405 stat_objects_get(StoreEntry * sentry)
406 {
407 statObjectsStart(sentry, NULL);
408 }
409
410 static int
411 statObjectsVmFilter(const StoreEntry * e)
412 {
413 return e->mem_obj ? 1 : 0;
414 }
415
416 static void
417 stat_vmobjects_get(StoreEntry * sentry)
418 {
419 statObjectsStart(sentry, statObjectsVmFilter);
420 }
421
422 #if DEBUG_OPENFD
423 static int
424 statObjectsOpenfdFilter(const StoreEntry * e)
425 {
426 if (e->mem_obj == NULL)
427 return 0;
428
429 if (e->mem_obj->swapout.sio == NULL)
430 return 0;
431
432 return 1;
433 }
434
435 static void
436 statOpenfdObj(StoreEntry * sentry)
437 {
438 statObjectsStart(sentry, statObjectsOpenfdFilter);
439 }
440
441 #endif
442
443 #if XMALLOC_STATISTICS
444 static void
445 info_get_mallstat(int size, int number, int oldnum, void *data)
446 {
447 StoreEntry *sentry = (StoreEntry *)data;
448
449 // format: "%12s %15s %6s %12s\n","Alloc Size","Count","Delta","Alloc/sec"
450 if (number > 0)
451 storeAppendPrintf(sentry, "%12d %15d %6d %.1f\n", size, number, number - oldnum, xdiv((number - oldnum), xm_deltat));
452 }
453
454 #endif
455
456 void
457 GetInfo(Mgr::InfoActionData& stats)
458 {
459
460 struct rusage rusage;
461 double cputime;
462 double runtime;
463 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
464 struct mstats ms;
465 #endif
466
467 runtime = tvSubDsec(squid_start, current_time);
468
469 if (runtime == 0.0)
470 runtime = 1.0;
471
472 stats.squid_start = squid_start;
473
474 stats.current_time = current_time;
475
476 stats.client_http_clients = statCounter.client_http.clients;
477
478 stats.client_http_requests = statCounter.client_http.requests;
479
480 stats.icp_pkts_recv = statCounter.icp.pkts_recv;
481
482 stats.icp_pkts_sent = statCounter.icp.pkts_sent;
483
484 stats.icp_replies_queued = statCounter.icp.replies_queued;
485
486 #if USE_HTCP
487
488 stats.htcp_pkts_recv = statCounter.htcp.pkts_recv;
489
490 stats.htcp_pkts_sent = statCounter.htcp.pkts_sent;
491
492 #endif
493
494 stats.request_failure_ratio = request_failure_ratio;
495
496 stats.avg_client_http_requests = statCounter.client_http.requests / (runtime / 60.0);
497
498 stats.avg_icp_messages = (statCounter.icp.pkts_sent + statCounter.icp.pkts_recv) / (runtime / 60.0);
499
500 stats.select_loops = statCounter.select_loops;
501 stats.avg_loop_time = 1000.0 * runtime / statCounter.select_loops;
502
503 stats.request_hit_ratio5 = statRequestHitRatio(5);
504 stats.request_hit_ratio60 = statRequestHitRatio(60);
505
506 stats.byte_hit_ratio5 = statByteHitRatio(5);
507 stats.byte_hit_ratio60 = statByteHitRatio(60);
508
509 stats.request_hit_mem_ratio5 = statRequestHitMemoryRatio(5);
510 stats.request_hit_mem_ratio60 = statRequestHitMemoryRatio(60);
511
512 stats.request_hit_disk_ratio5 = statRequestHitDiskRatio(5);
513 stats.request_hit_disk_ratio60 = statRequestHitDiskRatio(60);
514
515 Store::Root().getStats(stats.store);
516
517 stats.unlink_requests = statCounter.unlink.requests;
518
519 stats.http_requests5 = statPctileSvc(0.5, 5, PCTILE_HTTP);
520 stats.http_requests60 = statPctileSvc(0.5, 60, PCTILE_HTTP);
521
522 stats.cache_misses5 = statPctileSvc(0.5, 5, PCTILE_MISS);
523 stats.cache_misses60 = statPctileSvc(0.5, 60, PCTILE_MISS);
524
525 stats.cache_hits5 = statPctileSvc(0.5, 5, PCTILE_HIT);
526 stats.cache_hits60 = statPctileSvc(0.5, 60, PCTILE_HIT);
527
528 stats.near_hits5 = statPctileSvc(0.5, 5, PCTILE_NH);
529 stats.near_hits60 = statPctileSvc(0.5, 60, PCTILE_NH);
530
531 stats.not_modified_replies5 = statPctileSvc(0.5, 5, PCTILE_NM);
532 stats.not_modified_replies60 = statPctileSvc(0.5, 60, PCTILE_NM);
533
534 stats.dns_lookups5 = statPctileSvc(0.5, 5, PCTILE_DNS);
535 stats.dns_lookups60 = statPctileSvc(0.5, 60, PCTILE_DNS);
536
537 stats.icp_queries5 = statPctileSvc(0.5, 5, PCTILE_ICP_QUERY);
538 stats.icp_queries60 = statPctileSvc(0.5, 60, PCTILE_ICP_QUERY);
539
540 squid_getrusage(&rusage);
541 cputime = rusage_cputime(&rusage);
542
543 stats.up_time = runtime;
544 stats.cpu_time = cputime;
545 stats.cpu_usage = Math::doublePercent(cputime, runtime);
546 stats.cpu_usage5 = statCPUUsage(5);
547 stats.cpu_usage60 = statCPUUsage(60);
548
549 stats.maxrss = rusage_maxrss(&rusage);
550
551 stats.page_faults = rusage_pagefaults(&rusage);
552
553 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
554
555 ms = mstats();
556
557 stats.ms_bytes_total = ms.bytes_total;
558
559 stats.ms_bytes_free = ms.bytes_free;
560
561 #endif
562
563 stats.total_accounted = statMemoryAccounted();
564
565 {
566 MemPoolGlobalStats mp_stats;
567 memPoolGetGlobalStats(&mp_stats);
568 stats.gb_saved_count = mp_stats.TheMeter->gb_saved.count;
569 stats.gb_freed_count = mp_stats.TheMeter->gb_freed.count;
570 }
571
572 stats.max_fd = Squid_MaxFD;
573 stats.biggest_fd = Biggest_FD;
574 stats.number_fd = Number_FD;
575 stats.opening_fd = Opening_FD;
576 stats.num_fd_free = fdNFree();
577 stats.reserved_fd = RESERVED_FD;
578 }
579
580 void
581 DumpInfo(Mgr::InfoActionData& stats, StoreEntry* sentry)
582 {
583 storeAppendPrintf(sentry, "Squid Object Cache: Version %s\n",
584 version_string);
585
586 storeAppendPrintf(sentry, "Build Info: " SQUID_BUILD_INFO "\n");
587
588 #if _SQUID_WINDOWS_
589 if (WIN32_run_mode == _WIN_SQUID_RUN_MODE_SERVICE) {
590 storeAppendPrintf(sentry,"\nRunning as " SQUIDSBUFPH " Windows System Service on %s\n",
591 SQUIDSBUFPRINT(service_name), WIN32_OS_string);
592 storeAppendPrintf(sentry,"Service command line is: %s\n", WIN32_Service_Command_Line);
593 } else
594 storeAppendPrintf(sentry,"Running on %s\n",WIN32_OS_string);
595 #else
596 storeAppendPrintf(sentry,"Service Name: " SQUIDSBUFPH "\n", SQUIDSBUFPRINT(service_name));
597 #endif
598
599 storeAppendPrintf(sentry, "Start Time:\t%s\n",
600 mkrfc1123(stats.squid_start.tv_sec));
601
602 storeAppendPrintf(sentry, "Current Time:\t%s\n",
603 mkrfc1123(stats.current_time.tv_sec));
604
605 storeAppendPrintf(sentry, "Connection information for %s:\n",APP_SHORTNAME);
606
607 if (Config.onoff.client_db)
608 storeAppendPrintf(sentry, "\tNumber of clients accessing cache:\t%.0f\n", stats.client_http_clients);
609 else
610 sentry->append("\tNumber of clients accessing cache:\t(client_db off)\n", 52);
611
612 storeAppendPrintf(sentry, "\tNumber of HTTP requests received:\t%.0f\n",
613 stats.client_http_requests);
614
615 storeAppendPrintf(sentry, "\tNumber of ICP messages received:\t%.0f\n",
616 stats.icp_pkts_recv);
617
618 storeAppendPrintf(sentry, "\tNumber of ICP messages sent:\t%.0f\n",
619 stats.icp_pkts_sent);
620
621 storeAppendPrintf(sentry, "\tNumber of queued ICP replies:\t%.0f\n",
622 stats.icp_replies_queued);
623
624 #if USE_HTCP
625
626 storeAppendPrintf(sentry, "\tNumber of HTCP messages received:\t%.0f\n",
627 stats.htcp_pkts_recv);
628
629 storeAppendPrintf(sentry, "\tNumber of HTCP messages sent:\t%.0f\n",
630 stats.htcp_pkts_sent);
631
632 #endif
633
634 double fct = stats.count > 1 ? stats.count : 1.0;
635 storeAppendPrintf(sentry, "\tRequest failure ratio:\t%5.2f\n",
636 stats.request_failure_ratio / fct);
637
638 storeAppendPrintf(sentry, "\tAverage HTTP requests per minute since start:\t%.1f\n",
639 stats.avg_client_http_requests);
640
641 storeAppendPrintf(sentry, "\tAverage ICP messages per minute since start:\t%.1f\n",
642 stats.avg_icp_messages);
643
644 storeAppendPrintf(sentry, "\tSelect loop called: %.0f times, %0.3f ms avg\n",
645 stats.select_loops, stats.avg_loop_time / fct);
646
647 storeAppendPrintf(sentry, "Cache information for %s:\n",APP_SHORTNAME);
648
649 storeAppendPrintf(sentry, "\tHits as %% of all requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
650 stats.request_hit_ratio5 / fct,
651 stats.request_hit_ratio60 / fct);
652
653 storeAppendPrintf(sentry, "\tHits as %% of bytes sent:\t5min: %3.1f%%, 60min: %3.1f%%\n",
654 stats.byte_hit_ratio5 / fct,
655 stats.byte_hit_ratio60 / fct);
656
657 storeAppendPrintf(sentry, "\tMemory hits as %% of hit requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
658 stats.request_hit_mem_ratio5 / fct,
659 stats.request_hit_mem_ratio60 / fct);
660
661 storeAppendPrintf(sentry, "\tDisk hits as %% of hit requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
662 stats.request_hit_disk_ratio5 / fct,
663 stats.request_hit_disk_ratio60 / fct);
664
665 storeAppendPrintf(sentry, "\tStorage Swap size:\t%.0f KB\n",
666 stats.store.swap.size / 1024);
667
668 storeAppendPrintf(sentry, "\tStorage Swap capacity:\t%4.1f%% used, %4.1f%% free\n",
669 Math::doublePercent(stats.store.swap.size, stats.store.swap.capacity),
670 Math::doublePercent(stats.store.swap.available(), stats.store.swap.capacity));
671
672 storeAppendPrintf(sentry, "\tStorage Mem size:\t%.0f KB\n",
673 stats.store.mem.size / 1024);
674
675 storeAppendPrintf(sentry, "\tStorage Mem capacity:\t%4.1f%% used, %4.1f%% free\n",
676 Math::doublePercent(stats.store.mem.size, stats.store.mem.capacity),
677 Math::doublePercent(stats.store.mem.available(), stats.store.mem.capacity));
678
679 storeAppendPrintf(sentry, "\tMean Object Size:\t%0.2f KB\n",
680 stats.store.swap.meanObjectSize() / 1024);
681
682 storeAppendPrintf(sentry, "\tRequests given to unlinkd:\t%.0f\n",
683 stats.unlink_requests);
684
685 storeAppendPrintf(sentry, "Median Service Times (seconds) 5 min 60 min:\n");
686
687 fct = stats.count > 1 ? stats.count * 1000.0 : 1000.0;
688 storeAppendPrintf(sentry, "\tHTTP Requests (All): %8.5f %8.5f\n",
689 stats.http_requests5 / fct,
690 stats.http_requests60 / fct);
691
692 storeAppendPrintf(sentry, "\tCache Misses: %8.5f %8.5f\n",
693 stats.cache_misses5 / fct,
694 stats.cache_misses60 / fct);
695
696 storeAppendPrintf(sentry, "\tCache Hits: %8.5f %8.5f\n",
697 stats.cache_hits5 / fct,
698 stats.cache_hits60 / fct);
699
700 storeAppendPrintf(sentry, "\tNear Hits: %8.5f %8.5f\n",
701 stats.near_hits5 / fct,
702 stats.near_hits60 / fct);
703
704 storeAppendPrintf(sentry, "\tNot-Modified Replies: %8.5f %8.5f\n",
705 stats.not_modified_replies5 / fct,
706 stats.not_modified_replies60 / fct);
707
708 storeAppendPrintf(sentry, "\tDNS Lookups: %8.5f %8.5f\n",
709 stats.dns_lookups5 / fct,
710 stats.dns_lookups60 / fct);
711
712 fct = stats.count > 1 ? stats.count * 1000000.0 : 1000000.0;
713 storeAppendPrintf(sentry, "\tICP Queries: %8.5f %8.5f\n",
714 stats.icp_queries5 / fct,
715 stats.icp_queries60 / fct);
716
717 storeAppendPrintf(sentry, "Resource usage for %s:\n", APP_SHORTNAME);
718
719 storeAppendPrintf(sentry, "\tUP Time:\t%.3f seconds\n", stats.up_time);
720
721 storeAppendPrintf(sentry, "\tCPU Time:\t%.3f seconds\n", stats.cpu_time);
722
723 storeAppendPrintf(sentry, "\tCPU Usage:\t%.2f%%\n",
724 stats.cpu_usage);
725
726 storeAppendPrintf(sentry, "\tCPU Usage, 5 minute avg:\t%.2f%%\n",
727 stats.cpu_usage5);
728
729 storeAppendPrintf(sentry, "\tCPU Usage, 60 minute avg:\t%.2f%%\n",
730 stats.cpu_usage60);
731
732 storeAppendPrintf(sentry, "\tMaximum Resident Size: %.0f KB\n",
733 stats.maxrss);
734
735 storeAppendPrintf(sentry, "\tPage faults with physical i/o: %.0f\n",
736 stats.page_faults);
737
738 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
739
740 storeAppendPrintf(sentry, "Memory usage for %s via mstats():\n",APP_SHORTNAME);
741
742 storeAppendPrintf(sentry, "\tTotal space in arena: %6.0f KB\n",
743 stats.ms_bytes_total / 1024);
744
745 storeAppendPrintf(sentry, "\tTotal free: %6.0f KB %.0f%%\n",
746 stats.ms_bytes_free / 1024,
747 Math::doublePercent(stats.ms_bytes_free, stats.ms_bytes_total));
748
749 #endif
750
751 storeAppendPrintf(sentry, "Memory accounted for:\n");
752 storeAppendPrintf(sentry, "\tTotal accounted: %6.0f KB\n",
753 stats.total_accounted / 1024);
754 {
755 MemPoolGlobalStats mp_stats;
756 memPoolGetGlobalStats(&mp_stats);
757 storeAppendPrintf(sentry, "\tmemPoolAlloc calls: %9.0f\n",
758 stats.gb_saved_count);
759 storeAppendPrintf(sentry, "\tmemPoolFree calls: %9.0f\n",
760 stats.gb_freed_count);
761 }
762
763 storeAppendPrintf(sentry, "File descriptor usage for %s:\n", APP_SHORTNAME);
764 storeAppendPrintf(sentry, "\tMaximum number of file descriptors: %4.0f\n",
765 stats.max_fd);
766 storeAppendPrintf(sentry, "\tLargest file desc currently in use: %4.0f\n",
767 stats.biggest_fd);
768 storeAppendPrintf(sentry, "\tNumber of file desc currently in use: %4.0f\n",
769 stats.number_fd);
770 storeAppendPrintf(sentry, "\tFiles queued for open: %4.0f\n",
771 stats.opening_fd);
772 storeAppendPrintf(sentry, "\tAvailable number of file descriptors: %4.0f\n",
773 stats.num_fd_free);
774 storeAppendPrintf(sentry, "\tReserved number of file descriptors: %4.0f\n",
775 stats.reserved_fd);
776 storeAppendPrintf(sentry, "\tStore Disk files open: %4.0f\n",
777 stats.store.swap.open_disk_fd);
778
779 storeAppendPrintf(sentry, "Internal Data Structures:\n");
780 storeAppendPrintf(sentry, "\t%6.0f StoreEntries\n",
781 stats.store.store_entry_count);
782 storeAppendPrintf(sentry, "\t%6.0f StoreEntries with MemObjects\n",
783 stats.store.mem_object_count);
784 storeAppendPrintf(sentry, "\t%6.0f Hot Object Cache Items\n",
785 stats.store.mem.count);
786 storeAppendPrintf(sentry, "\t%6.0f on-disk objects\n",
787 stats.store.swap.count);
788 }
789
790 void
791 DumpMallocStatistics(StoreEntry* sentry)
792 {
793 #if XMALLOC_STATISTICS
794 xm_deltat = current_dtime - xm_time;
795 xm_time = current_dtime;
796 storeAppendPrintf(sentry, "\nMemory allocation statistics\n");
797 storeAppendPrintf(sentry, "%12s %15s %6s %12s\n","Alloc Size","Count","Delta","Alloc/sec");
798 malloc_statistics(info_get_mallstat, sentry);
799 #endif
800 }
801
802 void
803 GetServiceTimesStats(Mgr::ServiceTimesActionData& stats)
804 {
805 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
806 double p = (i + 1) * 5 / 100.0;
807 stats.http_requests5[i] = statPctileSvc(p, 5, PCTILE_HTTP);
808 stats.http_requests60[i] = statPctileSvc(p, 60, PCTILE_HTTP);
809
810 stats.cache_misses5[i] = statPctileSvc(p, 5, PCTILE_MISS);
811 stats.cache_misses60[i] = statPctileSvc(p, 60, PCTILE_MISS);
812
813 stats.cache_hits5[i] = statPctileSvc(p, 5, PCTILE_HIT);
814 stats.cache_hits60[i] = statPctileSvc(p, 60, PCTILE_HIT);
815
816 stats.near_hits5[i] = statPctileSvc(p, 5, PCTILE_NH);
817 stats.near_hits60[i] = statPctileSvc(p, 60, PCTILE_NH);
818
819 stats.not_modified_replies5[i] = statPctileSvc(p, 5, PCTILE_NM);
820 stats.not_modified_replies60[i] = statPctileSvc(p, 60, PCTILE_NM);
821
822 stats.dns_lookups5[i] = statPctileSvc(p, 5, PCTILE_DNS);
823 stats.dns_lookups60[i] = statPctileSvc(p, 60, PCTILE_DNS);
824
825 stats.icp_queries5[i] = statPctileSvc(p, 5, PCTILE_ICP_QUERY);
826 stats.icp_queries60[i] = statPctileSvc(p, 60, PCTILE_ICP_QUERY);
827 }
828 }
829
830 void
831 DumpServiceTimesStats(Mgr::ServiceTimesActionData& stats, StoreEntry* sentry)
832 {
833 storeAppendPrintf(sentry, "Service Time Percentiles 5 min 60 min:\n");
834 double fct = stats.count > 1 ? stats.count * 1000.0 : 1000.0;
835 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
836 storeAppendPrintf(sentry, "\tHTTP Requests (All): %2d%% %8.5f %8.5f\n",
837 (i + 1) * 5,
838 stats.http_requests5[i] / fct,
839 stats.http_requests60[i] / fct);
840 }
841 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
842 storeAppendPrintf(sentry, "\tCache Misses: %2d%% %8.5f %8.5f\n",
843 (i + 1) * 5,
844 stats.cache_misses5[i] / fct,
845 stats.cache_misses60[i] / fct);
846 }
847 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
848 storeAppendPrintf(sentry, "\tCache Hits: %2d%% %8.5f %8.5f\n",
849 (i + 1) * 5,
850 stats.cache_hits5[i] / fct,
851 stats.cache_hits60[i] / fct);
852 }
853 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
854 storeAppendPrintf(sentry, "\tNear Hits: %2d%% %8.5f %8.5f\n",
855 (i + 1) * 5,
856 stats.near_hits5[i] / fct,
857 stats.near_hits60[i] / fct);
858 }
859 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
860 storeAppendPrintf(sentry, "\tNot-Modified Replies: %2d%% %8.5f %8.5f\n",
861 (i + 1) * 5,
862 stats.not_modified_replies5[i] / fct,
863 stats.not_modified_replies60[i] / fct);
864 }
865 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
866 storeAppendPrintf(sentry, "\tDNS Lookups: %2d%% %8.5f %8.5f\n",
867 (i + 1) * 5,
868 stats.dns_lookups5[i] / fct,
869 stats.dns_lookups60[i] / fct);
870 }
871 fct = stats.count > 1 ? stats.count * 1000000.0 : 1000000.0;
872 for (int i = 0; i < Mgr::ServiceTimesActionData::seriesSize; ++i) {
873 storeAppendPrintf(sentry, "\tICP Queries: %2d%% %8.5f %8.5f\n",
874 (i + 1) * 5,
875 stats.icp_queries5[i] / fct,
876 stats.icp_queries60[i] / fct);
877 }
878 }
879
880 static void
881 statAvgDump(StoreEntry * sentry, int minutes, int hours)
882 {
883 Mgr::IntervalActionData stats;
884 GetAvgStat(stats, minutes, hours);
885 DumpAvgStat(stats, sentry);
886 }
887
888 #define XAVG(X) (dt ? (double) (f->X - l->X) / dt : 0.0)
889 void
890 GetAvgStat(Mgr::IntervalActionData& stats, int minutes, int hours)
891 {
892 StatCounters *f;
893 StatCounters *l;
894 double dt;
895 double ct;
896 assert(N_COUNT_HIST > 1);
897 assert(minutes > 0 || hours > 0);
898 f = &CountHist[0];
899 l = f;
900
901 if (minutes > 0 && hours == 0) {
902 /* checking minute readings ... */
903
904 if (minutes > N_COUNT_HIST - 1)
905 minutes = N_COUNT_HIST - 1;
906
907 l = &CountHist[minutes];
908 } else if (minutes == 0 && hours > 0) {
909 /* checking hour readings ... */
910
911 if (hours > N_COUNT_HOUR_HIST - 1)
912 hours = N_COUNT_HOUR_HIST - 1;
913
914 l = &CountHourHist[hours];
915 } else {
916 debugs(18, DBG_IMPORTANT, "statAvgDump: Invalid args, minutes=" << minutes << ", hours=" << hours);
917 return;
918 }
919
920 dt = tvSubDsec(l->timestamp, f->timestamp);
921 ct = f->cputime - l->cputime;
922
923 stats.sample_start_time = l->timestamp;
924 stats.sample_end_time = f->timestamp;
925
926 stats.client_http_requests = XAVG(client_http.requests);
927 stats.client_http_hits = XAVG(client_http.hits);
928 stats.client_http_errors = XAVG(client_http.errors);
929 stats.client_http_kbytes_in = XAVG(client_http.kbytes_in.kb);
930 stats.client_http_kbytes_out = XAVG(client_http.kbytes_out.kb);
931
932 stats.client_http_all_median_svc_time = statHistDeltaMedian(l->client_http.allSvcTime,
933 f->client_http.allSvcTime) / 1000.0;
934 stats.client_http_miss_median_svc_time = statHistDeltaMedian(l->client_http.missSvcTime,
935 f->client_http.missSvcTime) / 1000.0;
936 stats.client_http_nm_median_svc_time = statHistDeltaMedian(l->client_http.nearMissSvcTime,
937 f->client_http.nearMissSvcTime) / 1000.0;
938 stats.client_http_nh_median_svc_time = statHistDeltaMedian(l->client_http.nearHitSvcTime,
939 f->client_http.nearHitSvcTime) / 1000.0;
940 stats.client_http_hit_median_svc_time = statHistDeltaMedian(l->client_http.hitSvcTime,
941 f->client_http.hitSvcTime) / 1000.0;
942
943 stats.server_all_requests = XAVG(server.all.requests);
944 stats.server_all_errors = XAVG(server.all.errors);
945 stats.server_all_kbytes_in = XAVG(server.all.kbytes_in.kb);
946 stats.server_all_kbytes_out = XAVG(server.all.kbytes_out.kb);
947
948 stats.server_http_requests = XAVG(server.http.requests);
949 stats.server_http_errors = XAVG(server.http.errors);
950 stats.server_http_kbytes_in = XAVG(server.http.kbytes_in.kb);
951 stats.server_http_kbytes_out = XAVG(server.http.kbytes_out.kb);
952
953 stats.server_ftp_requests = XAVG(server.ftp.requests);
954 stats.server_ftp_errors = XAVG(server.ftp.errors);
955 stats.server_ftp_kbytes_in = XAVG(server.ftp.kbytes_in.kb);
956 stats.server_ftp_kbytes_out = XAVG(server.ftp.kbytes_out.kb);
957
958 stats.server_other_requests = XAVG(server.other.requests);
959 stats.server_other_errors = XAVG(server.other.errors);
960 stats.server_other_kbytes_in = XAVG(server.other.kbytes_in.kb);
961 stats.server_other_kbytes_out = XAVG(server.other.kbytes_out.kb);
962
963 stats.icp_pkts_sent = XAVG(icp.pkts_sent);
964 stats.icp_pkts_recv = XAVG(icp.pkts_recv);
965 stats.icp_queries_sent = XAVG(icp.queries_sent);
966 stats.icp_replies_sent = XAVG(icp.replies_sent);
967 stats.icp_queries_recv = XAVG(icp.queries_recv);
968 stats.icp_replies_recv = XAVG(icp.replies_recv);
969 stats.icp_replies_queued = XAVG(icp.replies_queued);
970 stats.icp_query_timeouts = XAVG(icp.query_timeouts);
971 stats.icp_kbytes_sent = XAVG(icp.kbytes_sent.kb);
972 stats.icp_kbytes_recv = XAVG(icp.kbytes_recv.kb);
973 stats.icp_q_kbytes_sent = XAVG(icp.q_kbytes_sent.kb);
974 stats.icp_r_kbytes_sent = XAVG(icp.r_kbytes_sent.kb);
975 stats.icp_q_kbytes_recv = XAVG(icp.q_kbytes_recv.kb);
976 stats.icp_r_kbytes_recv = XAVG(icp.r_kbytes_recv.kb);
977
978 stats.icp_query_median_svc_time = statHistDeltaMedian(l->icp.querySvcTime,
979 f->icp.querySvcTime) / 1000000.0;
980 stats.icp_reply_median_svc_time = statHistDeltaMedian(l->icp.replySvcTime,
981 f->icp.replySvcTime) / 1000000.0;
982 stats.dns_median_svc_time = statHistDeltaMedian(l->dns.svcTime,
983 f->dns.svcTime) / 1000.0;
984
985 stats.unlink_requests = XAVG(unlink.requests);
986 stats.page_faults = XAVG(page_faults);
987 stats.select_loops = XAVG(select_loops);
988 stats.select_fds = XAVG(select_fds);
989 stats.average_select_fd_period = f->select_fds > l->select_fds ?
990 (f->select_time - l->select_time) / (f->select_fds - l->select_fds) : 0.0;
991
992 stats.median_select_fds = statHistDeltaMedian(l->select_fds_hist, f->select_fds_hist);
993 stats.swap_outs = XAVG(swap.outs);
994 stats.swap_ins = XAVG(swap.ins);
995 stats.swap_files_cleaned = XAVG(swap.files_cleaned);
996 stats.aborted_requests = XAVG(aborted_requests);
997
998 stats.syscalls_disk_opens = XAVG(syscalls.disk.opens);
999 stats.syscalls_disk_closes = XAVG(syscalls.disk.closes);
1000 stats.syscalls_disk_reads = XAVG(syscalls.disk.reads);
1001 stats.syscalls_disk_writes = XAVG(syscalls.disk.writes);
1002 stats.syscalls_disk_seeks = XAVG(syscalls.disk.seeks);
1003 stats.syscalls_disk_unlinks = XAVG(syscalls.disk.unlinks);
1004 stats.syscalls_sock_accepts = XAVG(syscalls.sock.accepts);
1005 stats.syscalls_sock_sockets = XAVG(syscalls.sock.sockets);
1006 stats.syscalls_sock_connects = XAVG(syscalls.sock.connects);
1007 stats.syscalls_sock_binds = XAVG(syscalls.sock.binds);
1008 stats.syscalls_sock_closes = XAVG(syscalls.sock.closes);
1009 stats.syscalls_sock_reads = XAVG(syscalls.sock.reads);
1010 stats.syscalls_sock_writes = XAVG(syscalls.sock.writes);
1011 stats.syscalls_sock_recvfroms = XAVG(syscalls.sock.recvfroms);
1012 stats.syscalls_sock_sendtos = XAVG(syscalls.sock.sendtos);
1013 stats.syscalls_selects = XAVG(syscalls.selects);
1014
1015 stats.cpu_time = ct;
1016 stats.wall_time = dt;
1017 }
1018
1019 void
1020 DumpAvgStat(Mgr::IntervalActionData& stats, StoreEntry* sentry)
1021 {
1022 storeAppendPrintf(sentry, "sample_start_time = %d.%d (%s)\n",
1023 (int)stats.sample_start_time.tv_sec,
1024 (int)stats.sample_start_time.tv_usec,
1025 mkrfc1123(stats.sample_start_time.tv_sec));
1026 storeAppendPrintf(sentry, "sample_end_time = %d.%d (%s)\n",
1027 (int)stats.sample_end_time.tv_sec,
1028 (int)stats.sample_end_time.tv_usec,
1029 mkrfc1123(stats.sample_end_time.tv_sec));
1030
1031 storeAppendPrintf(sentry, "client_http.requests = %f/sec\n",
1032 stats.client_http_requests);
1033 storeAppendPrintf(sentry, "client_http.hits = %f/sec\n",
1034 stats.client_http_hits);
1035 storeAppendPrintf(sentry, "client_http.errors = %f/sec\n",
1036 stats.client_http_errors);
1037 storeAppendPrintf(sentry, "client_http.kbytes_in = %f/sec\n",
1038 stats.client_http_kbytes_in);
1039 storeAppendPrintf(sentry, "client_http.kbytes_out = %f/sec\n",
1040 stats.client_http_kbytes_out);
1041
1042 double fct = stats.count > 1 ? stats.count : 1.0;
1043 storeAppendPrintf(sentry, "client_http.all_median_svc_time = %f seconds\n",
1044 stats.client_http_all_median_svc_time / fct);
1045 storeAppendPrintf(sentry, "client_http.miss_median_svc_time = %f seconds\n",
1046 stats.client_http_miss_median_svc_time / fct);
1047 storeAppendPrintf(sentry, "client_http.nm_median_svc_time = %f seconds\n",
1048 stats.client_http_nm_median_svc_time / fct);
1049 storeAppendPrintf(sentry, "client_http.nh_median_svc_time = %f seconds\n",
1050 stats.client_http_nh_median_svc_time / fct);
1051 storeAppendPrintf(sentry, "client_http.hit_median_svc_time = %f seconds\n",
1052 stats.client_http_hit_median_svc_time / fct);
1053
1054 storeAppendPrintf(sentry, "server.all.requests = %f/sec\n",
1055 stats.server_all_requests);
1056 storeAppendPrintf(sentry, "server.all.errors = %f/sec\n",
1057 stats.server_all_errors);
1058 storeAppendPrintf(sentry, "server.all.kbytes_in = %f/sec\n",
1059 stats.server_all_kbytes_in);
1060 storeAppendPrintf(sentry, "server.all.kbytes_out = %f/sec\n",
1061 stats.server_all_kbytes_out);
1062
1063 storeAppendPrintf(sentry, "server.http.requests = %f/sec\n",
1064 stats.server_http_requests);
1065 storeAppendPrintf(sentry, "server.http.errors = %f/sec\n",
1066 stats.server_http_errors);
1067 storeAppendPrintf(sentry, "server.http.kbytes_in = %f/sec\n",
1068 stats.server_http_kbytes_in);
1069 storeAppendPrintf(sentry, "server.http.kbytes_out = %f/sec\n",
1070 stats.server_http_kbytes_out);
1071
1072 storeAppendPrintf(sentry, "server.ftp.requests = %f/sec\n",
1073 stats.server_ftp_requests);
1074 storeAppendPrintf(sentry, "server.ftp.errors = %f/sec\n",
1075 stats.server_ftp_errors);
1076 storeAppendPrintf(sentry, "server.ftp.kbytes_in = %f/sec\n",
1077 stats.server_ftp_kbytes_in);
1078 storeAppendPrintf(sentry, "server.ftp.kbytes_out = %f/sec\n",
1079 stats.server_ftp_kbytes_out);
1080
1081 storeAppendPrintf(sentry, "server.other.requests = %f/sec\n",
1082 stats.server_other_requests);
1083 storeAppendPrintf(sentry, "server.other.errors = %f/sec\n",
1084 stats.server_other_errors);
1085 storeAppendPrintf(sentry, "server.other.kbytes_in = %f/sec\n",
1086 stats.server_other_kbytes_in);
1087 storeAppendPrintf(sentry, "server.other.kbytes_out = %f/sec\n",
1088 stats.server_other_kbytes_out);
1089
1090 storeAppendPrintf(sentry, "icp.pkts_sent = %f/sec\n",
1091 stats.icp_pkts_sent);
1092 storeAppendPrintf(sentry, "icp.pkts_recv = %f/sec\n",
1093 stats.icp_pkts_recv);
1094 storeAppendPrintf(sentry, "icp.queries_sent = %f/sec\n",
1095 stats.icp_queries_sent);
1096 storeAppendPrintf(sentry, "icp.replies_sent = %f/sec\n",
1097 stats.icp_replies_sent);
1098 storeAppendPrintf(sentry, "icp.queries_recv = %f/sec\n",
1099 stats.icp_queries_recv);
1100 storeAppendPrintf(sentry, "icp.replies_recv = %f/sec\n",
1101 stats.icp_replies_recv);
1102 storeAppendPrintf(sentry, "icp.replies_queued = %f/sec\n",
1103 stats.icp_replies_queued);
1104 storeAppendPrintf(sentry, "icp.query_timeouts = %f/sec\n",
1105 stats.icp_query_timeouts);
1106 storeAppendPrintf(sentry, "icp.kbytes_sent = %f/sec\n",
1107 stats.icp_kbytes_sent);
1108 storeAppendPrintf(sentry, "icp.kbytes_recv = %f/sec\n",
1109 stats.icp_kbytes_recv);
1110 storeAppendPrintf(sentry, "icp.q_kbytes_sent = %f/sec\n",
1111 stats.icp_q_kbytes_sent);
1112 storeAppendPrintf(sentry, "icp.r_kbytes_sent = %f/sec\n",
1113 stats.icp_r_kbytes_sent);
1114 storeAppendPrintf(sentry, "icp.q_kbytes_recv = %f/sec\n",
1115 stats.icp_q_kbytes_recv);
1116 storeAppendPrintf(sentry, "icp.r_kbytes_recv = %f/sec\n",
1117 stats.icp_r_kbytes_recv);
1118 storeAppendPrintf(sentry, "icp.query_median_svc_time = %f seconds\n",
1119 stats.icp_query_median_svc_time / fct);
1120 storeAppendPrintf(sentry, "icp.reply_median_svc_time = %f seconds\n",
1121 stats.icp_reply_median_svc_time / fct);
1122 storeAppendPrintf(sentry, "dns.median_svc_time = %f seconds\n",
1123 stats.dns_median_svc_time / fct);
1124 storeAppendPrintf(sentry, "unlink.requests = %f/sec\n",
1125 stats.unlink_requests);
1126 storeAppendPrintf(sentry, "page_faults = %f/sec\n",
1127 stats.page_faults);
1128 storeAppendPrintf(sentry, "select_loops = %f/sec\n",
1129 stats.select_loops);
1130 storeAppendPrintf(sentry, "select_fds = %f/sec\n",
1131 stats.select_fds);
1132 storeAppendPrintf(sentry, "average_select_fd_period = %f/fd\n",
1133 stats.average_select_fd_period / fct);
1134 storeAppendPrintf(sentry, "median_select_fds = %f\n",
1135 stats.median_select_fds / fct);
1136 storeAppendPrintf(sentry, "swap.outs = %f/sec\n",
1137 stats.swap_outs);
1138 storeAppendPrintf(sentry, "swap.ins = %f/sec\n",
1139 stats.swap_ins);
1140 storeAppendPrintf(sentry, "swap.files_cleaned = %f/sec\n",
1141 stats.swap_files_cleaned);
1142 storeAppendPrintf(sentry, "aborted_requests = %f/sec\n",
1143 stats.aborted_requests);
1144
1145 #if USE_POLL
1146 storeAppendPrintf(sentry, "syscalls.polls = %f/sec\n", stats.syscalls_selects);
1147 #elif defined(USE_SELECT) || defined(USE_SELECT_WIN32)
1148 storeAppendPrintf(sentry, "syscalls.selects = %f/sec\n", stats.syscalls_selects);
1149 #endif
1150
1151 storeAppendPrintf(sentry, "syscalls.disk.opens = %f/sec\n", stats.syscalls_disk_opens);
1152 storeAppendPrintf(sentry, "syscalls.disk.closes = %f/sec\n", stats.syscalls_disk_closes);
1153 storeAppendPrintf(sentry, "syscalls.disk.reads = %f/sec\n", stats.syscalls_disk_reads);
1154 storeAppendPrintf(sentry, "syscalls.disk.writes = %f/sec\n", stats.syscalls_disk_writes);
1155 storeAppendPrintf(sentry, "syscalls.disk.seeks = %f/sec\n", stats.syscalls_disk_seeks);
1156 storeAppendPrintf(sentry, "syscalls.disk.unlinks = %f/sec\n", stats.syscalls_disk_unlinks);
1157 storeAppendPrintf(sentry, "syscalls.sock.accepts = %f/sec\n", stats.syscalls_sock_accepts);
1158 storeAppendPrintf(sentry, "syscalls.sock.sockets = %f/sec\n", stats.syscalls_sock_sockets);
1159 storeAppendPrintf(sentry, "syscalls.sock.connects = %f/sec\n", stats.syscalls_sock_connects);
1160 storeAppendPrintf(sentry, "syscalls.sock.binds = %f/sec\n", stats.syscalls_sock_binds);
1161 storeAppendPrintf(sentry, "syscalls.sock.closes = %f/sec\n", stats.syscalls_sock_closes);
1162 storeAppendPrintf(sentry, "syscalls.sock.reads = %f/sec\n", stats.syscalls_sock_reads);
1163 storeAppendPrintf(sentry, "syscalls.sock.writes = %f/sec\n", stats.syscalls_sock_writes);
1164 storeAppendPrintf(sentry, "syscalls.sock.recvfroms = %f/sec\n", stats.syscalls_sock_recvfroms);
1165 storeAppendPrintf(sentry, "syscalls.sock.sendtos = %f/sec\n", stats.syscalls_sock_sendtos);
1166
1167 storeAppendPrintf(sentry, "cpu_time = %f seconds\n", stats.cpu_time);
1168 storeAppendPrintf(sentry, "wall_time = %f seconds\n", stats.wall_time);
1169 storeAppendPrintf(sentry, "cpu_usage = %f%%\n", Math::doublePercent(stats.cpu_time, stats.wall_time));
1170 }
1171
1172 static void
1173 statRegisterWithCacheManager(void)
1174 {
1175 Mgr::RegisterAction("info", "General Runtime Information",
1176 &Mgr::InfoAction::Create, 0, 1);
1177 Mgr::RegisterAction("service_times", "Service Times (Percentiles)",
1178 &Mgr::ServiceTimesAction::Create, 0, 1);
1179 Mgr::RegisterAction("filedescriptors", "Process Filedescriptor Allocation",
1180 fde::DumpStats, 0, 1);
1181 Mgr::RegisterAction("objects", "All Cache Objects", stat_objects_get, 0, 0);
1182 Mgr::RegisterAction("vm_objects", "In-Memory and In-Transit Objects",
1183 stat_vmobjects_get, 0, 0);
1184 Mgr::RegisterAction("io", "Server-side network read() size histograms",
1185 &Mgr::IoAction::Create, 0, 1);
1186 Mgr::RegisterAction("counters", "Traffic and Resource Counters",
1187 &Mgr::CountersAction::Create, 0, 1);
1188 Mgr::RegisterAction("peer_select", "Peer Selection Algorithms",
1189 statPeerSelect, 0, 1);
1190 Mgr::RegisterAction("digest_stats", "Cache Digest and ICP blob",
1191 statDigestBlob, 0, 1);
1192 Mgr::RegisterAction("5min", "5 Minute Average of Counters",
1193 &Mgr::IntervalAction::Create5min, 0, 1);
1194 Mgr::RegisterAction("60min", "60 Minute Average of Counters",
1195 &Mgr::IntervalAction::Create60min, 0, 1);
1196 Mgr::RegisterAction("utilization", "Cache Utilization",
1197 statUtilization, 0, 1);
1198 Mgr::RegisterAction("histograms", "Full Histogram Counts",
1199 statCountersHistograms, 0, 1);
1200 Mgr::RegisterAction("active_requests",
1201 "Client-side Active Requests",
1202 statClientRequests, 0, 1);
1203 #if USE_AUTH
1204 Mgr::RegisterAction("username_cache",
1205 "Active Cached Usernames",
1206 Auth::User::CredentialsCacheStats, 0, 1);
1207 #endif
1208 #if DEBUG_OPENFD
1209 Mgr::RegisterAction("openfd_objects", "Objects with Swapout files open",
1210 statOpenfdObj, 0, 0);
1211 #endif
1212 #if STAT_GRAPHS
1213 Mgr::RegisterAction("graph_variables", "Display cache metrics graphically",
1214 statGraphDump, 0, 1);
1215 #endif
1216 }
1217
1218 /* add special cases here as they arrive */
1219 static void
1220 statCountersInitSpecial(StatCounters * C)
1221 {
1222 /*
1223 * HTTP svc_time hist is kept in milli-seconds; max of 3 hours.
1224 */
1225 C->client_http.allSvcTime.logInit(300, 0.0, 3600000.0 * 3.0);
1226 C->client_http.missSvcTime.logInit(300, 0.0, 3600000.0 * 3.0);
1227 C->client_http.nearMissSvcTime.logInit(300, 0.0, 3600000.0 * 3.0);
1228 C->client_http.nearHitSvcTime.logInit(300, 0.0, 3600000.0 * 3.0);
1229 C->client_http.hitSvcTime.logInit(300, 0.0, 3600000.0 * 3.0);
1230 /*
1231 * ICP svc_time hist is kept in micro-seconds; max of 1 minute.
1232 */
1233 C->icp.querySvcTime.logInit(300, 0.0, 1000000.0 * 60.0);
1234 C->icp.replySvcTime.logInit(300, 0.0, 1000000.0 * 60.0);
1235 /*
1236 * DNS svc_time hist is kept in milli-seconds; max of 10 minutes.
1237 */
1238 C->dns.svcTime.logInit(300, 0.0, 60000.0 * 10.0);
1239 /*
1240 * Cache Digest Stuff
1241 */
1242 C->cd.on_xition_count.enumInit(CacheDigestHashFuncCount);
1243 C->comm_udp_incoming.enumInit(INCOMING_UDP_MAX);
1244 C->comm_dns_incoming.enumInit(INCOMING_DNS_MAX);
1245 C->comm_tcp_incoming.enumInit(INCOMING_TCP_MAX);
1246 C->select_fds_hist.enumInit(256); /* was SQUID_MAXFD, but it is way too much. It is OK to crop this statistics */
1247 }
1248
1249 static void
1250 statCountersInit(StatCounters * C)
1251 {
1252 assert(C);
1253 *C = StatCounters();
1254 statCountersInitSpecial(C);
1255 }
1256
1257 void
1258 statInit(void)
1259 {
1260 int i;
1261 debugs(18, 5, "statInit: Initializing...");
1262
1263 for (i = 0; i < N_COUNT_HIST; ++i)
1264 statCountersInit(&CountHist[i]);
1265
1266 for (i = 0; i < N_COUNT_HOUR_HIST; ++i)
1267 statCountersInit(&CountHourHist[i]);
1268
1269 statCountersInit(&statCounter);
1270
1271 eventAdd("statAvgTick", statAvgTick, NULL, (double) COUNT_INTERVAL, 1);
1272
1273 ClientActiveRequests.head = NULL;
1274
1275 ClientActiveRequests.tail = NULL;
1276
1277 statRegisterWithCacheManager();
1278 }
1279
1280 static void
1281 statAvgTick(void *)
1282 {
1283 struct rusage rusage;
1284 eventAdd("statAvgTick", statAvgTick, NULL, (double) COUNT_INTERVAL, 1);
1285 squid_getrusage(&rusage);
1286 statCounter.page_faults = rusage_pagefaults(&rusage);
1287 statCounter.cputime = rusage_cputime(&rusage);
1288 statCounter.timestamp = current_time;
1289 // shift all elements right and prepend statCounter
1290 for(int i = N_COUNT_HIST-1; i > 0; --i)
1291 CountHist[i] = CountHist[i-1];
1292 CountHist[0] = statCounter;
1293 ++NCountHist;
1294
1295 if ((NCountHist % COUNT_INTERVAL) == 0) {
1296 /* we have an hours worth of readings. store previous hour */
1297 // shift all elements right and prepend final CountHist element
1298 for(int i = N_COUNT_HOUR_HIST-1; i > 0; --i)
1299 CountHourHist[i] = CountHourHist[i-1];
1300 CountHourHist[0] = CountHist[N_COUNT_HIST - 1];
1301 ++NCountHourHist;
1302 }
1303
1304 if (Config.warnings.high_rptm > 0) {
1305 int i = (int) statPctileSvc(0.5, 20, PCTILE_HTTP);
1306
1307 if (Config.warnings.high_rptm < i)
1308 debugs(18, DBG_CRITICAL, "WARNING: Median response time is " << i << " milliseconds");
1309 }
1310
1311 if (Config.warnings.high_pf) {
1312 int i = (CountHist[0].page_faults - CountHist[1].page_faults);
1313 double dt = tvSubDsec(CountHist[0].timestamp, CountHist[1].timestamp);
1314
1315 if (i > 0 && dt > 0.0) {
1316 i /= (int) dt;
1317
1318 if (Config.warnings.high_pf < i)
1319 debugs(18, DBG_CRITICAL, "WARNING: Page faults occurring at " << i << "/sec");
1320 }
1321 }
1322
1323 if (Config.warnings.high_memory) {
1324 size_t i = 0;
1325 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
1326 struct mstats ms = mstats();
1327 i = ms.bytes_total;
1328 #endif
1329 if (Config.warnings.high_memory < i)
1330 debugs(18, DBG_CRITICAL, "WARNING: Memory usage at " << ((unsigned long int)(i >> 20)) << " MB");
1331 }
1332 }
1333
1334 static void
1335 statCountersHistograms(StoreEntry * sentry)
1336 {
1337 storeAppendPrintf(sentry, "client_http.allSvcTime histogram:\n");
1338 statCounter.client_http.allSvcTime.dump(sentry, NULL);
1339 storeAppendPrintf(sentry, "client_http.missSvcTime histogram:\n");
1340 statCounter.client_http.missSvcTime.dump(sentry, NULL);
1341 storeAppendPrintf(sentry, "client_http.nearMissSvcTime histogram:\n");
1342 statCounter.client_http.nearMissSvcTime.dump(sentry, NULL);
1343 storeAppendPrintf(sentry, "client_http.nearHitSvcTime histogram:\n");
1344 statCounter.client_http.nearHitSvcTime.dump(sentry, NULL);
1345 storeAppendPrintf(sentry, "client_http.hitSvcTime histogram:\n");
1346 statCounter.client_http.hitSvcTime.dump(sentry, NULL);
1347 storeAppendPrintf(sentry, "icp.querySvcTime histogram:\n");
1348 statCounter.icp.querySvcTime.dump(sentry, NULL);
1349 storeAppendPrintf(sentry, "icp.replySvcTime histogram:\n");
1350 statCounter.icp.replySvcTime.dump(sentry, NULL);
1351 storeAppendPrintf(sentry, "dns.svc_time histogram:\n");
1352 statCounter.dns.svcTime.dump(sentry, NULL);
1353 storeAppendPrintf(sentry, "select_fds_hist histogram:\n");
1354 statCounter.select_fds_hist.dump(sentry, NULL);
1355 }
1356
1357 static void
1358 statCountersDump(StoreEntry * sentry)
1359 {
1360 Mgr::CountersActionData stats;
1361 GetCountersStats(stats);
1362 DumpCountersStats(stats, sentry);
1363 }
1364
1365 void
1366 GetCountersStats(Mgr::CountersActionData& stats)
1367 {
1368 StatCounters *f = &statCounter;
1369
1370 struct rusage rusage;
1371 squid_getrusage(&rusage);
1372 f->page_faults = rusage_pagefaults(&rusage);
1373 f->cputime = rusage_cputime(&rusage);
1374
1375 stats.sample_time = f->timestamp;
1376 stats.client_http_requests = f->client_http.requests;
1377 stats.client_http_hits = f->client_http.hits;
1378 stats.client_http_errors = f->client_http.errors;
1379 stats.client_http_kbytes_in = f->client_http.kbytes_in.kb;
1380 stats.client_http_kbytes_out = f->client_http.kbytes_out.kb;
1381 stats.client_http_hit_kbytes_out = f->client_http.hit_kbytes_out.kb;
1382
1383 stats.server_all_requests = f->server.all.requests;
1384 stats.server_all_errors = f->server.all.errors;
1385 stats.server_all_kbytes_in = f->server.all.kbytes_in.kb;
1386 stats.server_all_kbytes_out = f->server.all.kbytes_out.kb;
1387
1388 stats.server_http_requests = f->server.http.requests;
1389 stats.server_http_errors = f->server.http.errors;
1390 stats.server_http_kbytes_in = f->server.http.kbytes_in.kb;
1391 stats.server_http_kbytes_out = f->server.http.kbytes_out.kb;
1392
1393 stats.server_ftp_requests = f->server.ftp.requests;
1394 stats.server_ftp_errors = f->server.ftp.errors;
1395 stats.server_ftp_kbytes_in = f->server.ftp.kbytes_in.kb;
1396 stats.server_ftp_kbytes_out = f->server.ftp.kbytes_out.kb;
1397
1398 stats.server_other_requests = f->server.other.requests;
1399 stats.server_other_errors = f->server.other.errors;
1400 stats.server_other_kbytes_in = f->server.other.kbytes_in.kb;
1401 stats.server_other_kbytes_out = f->server.other.kbytes_out.kb;
1402
1403 stats.icp_pkts_sent = f->icp.pkts_sent;
1404 stats.icp_pkts_recv = f->icp.pkts_recv;
1405 stats.icp_queries_sent = f->icp.queries_sent;
1406 stats.icp_replies_sent = f->icp.replies_sent;
1407 stats.icp_queries_recv = f->icp.queries_recv;
1408 stats.icp_replies_recv = f->icp.replies_recv;
1409 stats.icp_query_timeouts = f->icp.query_timeouts;
1410 stats.icp_replies_queued = f->icp.replies_queued;
1411 stats.icp_kbytes_sent = f->icp.kbytes_sent.kb;
1412 stats.icp_kbytes_recv = f->icp.kbytes_recv.kb;
1413 stats.icp_q_kbytes_sent = f->icp.q_kbytes_sent.kb;
1414 stats.icp_r_kbytes_sent = f->icp.r_kbytes_sent.kb;
1415 stats.icp_q_kbytes_recv = f->icp.q_kbytes_recv.kb;
1416 stats.icp_r_kbytes_recv = f->icp.r_kbytes_recv.kb;
1417
1418 #if USE_CACHE_DIGESTS
1419
1420 stats.icp_times_used = f->icp.times_used;
1421 stats.cd_times_used = f->cd.times_used;
1422 stats.cd_msgs_sent = f->cd.msgs_sent;
1423 stats.cd_msgs_recv = f->cd.msgs_recv;
1424 stats.cd_memory = f->cd.memory.kb;
1425 stats.cd_local_memory = store_digest ? store_digest->mask_size / 1024 : 0;
1426 stats.cd_kbytes_sent = f->cd.kbytes_sent.kb;
1427 stats.cd_kbytes_recv = f->cd.kbytes_recv.kb;
1428 #endif
1429
1430 stats.unlink_requests = f->unlink.requests;
1431 stats.page_faults = f->page_faults;
1432 stats.select_loops = f->select_loops;
1433 stats.cpu_time = f->cputime;
1434 stats.wall_time = tvSubDsec(f->timestamp, current_time);
1435 stats.swap_outs = f->swap.outs;
1436 stats.swap_ins = f->swap.ins;
1437 stats.swap_files_cleaned = f->swap.files_cleaned;
1438 stats.aborted_requests = f->aborted_requests;
1439 }
1440
1441 void
1442 DumpCountersStats(Mgr::CountersActionData& stats, StoreEntry* sentry)
1443 {
1444 storeAppendPrintf(sentry, "sample_time = %d.%d (%s)\n",
1445 (int) stats.sample_time.tv_sec,
1446 (int) stats.sample_time.tv_usec,
1447 mkrfc1123(stats.sample_time.tv_sec));
1448 storeAppendPrintf(sentry, "client_http.requests = %.0f\n",
1449 stats.client_http_requests);
1450 storeAppendPrintf(sentry, "client_http.hits = %.0f\n",
1451 stats.client_http_hits);
1452 storeAppendPrintf(sentry, "client_http.errors = %.0f\n",
1453 stats.client_http_errors);
1454 storeAppendPrintf(sentry, "client_http.kbytes_in = %.0f\n",
1455 stats.client_http_kbytes_in);
1456 storeAppendPrintf(sentry, "client_http.kbytes_out = %.0f\n",
1457 stats.client_http_kbytes_out);
1458 storeAppendPrintf(sentry, "client_http.hit_kbytes_out = %.0f\n",
1459 stats.client_http_hit_kbytes_out);
1460
1461 storeAppendPrintf(sentry, "server.all.requests = %.0f\n",
1462 stats.server_all_requests);
1463 storeAppendPrintf(sentry, "server.all.errors = %.0f\n",
1464 stats.server_all_errors);
1465 storeAppendPrintf(sentry, "server.all.kbytes_in = %.0f\n",
1466 stats.server_all_kbytes_in);
1467 storeAppendPrintf(sentry, "server.all.kbytes_out = %.0f\n",
1468 stats.server_all_kbytes_out);
1469
1470 storeAppendPrintf(sentry, "server.http.requests = %.0f\n",
1471 stats.server_http_requests);
1472 storeAppendPrintf(sentry, "server.http.errors = %.0f\n",
1473 stats.server_http_errors);
1474 storeAppendPrintf(sentry, "server.http.kbytes_in = %.0f\n",
1475 stats.server_http_kbytes_in);
1476 storeAppendPrintf(sentry, "server.http.kbytes_out = %.0f\n",
1477 stats.server_http_kbytes_out);
1478
1479 storeAppendPrintf(sentry, "server.ftp.requests = %.0f\n",
1480 stats.server_ftp_requests);
1481 storeAppendPrintf(sentry, "server.ftp.errors = %.0f\n",
1482 stats.server_ftp_errors);
1483 storeAppendPrintf(sentry, "server.ftp.kbytes_in = %.0f\n",
1484 stats.server_ftp_kbytes_in);
1485 storeAppendPrintf(sentry, "server.ftp.kbytes_out = %.0f\n",
1486 stats.server_ftp_kbytes_out);
1487
1488 storeAppendPrintf(sentry, "server.other.requests = %.0f\n",
1489 stats.server_other_requests);
1490 storeAppendPrintf(sentry, "server.other.errors = %.0f\n",
1491 stats.server_other_errors);
1492 storeAppendPrintf(sentry, "server.other.kbytes_in = %.0f\n",
1493 stats.server_other_kbytes_in);
1494 storeAppendPrintf(sentry, "server.other.kbytes_out = %.0f\n",
1495 stats.server_other_kbytes_out);
1496
1497 storeAppendPrintf(sentry, "icp.pkts_sent = %.0f\n",
1498 stats.icp_pkts_sent);
1499 storeAppendPrintf(sentry, "icp.pkts_recv = %.0f\n",
1500 stats.icp_pkts_recv);
1501 storeAppendPrintf(sentry, "icp.queries_sent = %.0f\n",
1502 stats.icp_queries_sent);
1503 storeAppendPrintf(sentry, "icp.replies_sent = %.0f\n",
1504 stats.icp_replies_sent);
1505 storeAppendPrintf(sentry, "icp.queries_recv = %.0f\n",
1506 stats.icp_queries_recv);
1507 storeAppendPrintf(sentry, "icp.replies_recv = %.0f\n",
1508 stats.icp_replies_recv);
1509 storeAppendPrintf(sentry, "icp.query_timeouts = %.0f\n",
1510 stats.icp_query_timeouts);
1511 storeAppendPrintf(sentry, "icp.replies_queued = %.0f\n",
1512 stats.icp_replies_queued);
1513 storeAppendPrintf(sentry, "icp.kbytes_sent = %.0f\n",
1514 stats.icp_kbytes_sent);
1515 storeAppendPrintf(sentry, "icp.kbytes_recv = %.0f\n",
1516 stats.icp_kbytes_recv);
1517 storeAppendPrintf(sentry, "icp.q_kbytes_sent = %.0f\n",
1518 stats.icp_q_kbytes_sent);
1519 storeAppendPrintf(sentry, "icp.r_kbytes_sent = %.0f\n",
1520 stats.icp_r_kbytes_sent);
1521 storeAppendPrintf(sentry, "icp.q_kbytes_recv = %.0f\n",
1522 stats.icp_q_kbytes_recv);
1523 storeAppendPrintf(sentry, "icp.r_kbytes_recv = %.0f\n",
1524 stats.icp_r_kbytes_recv);
1525
1526 #if USE_CACHE_DIGESTS
1527
1528 storeAppendPrintf(sentry, "icp.times_used = %.0f\n",
1529 stats.icp_times_used);
1530 storeAppendPrintf(sentry, "cd.times_used = %.0f\n",
1531 stats.cd_times_used);
1532 storeAppendPrintf(sentry, "cd.msgs_sent = %.0f\n",
1533 stats.cd_msgs_sent);
1534 storeAppendPrintf(sentry, "cd.msgs_recv = %.0f\n",
1535 stats.cd_msgs_recv);
1536 storeAppendPrintf(sentry, "cd.memory = %.0f\n",
1537 stats.cd_memory);
1538 storeAppendPrintf(sentry, "cd.local_memory = %.0f\n",
1539 stats.cd_local_memory);
1540 storeAppendPrintf(sentry, "cd.kbytes_sent = %.0f\n",
1541 stats.cd_kbytes_sent);
1542 storeAppendPrintf(sentry, "cd.kbytes_recv = %.0f\n",
1543 stats.cd_kbytes_recv);
1544 #endif
1545
1546 storeAppendPrintf(sentry, "unlink.requests = %.0f\n",
1547 stats.unlink_requests);
1548 storeAppendPrintf(sentry, "page_faults = %.0f\n",
1549 stats.page_faults);
1550 storeAppendPrintf(sentry, "select_loops = %.0f\n",
1551 stats.select_loops);
1552 storeAppendPrintf(sentry, "cpu_time = %f\n",
1553 stats.cpu_time);
1554 storeAppendPrintf(sentry, "wall_time = %f\n",
1555 stats.wall_time);
1556 storeAppendPrintf(sentry, "swap.outs = %.0f\n",
1557 stats.swap_outs);
1558 storeAppendPrintf(sentry, "swap.ins = %.0f\n",
1559 stats.swap_ins);
1560 storeAppendPrintf(sentry, "swap.files_cleaned = %.0f\n",
1561 stats.swap_files_cleaned);
1562 storeAppendPrintf(sentry, "aborted_requests = %.0f\n",
1563 stats.aborted_requests);
1564 }
1565
1566 void
1567 statFreeMemory(void)
1568 {
1569 // TODO: replace with delete[]
1570 for (int i = 0; i < N_COUNT_HIST; ++i)
1571 CountHist[i] = StatCounters();
1572
1573 for (int i = 0; i < N_COUNT_HOUR_HIST; ++i)
1574 CountHourHist[i] = StatCounters();
1575 }
1576
1577 static void
1578 statPeerSelect(StoreEntry * sentry)
1579 {
1580 #if USE_CACHE_DIGESTS
1581 StatCounters *f = &statCounter;
1582 CachePeer *peer;
1583 const int tot_used = f->cd.times_used + f->icp.times_used;
1584
1585 /* totals */
1586 static const SBuf label("all peers");
1587 cacheDigestGuessStatsReport(&f->cd.guess, sentry, label);
1588 /* per-peer */
1589 storeAppendPrintf(sentry, "\nPer-peer statistics:\n");
1590
1591 for (peer = getFirstPeer(); peer; peer = getNextPeer(peer)) {
1592 if (peer->digest)
1593 peerDigestStatsReport(peer->digest, sentry);
1594 else
1595 storeAppendPrintf(sentry, "\nNo peer digest from %s\n", peer->host);
1596
1597 storeAppendPrintf(sentry, "\n");
1598 }
1599
1600 storeAppendPrintf(sentry, "\nAlgorithm usage:\n");
1601 storeAppendPrintf(sentry, "Cache Digest: %7d (%3d%%)\n",
1602 f->cd.times_used, xpercentInt(f->cd.times_used, tot_used));
1603 storeAppendPrintf(sentry, "Icp: %7d (%3d%%)\n",
1604 f->icp.times_used, xpercentInt(f->icp.times_used, tot_used));
1605 storeAppendPrintf(sentry, "Total: %7d (%3d%%)\n",
1606 tot_used, xpercentInt(tot_used, tot_used));
1607 #else
1608
1609 storeAppendPrintf(sentry, "peer digests are disabled; no stats is available.\n");
1610 #endif
1611 }
1612
1613 static void
1614 statDigestBlob(StoreEntry * sentry)
1615 {
1616 storeAppendPrintf(sentry, "\nCounters:\n");
1617 statCountersDump(sentry);
1618 storeAppendPrintf(sentry, "\n5 Min Averages:\n");
1619 statAvgDump(sentry, 5, 0);
1620 storeAppendPrintf(sentry, "\nHistograms:\n");
1621 statCountersHistograms(sentry);
1622 storeAppendPrintf(sentry, "\nPeer Digests:\n");
1623 statPeerSelect(sentry);
1624 storeAppendPrintf(sentry, "\nLocal Digest:\n");
1625 storeDigestReport(sentry);
1626 }
1627
1628 static double
1629 statPctileSvc(double pctile, int interval, int which)
1630 {
1631 StatCounters *f;
1632 StatCounters *l;
1633 double x;
1634 assert(interval > 0);
1635
1636 if (interval > N_COUNT_HIST - 1)
1637 interval = N_COUNT_HIST - 1;
1638
1639 f = &CountHist[0];
1640
1641 l = &CountHist[interval];
1642
1643 assert(f);
1644
1645 assert(l);
1646
1647 switch (which) {
1648
1649 case PCTILE_HTTP:
1650 x = statHistDeltaPctile(l->client_http.allSvcTime,f->client_http.allSvcTime, pctile);
1651 break;
1652
1653 case PCTILE_HIT:
1654 x = statHistDeltaPctile(l->client_http.hitSvcTime,f->client_http.hitSvcTime, pctile);
1655 break;
1656
1657 case PCTILE_MISS:
1658 x = statHistDeltaPctile(l->client_http.missSvcTime,f->client_http.missSvcTime, pctile);
1659 break;
1660
1661 case PCTILE_NM:
1662 x = statHistDeltaPctile(l->client_http.nearMissSvcTime,f->client_http.nearMissSvcTime, pctile);
1663 break;
1664
1665 case PCTILE_NH:
1666 x = statHistDeltaPctile(l->client_http.nearHitSvcTime,f->client_http.nearHitSvcTime, pctile);
1667 break;
1668
1669 case PCTILE_ICP_QUERY:
1670 x = statHistDeltaPctile(l->icp.querySvcTime,f->icp.querySvcTime, pctile);
1671 break;
1672
1673 case PCTILE_DNS:
1674 x = statHistDeltaPctile(l->dns.svcTime,f->dns.svcTime, pctile);
1675 break;
1676
1677 default:
1678 debugs(49, 5, "statPctileSvc: unknown type.");
1679 x = 0;
1680 }
1681
1682 return x;
1683 }
1684
1685 StatCounters *
1686 snmpStatGet(int minutes)
1687 {
1688 return &CountHist[minutes];
1689 }
1690
1691 int
1692 stat5minClientRequests(void)
1693 {
1694 assert(N_COUNT_HIST > 5);
1695 return statCounter.client_http.requests - CountHist[5].client_http.requests;
1696 }
1697
1698 static double
1699 statCPUUsage(int minutes)
1700 {
1701 assert(minutes < N_COUNT_HIST);
1702 return Math::doublePercent(CountHist[0].cputime - CountHist[minutes].cputime,
1703 tvSubDsec(CountHist[minutes].timestamp, CountHist[0].timestamp));
1704 }
1705
1706 double
1707 statRequestHitRatio(int minutes)
1708 {
1709 assert(minutes < N_COUNT_HIST);
1710 return Math::doublePercent(CountHist[0].client_http.hits -
1711 CountHist[minutes].client_http.hits,
1712 CountHist[0].client_http.requests -
1713 CountHist[minutes].client_http.requests);
1714 }
1715
1716 double
1717 statRequestHitMemoryRatio(int minutes)
1718 {
1719 assert(minutes < N_COUNT_HIST);
1720 return Math::doublePercent(CountHist[0].client_http.mem_hits -
1721 CountHist[minutes].client_http.mem_hits,
1722 CountHist[0].client_http.hits -
1723 CountHist[minutes].client_http.hits);
1724 }
1725
1726 double
1727 statRequestHitDiskRatio(int minutes)
1728 {
1729 assert(minutes < N_COUNT_HIST);
1730 return Math::doublePercent(CountHist[0].client_http.disk_hits -
1731 CountHist[minutes].client_http.disk_hits,
1732 CountHist[0].client_http.hits -
1733 CountHist[minutes].client_http.hits);
1734 }
1735
1736 double
1737 statByteHitRatio(int minutes)
1738 {
1739 size_t s;
1740 size_t c;
1741 #if USE_CACHE_DIGESTS
1742
1743 size_t cd;
1744 #endif
1745 /* size_t might be unsigned */
1746 assert(minutes < N_COUNT_HIST);
1747 c = CountHist[0].client_http.kbytes_out.kb - CountHist[minutes].client_http.kbytes_out.kb;
1748 s = CountHist[0].server.all.kbytes_in.kb - CountHist[minutes].server.all.kbytes_in.kb;
1749 #if USE_CACHE_DIGESTS
1750 /*
1751 * This ugly hack is here to prevent the user from seeing a
1752 * negative byte hit ratio. When we fetch a cache digest from
1753 * a neighbor, it gets treated like a cache miss because the
1754 * object is consumed internally. Thus, we subtract cache
1755 * digest bytes out before calculating the byte hit ratio.
1756 */
1757 cd = CountHist[0].cd.kbytes_recv.kb - CountHist[minutes].cd.kbytes_recv.kb;
1758
1759 if (s < cd)
1760 debugs(18, DBG_IMPORTANT, "STRANGE: srv_kbytes=" << s << ", cd_kbytes=" << cd);
1761
1762 s -= cd;
1763
1764 #endif
1765
1766 if (c > s)
1767 return Math::doublePercent(c - s, c);
1768 else
1769 return (-1.0 * Math::doublePercent(s - c, c));
1770 }
1771
1772 static void
1773 statClientRequests(StoreEntry * s)
1774 {
1775 dlink_node *i;
1776 ClientHttpRequest *http;
1777 StoreEntry *e;
1778 char buf[MAX_IPSTRLEN];
1779
1780 for (i = ClientActiveRequests.head; i; i = i->next) {
1781 const char *p = NULL;
1782 http = static_cast<ClientHttpRequest *>(i->data);
1783 assert(http);
1784 ConnStateData * conn = http->getConn();
1785 storeAppendPrintf(s, "Connection: %p\n", conn);
1786
1787 if (conn != NULL) {
1788 const int fd = conn->clientConnection->fd;
1789 storeAppendPrintf(s, "\tFD %d, read %" PRId64 ", wrote %" PRId64 "\n", fd,
1790 fd_table[fd].bytes_read, fd_table[fd].bytes_written);
1791 storeAppendPrintf(s, "\tFD desc: %s\n", fd_table[fd].desc);
1792 storeAppendPrintf(s, "\tin: buf %p, used %ld, free %ld\n",
1793 conn->inBuf.rawContent(), (long int) conn->inBuf.length(), (long int) conn->inBuf.spaceSize());
1794 storeAppendPrintf(s, "\tremote: %s\n",
1795 conn->clientConnection->remote.toUrl(buf,MAX_IPSTRLEN));
1796 storeAppendPrintf(s, "\tlocal: %s\n",
1797 conn->clientConnection->local.toUrl(buf,MAX_IPSTRLEN));
1798 storeAppendPrintf(s, "\tnrequests: %u\n", conn->pipeline.nrequests);
1799 }
1800
1801 storeAppendPrintf(s, "uri %s\n", http->uri);
1802 storeAppendPrintf(s, "logType %s\n", http->logType.c_str());
1803 storeAppendPrintf(s, "out.offset %ld, out.size %lu\n",
1804 (long int) http->out.offset, (unsigned long int) http->out.size);
1805 storeAppendPrintf(s, "req_sz %ld\n", (long int) http->req_sz);
1806 e = http->storeEntry();
1807 storeAppendPrintf(s, "entry %p/%s\n", e, e ? e->getMD5Text() : "N/A");
1808 storeAppendPrintf(s, "start %ld.%06d (%f seconds ago)\n",
1809 (long int) http->al->cache.start_time.tv_sec,
1810 (int) http->al->cache.start_time.tv_usec,
1811 tvSubDsec(http->al->cache.start_time, current_time));
1812 #if USE_AUTH
1813 if (http->request->auth_user_request != NULL)
1814 p = http->request->auth_user_request->username();
1815 else
1816 #endif
1817 if (http->request->extacl_user.size() > 0) {
1818 p = http->request->extacl_user.termedBuf();
1819 }
1820
1821 if (!p && conn != NULL && conn->clientConnection->rfc931[0])
1822 p = conn->clientConnection->rfc931;
1823
1824 #if USE_OPENSSL
1825 if (!p && conn != NULL && Comm::IsConnOpen(conn->clientConnection))
1826 p = sslGetUserEmail(fd_table[conn->clientConnection->fd].ssl.get());
1827 #endif
1828
1829 if (!p)
1830 p = dash_str;
1831
1832 storeAppendPrintf(s, "username %s\n", p);
1833
1834 #if USE_DELAY_POOLS
1835 storeAppendPrintf(s, "delay_pool %d\n", DelayId::DelayClient(http).pool());
1836 #endif
1837
1838 storeAppendPrintf(s, "\n");
1839 }
1840 }
1841
1842 #if STAT_GRAPHS
1843 /*
1844 * urgh, i don't like these, but they do cut the amount of code down immensely
1845 */
1846
1847 #define GRAPH_PER_MIN(Y) \
1848 for (i=0;i<(N_COUNT_HIST-2);++i) { \
1849 dt = tvSubDsec(CountHist[i+1].timestamp, CountHist[i].timestamp); \
1850 if (dt <= 0.0) \
1851 break; \
1852 storeAppendPrintf(e, "%lu,%0.2f:", \
1853 CountHist[i].timestamp.tv_sec, \
1854 ((CountHist[i].Y - CountHist[i+1].Y) / dt)); \
1855 }
1856
1857 #define GRAPH_PER_HOUR(Y) \
1858 for (i=0;i<(N_COUNT_HOUR_HIST-2);++i) { \
1859 dt = tvSubDsec(CountHourHist[i+1].timestamp, CountHourHist[i].timestamp); \
1860 if (dt <= 0.0) \
1861 break; \
1862 storeAppendPrintf(e, "%lu,%0.2f:", \
1863 CountHourHist[i].timestamp.tv_sec, \
1864 ((CountHourHist[i].Y - CountHourHist[i+1].Y) / dt)); \
1865 }
1866
1867 #define GRAPH_TITLE(X,Y) storeAppendPrintf(e,"%s\t%s\t",X,Y);
1868 #define GRAPH_END storeAppendPrintf(e,"\n");
1869
1870 #define GENGRAPH(X,Y,Z) \
1871 GRAPH_TITLE(Y,Z) \
1872 GRAPH_PER_MIN(X) \
1873 GRAPH_PER_HOUR(X) \
1874 GRAPH_END
1875
1876 static void
1877 statGraphDump(StoreEntry * e)
1878 {
1879 int i;
1880 double dt;
1881
1882 GENGRAPH(client_http.requests, "client_http.requests", "Client HTTP requests/sec");
1883 GENGRAPH(client_http.hits, "client_http.hits", "Client HTTP hits/sec");
1884 GENGRAPH(client_http.errors, "client_http.errors", "Client HTTP errors/sec");
1885 GENGRAPH(client_http.kbytes_in.kb, "client_http.kbytes_in", "Client HTTP kbytes_in/sec");
1886 GENGRAPH(client_http.kbytes_out.kb, "client_http.kbytes_out", "Client HTTP kbytes_out/sec");
1887
1888 /* XXX todo: http median service times */
1889
1890 GENGRAPH(server.all.requests, "server.all.requests", "Server requests/sec");
1891 GENGRAPH(server.all.errors, "server.all.errors", "Server errors/sec");
1892 GENGRAPH(server.all.kbytes_in.kb, "server.all.kbytes_in", "Server total kbytes_in/sec");
1893 GENGRAPH(server.all.kbytes_out.kb, "server.all.kbytes_out", "Server total kbytes_out/sec");
1894
1895 GENGRAPH(server.http.requests, "server.http.requests", "Server HTTP requests/sec");
1896 GENGRAPH(server.http.errors, "server.http.errors", "Server HTTP errors/sec");
1897 GENGRAPH(server.http.kbytes_in.kb, "server.http.kbytes_in", "Server HTTP kbytes_in/sec");
1898 GENGRAPH(server.http.kbytes_out.kb, "server.http.kbytes_out", "Server HTTP kbytes_out/sec");
1899
1900 GENGRAPH(server.ftp.requests, "server.ftp.requests", "Server FTP requests/sec");
1901 GENGRAPH(server.ftp.errors, "server.ftp.errors", "Server FTP errors/sec");
1902 GENGRAPH(server.ftp.kbytes_in.kb, "server.ftp.kbytes_in", "Server FTP kbytes_in/sec");
1903 GENGRAPH(server.ftp.kbytes_out.kb, "server.ftp.kbytes_out", "Server FTP kbytes_out/sec");
1904
1905 GENGRAPH(server.other.requests, "server.other.requests", "Server other requests/sec");
1906 GENGRAPH(server.other.errors, "server.other.errors", "Server other errors/sec");
1907 GENGRAPH(server.other.kbytes_in.kb, "server.other.kbytes_in", "Server other kbytes_in/sec");
1908 GENGRAPH(server.other.kbytes_out.kb, "server.other.kbytes_out", "Server other kbytes_out/sec");
1909
1910 GENGRAPH(icp.pkts_sent, "icp.pkts_sent", "ICP packets sent/sec");
1911 GENGRAPH(icp.pkts_recv, "icp.pkts_recv", "ICP packets received/sec");
1912 GENGRAPH(icp.kbytes_sent.kb, "icp.kbytes_sent", "ICP kbytes_sent/sec");
1913 GENGRAPH(icp.kbytes_recv.kb, "icp.kbytes_recv", "ICP kbytes_received/sec");
1914
1915 /* XXX todo: icp median service times */
1916 /* XXX todo: dns median service times */
1917
1918 GENGRAPH(unlink.requests, "unlink.requests", "Cache File unlink requests/sec");
1919 GENGRAPH(page_faults, "page_faults", "System Page Faults/sec");
1920 GENGRAPH(select_loops, "select_loops", "System Select Loop calls/sec");
1921 GENGRAPH(cputime, "cputime", "CPU utilisation");
1922 }
1923
1924 #endif /* STAT_GRAPHS */
1925
1926 int
1927 statMemoryAccounted(void)
1928 {
1929 return memPoolsTotalAllocated();
1930 }
1931