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