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