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