2 * Copyright (C) 1996-2025 The Squid Software Foundation and contributors
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.
9 /* DEBUG: section 18 Cache Manager Statistics */
12 #include "AccessLogEntry.h"
13 #include "CacheDigest.h"
14 #include "CachePeer.h"
15 #include "CachePeers.h"
16 #include "client_side.h"
17 #include "client_side_request.h"
18 #include "comm/Connection.h"
19 #include "comm/Loops.h"
22 #include "format/Token.h"
24 #include "http/Stream.h"
25 #include "HttpRequest.h"
28 #include "mem/Stats.h"
31 #include "MemObject.h"
32 #include "mgr/CountersAction.h"
33 #include "mgr/FunAction.h"
34 #include "mgr/InfoAction.h"
35 #include "mgr/IntervalAction.h"
36 #include "mgr/IoAction.h"
37 #include "mgr/Registration.h"
38 #include "mgr/ServiceTimesAction.h"
39 #include "neighbors.h"
40 #include "PeerDigest.h"
41 #include "SquidConfig.h"
42 #include "SquidMath.h"
44 #include "StatCounters.h"
46 #include "store_digest.h"
47 #include "StoreClient.h"
50 #include "auth/UserRequest.h"
56 #include "ssl/support.h"
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
64 #include "StoreSearch.h"
66 typedef int STOBJFLT(const StoreEntry
*);
68 class StatObjectsState
70 CBDATA_CLASS(StatObjectsState
);
75 StoreSearchPointer theSearch
;
79 static const char *describeStatuses(const StoreEntry
*);
80 static void statAvgTick(void *notused
);
81 static void statAvgDump(StoreEntry
*, int minutes
, int hours
);
83 static void statGraphDump(StoreEntry
*);
85 static double statPctileSvc(double, int, int);
86 static void statStoreEntry(MemBuf
* mb
, StoreEntry
* e
);
87 static double statCPUUsage(int minutes
);
88 static OBJH stat_objects_get
;
89 static OBJH stat_vmobjects_get
;
90 static OBJH statOpenfdObj
;
91 static EVH statObjects
;
92 static OBJH statCountersDump
;
93 static OBJH statPeerSelect
;
94 static OBJH statDigestBlob
;
95 static OBJH statUtilization
;
96 static OBJH statCountersHistograms
;
97 static OBJH statClientRequests
;
98 void GetAvgStat(Mgr::IntervalActionData
& stats
, int minutes
, int hours
);
99 void DumpAvgStat(Mgr::IntervalActionData
& stats
, StoreEntry
* sentry
);
100 void GetInfo(Mgr::InfoActionData
& stats
);
101 void DumpInfo(Mgr::InfoActionData
& stats
, StoreEntry
* sentry
);
102 void DumpMallocStatistics(StoreEntry
* sentry
);
103 void GetCountersStats(Mgr::CountersActionData
& stats
);
104 void DumpCountersStats(Mgr::CountersActionData
& stats
, StoreEntry
* sentry
);
105 void GetServiceTimesStats(Mgr::ServiceTimesActionData
& stats
);
106 void DumpServiceTimesStats(Mgr::ServiceTimesActionData
& stats
, StoreEntry
* sentry
);
107 void GetIoStats(Mgr::IoActionData
& stats
);
108 void DumpIoStats(Mgr::IoActionData
& stats
, StoreEntry
* sentry
);
110 #if XMALLOC_STATISTICS
111 static void info_get_mallstat(int, int, int, void *);
112 static double xm_time
;
113 static double xm_deltat
;
116 StatCounters CountHist
[N_COUNT_HIST
];
117 static int NCountHist
= 0;
118 static StatCounters CountHourHist
[N_COUNT_HOUR_HIST
];
119 static int NCountHourHist
= 0;
120 CBDATA_CLASS_INIT(StatObjectsState
);
122 extern unsigned int mem_pool_alloc_calls
;
123 extern unsigned int mem_pool_free_calls
;
126 statUtilization(StoreEntry
* e
)
128 storeAppendPrintf(e
, "Cache Utilisation:\n");
129 storeAppendPrintf(e
, "\n");
130 storeAppendPrintf(e
, "Last 5 minutes:\n");
133 statAvgDump(e
, 5, 0);
135 storeAppendPrintf(e
, "(no values recorded yet)\n");
137 storeAppendPrintf(e
, "\n");
139 storeAppendPrintf(e
, "Last 15 minutes:\n");
141 if (NCountHist
>= 15)
142 statAvgDump(e
, 15, 0);
144 storeAppendPrintf(e
, "(no values recorded yet)\n");
146 storeAppendPrintf(e
, "\n");
148 storeAppendPrintf(e
, "Last hour:\n");
150 if (NCountHist
>= 60)
151 statAvgDump(e
, 60, 0);
153 storeAppendPrintf(e
, "(no values recorded yet)\n");
155 storeAppendPrintf(e
, "\n");
157 storeAppendPrintf(e
, "Last 8 hours:\n");
159 if (NCountHourHist
>= 8)
160 statAvgDump(e
, 0, 8);
162 storeAppendPrintf(e
, "(no values recorded yet)\n");
164 storeAppendPrintf(e
, "\n");
166 storeAppendPrintf(e
, "Last day:\n");
168 if (NCountHourHist
>= 24)
169 statAvgDump(e
, 0, 24);
171 storeAppendPrintf(e
, "(no values recorded yet)\n");
173 storeAppendPrintf(e
, "\n");
175 storeAppendPrintf(e
, "Last 3 days:\n");
177 if (NCountHourHist
>= 72)
178 statAvgDump(e
, 0, 72);
180 storeAppendPrintf(e
, "(no values recorded yet)\n");
182 storeAppendPrintf(e
, "\n");
184 storeAppendPrintf(e
, "Totals since cache startup:\n");
190 GetIoStats(Mgr::IoActionData
& stats
)
194 stats
.http_reads
= IOStats
.Http
.reads
;
196 for (i
= 0; i
< IoStats::histSize
; ++i
) {
197 stats
.http_read_hist
[i
] = IOStats
.Http
.read_hist
[i
];
200 stats
.ftp_reads
= IOStats
.Ftp
.reads
;
202 for (i
= 0; i
< IoStats::histSize
; ++i
) {
203 stats
.ftp_read_hist
[i
] = IOStats
.Ftp
.read_hist
[i
];
208 DumpIoStats(Mgr::IoActionData
& stats
, StoreEntry
* sentry
)
212 storeAppendPrintf(sentry
, "HTTP I/O\n");
213 storeAppendPrintf(sentry
, "number of reads: %.0f\n", stats
.http_reads
);
214 storeAppendPrintf(sentry
, "Read Histogram:\n");
216 for (i
= 0; i
< IoStats::histSize
; ++i
) {
217 storeAppendPrintf(sentry
, "%5d-%5d: %9.0f %2.0f%%\n",
218 i
? (1 << (i
- 1)) + 1 : 1,
220 stats
.http_read_hist
[i
],
221 Math::doublePercent(stats
.http_read_hist
[i
], stats
.http_reads
));
224 storeAppendPrintf(sentry
, "\n");
225 storeAppendPrintf(sentry
, "FTP I/O\n");
226 storeAppendPrintf(sentry
, "number of reads: %.0f\n", stats
.ftp_reads
);
227 storeAppendPrintf(sentry
, "Read Histogram:\n");
229 for (i
= 0; i
< IoStats::histSize
; ++i
) {
230 storeAppendPrintf(sentry
, "%5d-%5d: %9.0f %2.0f%%\n",
231 i
? (1 << (i
- 1)) + 1 : 1,
233 stats
.ftp_read_hist
[i
],
234 Math::doublePercent(stats
.ftp_read_hist
[i
], stats
.ftp_reads
));
237 storeAppendPrintf(sentry
, "\n");
241 describeStatuses(const StoreEntry
* entry
)
243 LOCAL_ARRAY(char, buf
, 256);
244 snprintf(buf
, 256, "%-13s %-13s %-12s %-12s",
245 storeStatusStr
[entry
->store_status
],
246 memStatusStr
[entry
->mem_status
],
247 swapStatusStr
[entry
->swap_status
],
248 pingStatusStr
[entry
->ping_status
]);
253 storeEntryFlags(const StoreEntry
* entry
)
255 LOCAL_ARRAY(char, buf
, 256);
256 int flags
= (int) entry
->flags
;
260 if (EBIT_TEST(flags
, ENTRY_SPECIAL
))
261 strcat(buf
, "SPECIAL,");
263 if (EBIT_TEST(flags
, ENTRY_REVALIDATE_ALWAYS
))
264 strcat(buf
, "REVALIDATE_ALWAYS,");
266 if (EBIT_TEST(flags
, DELAY_SENDING
))
267 strcat(buf
, "DELAY_SENDING,");
269 if (EBIT_TEST(flags
, RELEASE_REQUEST
))
270 strcat(buf
, "RELEASE_REQUEST,");
272 if (EBIT_TEST(flags
, REFRESH_REQUEST
))
273 strcat(buf
, "REFRESH_REQUEST,");
275 if (EBIT_TEST(flags
, ENTRY_REVALIDATE_STALE
))
276 strcat(buf
, "REVALIDATE_STALE,");
278 if (EBIT_TEST(flags
, ENTRY_DISPATCHED
))
279 strcat(buf
, "DISPATCHED,");
281 if (EBIT_TEST(flags
, KEY_PRIVATE
))
282 strcat(buf
, "PRIVATE,");
284 if (EBIT_TEST(flags
, ENTRY_FWD_HDR_WAIT
))
285 strcat(buf
, "FWD_HDR_WAIT,");
287 if (EBIT_TEST(flags
, ENTRY_NEGCACHED
))
288 strcat(buf
, "NEGCACHED,");
290 if (EBIT_TEST(flags
, ENTRY_VALIDATED
))
291 strcat(buf
, "VALIDATED,");
293 if (EBIT_TEST(flags
, ENTRY_BAD_LENGTH
))
294 strcat(buf
, "BAD_LENGTH,");
296 if (EBIT_TEST(flags
, ENTRY_ABORTED
))
297 strcat(buf
, "ABORTED,");
299 if ((t
= strrchr(buf
, ',')))
306 statStoreEntry(MemBuf
* mb
, StoreEntry
* e
)
308 MemObject
*mem
= e
->mem_obj
;
309 mb
->appendf("KEY %s\n", e
->getMD5Text());
310 mb
->appendf("\t%s\n", describeStatuses(e
));
311 mb
->appendf("\t%s\n", storeEntryFlags(e
));
312 mb
->appendf("\t%s\n", e
->describeTimestamps());
313 mb
->appendf("\t%d locks, %d clients, %d refs\n", (int) e
->locks(), storePendingNClients(e
), (int) e
->refcount
);
314 mb
->appendf("\tSwap Dir %d, File %#08X\n", e
->swap_dirn
, e
->swap_filen
);
322 /* process objects list */
324 statObjects(void *data
)
326 StatObjectsState
*state
= static_cast<StatObjectsState
*>(data
);
329 if (state
->theSearch
->isDone()) {
330 Mgr::CloseKidSection(state
->sentry
, Mgr::Format::informal
);
331 state
->sentry
->complete();
332 state
->sentry
->unlock("statObjects+isDone");
335 } else if (EBIT_TEST(state
->sentry
->flags
, ENTRY_ABORTED
)) {
336 state
->sentry
->unlock("statObjects+aborted");
339 } else if (state
->sentry
->checkDeferRead(-1)) {
340 state
->sentry
->flush();
341 eventAdd("statObjects", statObjects
, state
, 0.1, 1);
345 state
->sentry
->buffer();
346 size_t statCount
= 0;
350 while (statCount
++ < static_cast<size_t>(Config
.Store
.objectsPerBucket
) && state
->
352 e
= state
->theSearch
->currentItem();
354 if (state
->filter
&& 0 == state
->filter(e
))
357 statStoreEntry(&mb
, e
);
361 state
->sentry
->append(mb
.buf
, mb
.size
);
364 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
368 statObjectsStart(StoreEntry
* sentry
, STOBJFLT
* filter
)
370 StatObjectsState
*state
= new StatObjectsState
;
371 state
->sentry
= sentry
;
372 state
->filter
= filter
;
374 sentry
->lock("statObjects");
375 state
->theSearch
= Store::Root().search();
377 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
381 stat_objects_get(StoreEntry
* sentry
)
383 statObjectsStart(sentry
, nullptr);
387 statObjectsVmFilter(const StoreEntry
* e
)
389 return e
->mem_obj
? 1 : 0;
393 stat_vmobjects_get(StoreEntry
* sentry
)
395 statObjectsStart(sentry
, statObjectsVmFilter
);
399 statObjectsOpenfdFilter(const StoreEntry
* e
)
401 if (e
->mem_obj
== nullptr)
404 if (e
->mem_obj
->swapout
.sio
== nullptr)
411 statOpenfdObj(StoreEntry
* sentry
)
413 statObjectsStart(sentry
, statObjectsOpenfdFilter
);
416 #if XMALLOC_STATISTICS
418 info_get_mallstat(int size
, int number
, int oldnum
, void *data
)
420 StoreEntry
*sentry
= (StoreEntry
*)data
;
422 // format: "%12s %15s %6s %12s\n","Alloc Size","Count","Delta","Alloc/sec"
424 storeAppendPrintf(sentry
, "%12d %15d %6d %.1f\n", size
, number
, number
- oldnum
, xdiv((number
- oldnum
), xm_deltat
));
430 GetInfo(Mgr::InfoActionData
& stats
)
433 struct rusage rusage
;
436 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
440 runtime
= tvSubDsec(squid_start
, current_time
);
445 stats
.squid_start
= squid_start
;
447 stats
.current_time
= current_time
;
449 stats
.client_http_clients
= statCounter
.client_http
.clients
;
451 stats
.client_http_requests
= statCounter
.client_http
.requests
;
453 stats
.icp_pkts_recv
= statCounter
.icp
.pkts_recv
;
455 stats
.icp_pkts_sent
= statCounter
.icp
.pkts_sent
;
457 stats
.icp_replies_queued
= statCounter
.icp
.replies_queued
;
461 stats
.htcp_pkts_recv
= statCounter
.htcp
.pkts_recv
;
463 stats
.htcp_pkts_sent
= statCounter
.htcp
.pkts_sent
;
467 stats
.request_failure_ratio
= request_failure_ratio
;
469 stats
.avg_client_http_requests
= statCounter
.client_http
.requests
/ (runtime
/ 60.0);
471 stats
.avg_icp_messages
= (statCounter
.icp
.pkts_sent
+ statCounter
.icp
.pkts_recv
) / (runtime
/ 60.0);
473 stats
.select_loops
= statCounter
.select_loops
;
474 stats
.avg_loop_time
= 1000.0 * runtime
/ statCounter
.select_loops
;
476 stats
.request_hit_ratio5
= statRequestHitRatio(5);
477 stats
.request_hit_ratio60
= statRequestHitRatio(60);
479 stats
.byte_hit_ratio5
= statByteHitRatio(5);
480 stats
.byte_hit_ratio60
= statByteHitRatio(60);
482 stats
.request_hit_mem_ratio5
= statRequestHitMemoryRatio(5);
483 stats
.request_hit_mem_ratio60
= statRequestHitMemoryRatio(60);
485 stats
.request_hit_disk_ratio5
= statRequestHitDiskRatio(5);
486 stats
.request_hit_disk_ratio60
= statRequestHitDiskRatio(60);
488 Store::Root().getStats(stats
.store
);
490 stats
.unlink_requests
= statCounter
.unlink
.requests
;
492 stats
.http_requests5
= statPctileSvc(0.5, 5, PCTILE_HTTP
);
493 stats
.http_requests60
= statPctileSvc(0.5, 60, PCTILE_HTTP
);
495 stats
.cache_misses5
= statPctileSvc(0.5, 5, PCTILE_MISS
);
496 stats
.cache_misses60
= statPctileSvc(0.5, 60, PCTILE_MISS
);
498 stats
.cache_hits5
= statPctileSvc(0.5, 5, PCTILE_HIT
);
499 stats
.cache_hits60
= statPctileSvc(0.5, 60, PCTILE_HIT
);
501 stats
.near_hits5
= statPctileSvc(0.5, 5, PCTILE_NH
);
502 stats
.near_hits60
= statPctileSvc(0.5, 60, PCTILE_NH
);
504 stats
.not_modified_replies5
= statPctileSvc(0.5, 5, PCTILE_NM
);
505 stats
.not_modified_replies60
= statPctileSvc(0.5, 60, PCTILE_NM
);
507 stats
.dns_lookups5
= statPctileSvc(0.5, 5, PCTILE_DNS
);
508 stats
.dns_lookups60
= statPctileSvc(0.5, 60, PCTILE_DNS
);
510 stats
.icp_queries5
= statPctileSvc(0.5, 5, PCTILE_ICP_QUERY
);
511 stats
.icp_queries60
= statPctileSvc(0.5, 60, PCTILE_ICP_QUERY
);
513 squid_getrusage(&rusage
);
514 cputime
= rusage_cputime(&rusage
);
516 stats
.up_time
= runtime
;
517 stats
.cpu_time
= cputime
;
518 stats
.cpu_usage
= Math::doublePercent(cputime
, runtime
);
519 stats
.cpu_usage5
= statCPUUsage(5);
520 stats
.cpu_usage60
= statCPUUsage(60);
522 stats
.maxrss
= rusage_maxrss(&rusage
);
524 stats
.page_faults
= rusage_pagefaults(&rusage
);
526 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
530 stats
.ms_bytes_total
= ms
.bytes_total
;
532 stats
.ms_bytes_free
= ms
.bytes_free
;
537 Mem::PoolStats mp_stats
;
538 Mem::GlobalStats(mp_stats
);
539 stats
.gb_saved_count
= mp_stats
.meter
->gb_saved
.count
;
540 stats
.gb_freed_count
= mp_stats
.meter
->gb_freed
.count
;
541 stats
.total_accounted
= mp_stats
.meter
->alloc
.currentLevel();
544 stats
.max_fd
= Squid_MaxFD
;
545 stats
.biggest_fd
= Biggest_FD
;
546 stats
.number_fd
= Number_FD
;
547 stats
.opening_fd
= Opening_FD
;
548 stats
.num_fd_free
= fdNFree();
549 stats
.reserved_fd
= RESERVED_FD
;
553 DumpInfo(Mgr::InfoActionData
& stats
, StoreEntry
* sentry
)
555 storeAppendPrintf(sentry
, "Squid Object Cache: Version %s\n",
558 storeAppendPrintf(sentry
, "Build Info: " SQUID_BUILD_INFO
"\n");
561 if (WIN32_run_mode
== _WIN_SQUID_RUN_MODE_SERVICE
) {
562 storeAppendPrintf(sentry
,"\nRunning as " SQUIDSBUFPH
" Windows System Service on %s\n",
563 SQUIDSBUFPRINT(service_name
), WIN32_OS_string
);
564 storeAppendPrintf(sentry
,"Service command line is: %s\n", WIN32_Service_Command_Line
);
566 storeAppendPrintf(sentry
,"Running on %s\n",WIN32_OS_string
);
568 storeAppendPrintf(sentry
,"Service Name: " SQUIDSBUFPH
"\n", SQUIDSBUFPRINT(service_name
));
571 storeAppendPrintf(sentry
, "Start Time:\t%s\n",
572 Time::FormatRfc1123(stats
.squid_start
.tv_sec
));
574 storeAppendPrintf(sentry
, "Current Time:\t%s\n",
575 Time::FormatRfc1123(stats
.current_time
.tv_sec
));
577 storeAppendPrintf(sentry
, "Connection information for %s:\n",APP_SHORTNAME
);
579 if (Config
.onoff
.client_db
)
580 storeAppendPrintf(sentry
, "\tNumber of clients accessing cache:\t%.0f\n", stats
.client_http_clients
);
582 sentry
->append("\tNumber of clients accessing cache:\t(client_db off)\n", 52);
584 storeAppendPrintf(sentry
, "\tNumber of HTTP requests received:\t%.0f\n",
585 stats
.client_http_requests
);
587 storeAppendPrintf(sentry
, "\tNumber of ICP messages received:\t%.0f\n",
588 stats
.icp_pkts_recv
);
590 storeAppendPrintf(sentry
, "\tNumber of ICP messages sent:\t%.0f\n",
591 stats
.icp_pkts_sent
);
593 storeAppendPrintf(sentry
, "\tNumber of queued ICP replies:\t%.0f\n",
594 stats
.icp_replies_queued
);
598 storeAppendPrintf(sentry
, "\tNumber of HTCP messages received:\t%.0f\n",
599 stats
.htcp_pkts_recv
);
601 storeAppendPrintf(sentry
, "\tNumber of HTCP messages sent:\t%.0f\n",
602 stats
.htcp_pkts_sent
);
606 double fct
= stats
.count
> 1 ? stats
.count
: 1.0;
607 storeAppendPrintf(sentry
, "\tRequest failure ratio:\t%5.2f\n",
608 stats
.request_failure_ratio
/ fct
);
610 storeAppendPrintf(sentry
, "\tAverage HTTP requests per minute since start:\t%.1f\n",
611 stats
.avg_client_http_requests
);
613 storeAppendPrintf(sentry
, "\tAverage ICP messages per minute since start:\t%.1f\n",
614 stats
.avg_icp_messages
);
616 storeAppendPrintf(sentry
, "\tSelect loop called: %.0f times, %0.3f ms avg\n",
617 stats
.select_loops
, stats
.avg_loop_time
/ fct
);
619 storeAppendPrintf(sentry
, "Cache information for %s:\n",APP_SHORTNAME
);
621 storeAppendPrintf(sentry
, "\tHits as %% of all requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
622 stats
.request_hit_ratio5
/ fct
,
623 stats
.request_hit_ratio60
/ fct
);
625 storeAppendPrintf(sentry
, "\tHits as %% of bytes sent:\t5min: %3.1f%%, 60min: %3.1f%%\n",
626 stats
.byte_hit_ratio5
/ fct
,
627 stats
.byte_hit_ratio60
/ fct
);
629 storeAppendPrintf(sentry
, "\tMemory hits as %% of hit requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
630 stats
.request_hit_mem_ratio5
/ fct
,
631 stats
.request_hit_mem_ratio60
/ fct
);
633 storeAppendPrintf(sentry
, "\tDisk hits as %% of hit requests:\t5min: %3.1f%%, 60min: %3.1f%%\n",
634 stats
.request_hit_disk_ratio5
/ fct
,
635 stats
.request_hit_disk_ratio60
/ fct
);
637 storeAppendPrintf(sentry
, "\tStorage Swap size:\t%.0f KB\n",
638 stats
.store
.swap
.size
/ 1024);
640 storeAppendPrintf(sentry
, "\tStorage Swap capacity:\t%4.1f%% used, %4.1f%% free\n",
641 Math::doublePercent(stats
.store
.swap
.size
, stats
.store
.swap
.capacity
),
642 Math::doublePercent(stats
.store
.swap
.available(), stats
.store
.swap
.capacity
));
644 storeAppendPrintf(sentry
, "\tStorage Mem size:\t%.0f KB\n",
645 stats
.store
.mem
.size
/ 1024);
647 storeAppendPrintf(sentry
, "\tStorage Mem capacity:\t%4.1f%% used, %4.1f%% free\n",
648 Math::doublePercent(stats
.store
.mem
.size
, stats
.store
.mem
.capacity
),
649 Math::doublePercent(stats
.store
.mem
.available(), stats
.store
.mem
.capacity
));
651 storeAppendPrintf(sentry
, "\tMean Object Size:\t%0.2f KB\n",
652 stats
.store
.swap
.meanObjectSize() / 1024);
654 storeAppendPrintf(sentry
, "\tRequests given to unlinkd:\t%.0f\n",
655 stats
.unlink_requests
);
657 storeAppendPrintf(sentry
, "Median Service Times (seconds) 5 min 60 min:\n");
659 fct
= stats
.count
> 1 ? stats
.count
* 1000.0 : 1000.0;
660 storeAppendPrintf(sentry
, "\tHTTP Requests (All): %8.5f %8.5f\n",
661 stats
.http_requests5
/ fct
,
662 stats
.http_requests60
/ fct
);
664 storeAppendPrintf(sentry
, "\tCache Misses: %8.5f %8.5f\n",
665 stats
.cache_misses5
/ fct
,
666 stats
.cache_misses60
/ fct
);
668 storeAppendPrintf(sentry
, "\tCache Hits: %8.5f %8.5f\n",
669 stats
.cache_hits5
/ fct
,
670 stats
.cache_hits60
/ fct
);
672 storeAppendPrintf(sentry
, "\tNear Hits: %8.5f %8.5f\n",
673 stats
.near_hits5
/ fct
,
674 stats
.near_hits60
/ fct
);
676 storeAppendPrintf(sentry
, "\tNot-Modified Replies: %8.5f %8.5f\n",
677 stats
.not_modified_replies5
/ fct
,
678 stats
.not_modified_replies60
/ fct
);
680 storeAppendPrintf(sentry
, "\tDNS Lookups: %8.5f %8.5f\n",
681 stats
.dns_lookups5
/ fct
,
682 stats
.dns_lookups60
/ fct
);
684 fct
= stats
.count
> 1 ? stats
.count
* 1000000.0 : 1000000.0;
685 storeAppendPrintf(sentry
, "\tICP Queries: %8.5f %8.5f\n",
686 stats
.icp_queries5
/ fct
,
687 stats
.icp_queries60
/ fct
);
689 storeAppendPrintf(sentry
, "Resource usage for %s:\n", APP_SHORTNAME
);
691 storeAppendPrintf(sentry
, "\tUP Time:\t%.3f seconds\n", stats
.up_time
);
693 storeAppendPrintf(sentry
, "\tCPU Time:\t%.3f seconds\n", stats
.cpu_time
);
695 storeAppendPrintf(sentry
, "\tCPU Usage:\t%.2f%%\n",
698 storeAppendPrintf(sentry
, "\tCPU Usage, 5 minute avg:\t%.2f%%\n",
701 storeAppendPrintf(sentry
, "\tCPU Usage, 60 minute avg:\t%.2f%%\n",
704 storeAppendPrintf(sentry
, "\tMaximum Resident Size: %.0f KB\n",
707 storeAppendPrintf(sentry
, "\tPage faults with physical i/o: %.0f\n",
710 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
712 storeAppendPrintf(sentry
, "Memory usage for %s via mstats():\n",APP_SHORTNAME
);
714 storeAppendPrintf(sentry
, "\tTotal space in arena: %6.0f KB\n",
715 stats
.ms_bytes_total
/ 1024);
717 storeAppendPrintf(sentry
, "\tTotal free: %6.0f KB %.0f%%\n",
718 stats
.ms_bytes_free
/ 1024,
719 Math::doublePercent(stats
.ms_bytes_free
, stats
.ms_bytes_total
));
723 storeAppendPrintf(sentry
, "Memory accounted for:\n");
724 storeAppendPrintf(sentry
, "\tTotal accounted: %6.0f KB\n",
725 stats
.total_accounted
/ 1024);
727 Mem::PoolStats mp_stats
;
728 Mem::GlobalStats(mp_stats
); // XXX: called just for its side effects
729 storeAppendPrintf(sentry
, "\tmemPoolAlloc calls: %9.0f\n",
730 stats
.gb_saved_count
);
731 storeAppendPrintf(sentry
, "\tmemPoolFree calls: %9.0f\n",
732 stats
.gb_freed_count
);
735 storeAppendPrintf(sentry
, "File descriptor usage for %s:\n", APP_SHORTNAME
);
736 storeAppendPrintf(sentry
, "\tMaximum number of file descriptors: %4.0f\n",
738 storeAppendPrintf(sentry
, "\tLargest file desc currently in use: %4.0f\n",
740 storeAppendPrintf(sentry
, "\tNumber of file desc currently in use: %4.0f\n",
742 storeAppendPrintf(sentry
, "\tFiles queued for open: %4.0f\n",
744 storeAppendPrintf(sentry
, "\tAvailable number of file descriptors: %4.0f\n",
746 storeAppendPrintf(sentry
, "\tReserved number of file descriptors: %4.0f\n",
748 storeAppendPrintf(sentry
, "\tStore Disk files open: %4.0f\n",
749 stats
.store
.swap
.open_disk_fd
);
751 storeAppendPrintf(sentry
, "Internal Data Structures:\n");
752 storeAppendPrintf(sentry
, "\t%6.0f StoreEntries\n",
753 stats
.store
.store_entry_count
);
754 storeAppendPrintf(sentry
, "\t%6.0f StoreEntries with MemObjects\n",
755 stats
.store
.mem_object_count
);
756 storeAppendPrintf(sentry
, "\t%6.0f Hot Object Cache Items\n",
757 stats
.store
.mem
.count
);
758 storeAppendPrintf(sentry
, "\t%6.0f on-disk objects\n",
759 stats
.store
.swap
.count
);
763 DumpMallocStatistics(StoreEntry
* sentry
)
765 #if XMALLOC_STATISTICS
766 xm_deltat
= current_dtime
- xm_time
;
767 xm_time
= current_dtime
;
768 storeAppendPrintf(sentry
, "\nMemory allocation statistics\n");
769 storeAppendPrintf(sentry
, "%12s %15s %6s %12s\n","Alloc Size","Count","Delta","Alloc/sec");
770 malloc_statistics(info_get_mallstat
, sentry
);
777 GetServiceTimesStats(Mgr::ServiceTimesActionData
& stats
)
779 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
780 double p
= (i
+ 1) * 5 / 100.0;
781 stats
.http_requests5
[i
] = statPctileSvc(p
, 5, PCTILE_HTTP
);
782 stats
.http_requests60
[i
] = statPctileSvc(p
, 60, PCTILE_HTTP
);
784 stats
.cache_misses5
[i
] = statPctileSvc(p
, 5, PCTILE_MISS
);
785 stats
.cache_misses60
[i
] = statPctileSvc(p
, 60, PCTILE_MISS
);
787 stats
.cache_hits5
[i
] = statPctileSvc(p
, 5, PCTILE_HIT
);
788 stats
.cache_hits60
[i
] = statPctileSvc(p
, 60, PCTILE_HIT
);
790 stats
.near_hits5
[i
] = statPctileSvc(p
, 5, PCTILE_NH
);
791 stats
.near_hits60
[i
] = statPctileSvc(p
, 60, PCTILE_NH
);
793 stats
.not_modified_replies5
[i
] = statPctileSvc(p
, 5, PCTILE_NM
);
794 stats
.not_modified_replies60
[i
] = statPctileSvc(p
, 60, PCTILE_NM
);
796 stats
.dns_lookups5
[i
] = statPctileSvc(p
, 5, PCTILE_DNS
);
797 stats
.dns_lookups60
[i
] = statPctileSvc(p
, 60, PCTILE_DNS
);
799 stats
.icp_queries5
[i
] = statPctileSvc(p
, 5, PCTILE_ICP_QUERY
);
800 stats
.icp_queries60
[i
] = statPctileSvc(p
, 60, PCTILE_ICP_QUERY
);
805 DumpServiceTimesStats(Mgr::ServiceTimesActionData
& stats
, StoreEntry
* sentry
)
807 storeAppendPrintf(sentry
, "Service Time Percentiles 5 min 60 min:\n");
808 double fct
= stats
.count
> 1 ? stats
.count
* 1000.0 : 1000.0;
809 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
810 storeAppendPrintf(sentry
, "\tHTTP Requests (All): %2d%% %8.5f %8.5f\n",
812 stats
.http_requests5
[i
] / fct
,
813 stats
.http_requests60
[i
] / fct
);
815 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
816 storeAppendPrintf(sentry
, "\tCache Misses: %2d%% %8.5f %8.5f\n",
818 stats
.cache_misses5
[i
] / fct
,
819 stats
.cache_misses60
[i
] / fct
);
821 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
822 storeAppendPrintf(sentry
, "\tCache Hits: %2d%% %8.5f %8.5f\n",
824 stats
.cache_hits5
[i
] / fct
,
825 stats
.cache_hits60
[i
] / fct
);
827 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
828 storeAppendPrintf(sentry
, "\tNear Hits: %2d%% %8.5f %8.5f\n",
830 stats
.near_hits5
[i
] / fct
,
831 stats
.near_hits60
[i
] / fct
);
833 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
834 storeAppendPrintf(sentry
, "\tNot-Modified Replies: %2d%% %8.5f %8.5f\n",
836 stats
.not_modified_replies5
[i
] / fct
,
837 stats
.not_modified_replies60
[i
] / fct
);
839 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
840 storeAppendPrintf(sentry
, "\tDNS Lookups: %2d%% %8.5f %8.5f\n",
842 stats
.dns_lookups5
[i
] / fct
,
843 stats
.dns_lookups60
[i
] / fct
);
845 fct
= stats
.count
> 1 ? stats
.count
* 1000000.0 : 1000000.0;
846 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
847 storeAppendPrintf(sentry
, "\tICP Queries: %2d%% %8.5f %8.5f\n",
849 stats
.icp_queries5
[i
] / fct
,
850 stats
.icp_queries60
[i
] / fct
);
855 statAvgDump(StoreEntry
* sentry
, int minutes
, int hours
)
857 Mgr::IntervalActionData stats
;
858 GetAvgStat(stats
, minutes
, hours
);
859 DumpAvgStat(stats
, sentry
);
862 #define XAVG(X) (dt ? (double) (f->X - l->X) / dt : 0.0)
864 GetAvgStat(Mgr::IntervalActionData
& stats
, int minutes
, int hours
)
870 assert(N_COUNT_HIST
> 1);
871 assert(minutes
> 0 || hours
> 0);
875 if (minutes
> 0 && hours
== 0) {
876 /* checking minute readings ... */
878 if (minutes
> N_COUNT_HIST
- 1)
879 minutes
= N_COUNT_HIST
- 1;
881 l
= &CountHist
[minutes
];
882 } else if (minutes
== 0 && hours
> 0) {
883 /* checking hour readings ... */
885 if (hours
> N_COUNT_HOUR_HIST
- 1)
886 hours
= N_COUNT_HOUR_HIST
- 1;
888 l
= &CountHourHist
[hours
];
890 debugs(18, DBG_IMPORTANT
, "ERROR: statAvgDump: Invalid args, minutes=" << minutes
<< ", hours=" << hours
);
894 dt
= tvSubDsec(l
->timestamp
, f
->timestamp
);
895 ct
= f
->cputime
- l
->cputime
;
897 stats
.sample_start_time
= l
->timestamp
;
898 stats
.sample_end_time
= f
->timestamp
;
900 stats
.client_http_requests
= XAVG(client_http
.requests
);
901 stats
.client_http_hits
= XAVG(client_http
.hits
);
902 stats
.client_http_errors
= XAVG(client_http
.errors
);
903 stats
.client_http_kbytes_in
= XAVG(client_http
.kbytes_in
.kb
);
904 stats
.client_http_kbytes_out
= XAVG(client_http
.kbytes_out
.kb
);
906 stats
.client_http_all_median_svc_time
= statHistDeltaMedian(l
->client_http
.allSvcTime
,
907 f
->client_http
.allSvcTime
) / 1000.0;
908 stats
.client_http_miss_median_svc_time
= statHistDeltaMedian(l
->client_http
.missSvcTime
,
909 f
->client_http
.missSvcTime
) / 1000.0;
910 stats
.client_http_nm_median_svc_time
= statHistDeltaMedian(l
->client_http
.nearMissSvcTime
,
911 f
->client_http
.nearMissSvcTime
) / 1000.0;
912 stats
.client_http_nh_median_svc_time
= statHistDeltaMedian(l
->client_http
.nearHitSvcTime
,
913 f
->client_http
.nearHitSvcTime
) / 1000.0;
914 stats
.client_http_hit_median_svc_time
= statHistDeltaMedian(l
->client_http
.hitSvcTime
,
915 f
->client_http
.hitSvcTime
) / 1000.0;
917 stats
.server_all_requests
= XAVG(server
.all
.requests
);
918 stats
.server_all_errors
= XAVG(server
.all
.errors
);
919 stats
.server_all_kbytes_in
= XAVG(server
.all
.kbytes_in
.kb
);
920 stats
.server_all_kbytes_out
= XAVG(server
.all
.kbytes_out
.kb
);
922 stats
.server_http_requests
= XAVG(server
.http
.requests
);
923 stats
.server_http_errors
= XAVG(server
.http
.errors
);
924 stats
.server_http_kbytes_in
= XAVG(server
.http
.kbytes_in
.kb
);
925 stats
.server_http_kbytes_out
= XAVG(server
.http
.kbytes_out
.kb
);
927 stats
.server_ftp_requests
= XAVG(server
.ftp
.requests
);
928 stats
.server_ftp_errors
= XAVG(server
.ftp
.errors
);
929 stats
.server_ftp_kbytes_in
= XAVG(server
.ftp
.kbytes_in
.kb
);
930 stats
.server_ftp_kbytes_out
= XAVG(server
.ftp
.kbytes_out
.kb
);
932 stats
.server_other_requests
= XAVG(server
.other
.requests
);
933 stats
.server_other_errors
= XAVG(server
.other
.errors
);
934 stats
.server_other_kbytes_in
= XAVG(server
.other
.kbytes_in
.kb
);
935 stats
.server_other_kbytes_out
= XAVG(server
.other
.kbytes_out
.kb
);
937 stats
.icp_pkts_sent
= XAVG(icp
.pkts_sent
);
938 stats
.icp_pkts_recv
= XAVG(icp
.pkts_recv
);
939 stats
.icp_queries_sent
= XAVG(icp
.queries_sent
);
940 stats
.icp_replies_sent
= XAVG(icp
.replies_sent
);
941 stats
.icp_queries_recv
= XAVG(icp
.queries_recv
);
942 stats
.icp_replies_recv
= XAVG(icp
.replies_recv
);
943 stats
.icp_replies_queued
= XAVG(icp
.replies_queued
);
944 stats
.icp_query_timeouts
= XAVG(icp
.query_timeouts
);
945 stats
.icp_kbytes_sent
= XAVG(icp
.kbytes_sent
.kb
);
946 stats
.icp_kbytes_recv
= XAVG(icp
.kbytes_recv
.kb
);
947 stats
.icp_q_kbytes_sent
= XAVG(icp
.q_kbytes_sent
.kb
);
948 stats
.icp_r_kbytes_sent
= XAVG(icp
.r_kbytes_sent
.kb
);
949 stats
.icp_q_kbytes_recv
= XAVG(icp
.q_kbytes_recv
.kb
);
950 stats
.icp_r_kbytes_recv
= XAVG(icp
.r_kbytes_recv
.kb
);
952 stats
.icp_query_median_svc_time
= statHistDeltaMedian(l
->icp
.querySvcTime
,
953 f
->icp
.querySvcTime
) / 1000000.0;
954 stats
.icp_reply_median_svc_time
= statHistDeltaMedian(l
->icp
.replySvcTime
,
955 f
->icp
.replySvcTime
) / 1000000.0;
956 stats
.dns_median_svc_time
= statHistDeltaMedian(l
->dns
.svcTime
,
957 f
->dns
.svcTime
) / 1000.0;
959 stats
.unlink_requests
= XAVG(unlink
.requests
);
960 stats
.page_faults
= XAVG(page_faults
);
961 stats
.select_loops
= XAVG(select_loops
);
962 stats
.select_fds
= XAVG(select_fds
);
963 stats
.average_select_fd_period
= f
->select_fds
> l
->select_fds
?
964 (f
->select_time
- l
->select_time
) / (f
->select_fds
- l
->select_fds
) : 0.0;
966 stats
.median_select_fds
= statHistDeltaMedian(l
->select_fds_hist
, f
->select_fds_hist
);
967 stats
.swap_outs
= XAVG(swap
.outs
);
968 stats
.swap_ins
= XAVG(swap
.ins
);
969 stats
.swap_files_cleaned
= XAVG(swap
.files_cleaned
);
970 stats
.aborted_requests
= XAVG(aborted_requests
);
972 stats
.hitValidationAttempts
= XAVG(hitValidation
.attempts
);
973 stats
.hitValidationRefusalsDueToLocking
= XAVG(hitValidation
.refusalsDueToLocking
);
974 stats
.hitValidationRefusalsDueToZeroSize
= XAVG(hitValidation
.refusalsDueToZeroSize
);
975 stats
.hitValidationRefusalsDueToTimeLimit
= XAVG(hitValidation
.refusalsDueToTimeLimit
);
976 stats
.hitValidationFailures
= XAVG(hitValidation
.failures
);
978 stats
.syscalls_disk_opens
= XAVG(syscalls
.disk
.opens
);
979 stats
.syscalls_disk_closes
= XAVG(syscalls
.disk
.closes
);
980 stats
.syscalls_disk_reads
= XAVG(syscalls
.disk
.reads
);
981 stats
.syscalls_disk_writes
= XAVG(syscalls
.disk
.writes
);
982 stats
.syscalls_disk_seeks
= XAVG(syscalls
.disk
.seeks
);
983 stats
.syscalls_disk_unlinks
= XAVG(syscalls
.disk
.unlinks
);
984 stats
.syscalls_sock_accepts
= XAVG(syscalls
.sock
.accepts
);
985 stats
.syscalls_sock_sockets
= XAVG(syscalls
.sock
.sockets
);
986 stats
.syscalls_sock_connects
= XAVG(syscalls
.sock
.connects
);
987 stats
.syscalls_sock_binds
= XAVG(syscalls
.sock
.binds
);
988 stats
.syscalls_sock_closes
= XAVG(syscalls
.sock
.closes
);
989 stats
.syscalls_sock_reads
= XAVG(syscalls
.sock
.reads
);
990 stats
.syscalls_sock_writes
= XAVG(syscalls
.sock
.writes
);
991 stats
.syscalls_sock_recvfroms
= XAVG(syscalls
.sock
.recvfroms
);
992 stats
.syscalls_sock_sendtos
= XAVG(syscalls
.sock
.sendtos
);
993 stats
.syscalls_selects
= XAVG(syscalls
.selects
);
996 stats
.wall_time
= dt
;
1000 DumpAvgStat(Mgr::IntervalActionData
& stats
, StoreEntry
* sentry
)
1002 storeAppendPrintf(sentry
, "sample_start_time = %d.%d (%s)\n",
1003 (int)stats
.sample_start_time
.tv_sec
,
1004 (int)stats
.sample_start_time
.tv_usec
,
1005 Time::FormatRfc1123(stats
.sample_start_time
.tv_sec
));
1006 storeAppendPrintf(sentry
, "sample_end_time = %d.%d (%s)\n",
1007 (int)stats
.sample_end_time
.tv_sec
,
1008 (int)stats
.sample_end_time
.tv_usec
,
1009 Time::FormatRfc1123(stats
.sample_end_time
.tv_sec
));
1011 storeAppendPrintf(sentry
, "client_http.requests = %f/sec\n",
1012 stats
.client_http_requests
);
1013 storeAppendPrintf(sentry
, "client_http.hits = %f/sec\n",
1014 stats
.client_http_hits
);
1015 storeAppendPrintf(sentry
, "client_http.errors = %f/sec\n",
1016 stats
.client_http_errors
);
1017 storeAppendPrintf(sentry
, "client_http.kbytes_in = %f/sec\n",
1018 stats
.client_http_kbytes_in
);
1019 storeAppendPrintf(sentry
, "client_http.kbytes_out = %f/sec\n",
1020 stats
.client_http_kbytes_out
);
1022 double fct
= stats
.count
> 1 ? stats
.count
: 1.0;
1023 storeAppendPrintf(sentry
, "client_http.all_median_svc_time = %f seconds\n",
1024 stats
.client_http_all_median_svc_time
/ fct
);
1025 storeAppendPrintf(sentry
, "client_http.miss_median_svc_time = %f seconds\n",
1026 stats
.client_http_miss_median_svc_time
/ fct
);
1027 storeAppendPrintf(sentry
, "client_http.nm_median_svc_time = %f seconds\n",
1028 stats
.client_http_nm_median_svc_time
/ fct
);
1029 storeAppendPrintf(sentry
, "client_http.nh_median_svc_time = %f seconds\n",
1030 stats
.client_http_nh_median_svc_time
/ fct
);
1031 storeAppendPrintf(sentry
, "client_http.hit_median_svc_time = %f seconds\n",
1032 stats
.client_http_hit_median_svc_time
/ fct
);
1034 storeAppendPrintf(sentry
, "server.all.requests = %f/sec\n",
1035 stats
.server_all_requests
);
1036 storeAppendPrintf(sentry
, "server.all.errors = %f/sec\n",
1037 stats
.server_all_errors
);
1038 storeAppendPrintf(sentry
, "server.all.kbytes_in = %f/sec\n",
1039 stats
.server_all_kbytes_in
);
1040 storeAppendPrintf(sentry
, "server.all.kbytes_out = %f/sec\n",
1041 stats
.server_all_kbytes_out
);
1043 storeAppendPrintf(sentry
, "server.http.requests = %f/sec\n",
1044 stats
.server_http_requests
);
1045 storeAppendPrintf(sentry
, "server.http.errors = %f/sec\n",
1046 stats
.server_http_errors
);
1047 storeAppendPrintf(sentry
, "server.http.kbytes_in = %f/sec\n",
1048 stats
.server_http_kbytes_in
);
1049 storeAppendPrintf(sentry
, "server.http.kbytes_out = %f/sec\n",
1050 stats
.server_http_kbytes_out
);
1052 storeAppendPrintf(sentry
, "server.ftp.requests = %f/sec\n",
1053 stats
.server_ftp_requests
);
1054 storeAppendPrintf(sentry
, "server.ftp.errors = %f/sec\n",
1055 stats
.server_ftp_errors
);
1056 storeAppendPrintf(sentry
, "server.ftp.kbytes_in = %f/sec\n",
1057 stats
.server_ftp_kbytes_in
);
1058 storeAppendPrintf(sentry
, "server.ftp.kbytes_out = %f/sec\n",
1059 stats
.server_ftp_kbytes_out
);
1061 storeAppendPrintf(sentry
, "server.other.requests = %f/sec\n",
1062 stats
.server_other_requests
);
1063 storeAppendPrintf(sentry
, "server.other.errors = %f/sec\n",
1064 stats
.server_other_errors
);
1065 storeAppendPrintf(sentry
, "server.other.kbytes_in = %f/sec\n",
1066 stats
.server_other_kbytes_in
);
1067 storeAppendPrintf(sentry
, "server.other.kbytes_out = %f/sec\n",
1068 stats
.server_other_kbytes_out
);
1070 storeAppendPrintf(sentry
, "icp.pkts_sent = %f/sec\n",
1071 stats
.icp_pkts_sent
);
1072 storeAppendPrintf(sentry
, "icp.pkts_recv = %f/sec\n",
1073 stats
.icp_pkts_recv
);
1074 storeAppendPrintf(sentry
, "icp.queries_sent = %f/sec\n",
1075 stats
.icp_queries_sent
);
1076 storeAppendPrintf(sentry
, "icp.replies_sent = %f/sec\n",
1077 stats
.icp_replies_sent
);
1078 storeAppendPrintf(sentry
, "icp.queries_recv = %f/sec\n",
1079 stats
.icp_queries_recv
);
1080 storeAppendPrintf(sentry
, "icp.replies_recv = %f/sec\n",
1081 stats
.icp_replies_recv
);
1082 storeAppendPrintf(sentry
, "icp.replies_queued = %f/sec\n",
1083 stats
.icp_replies_queued
);
1084 storeAppendPrintf(sentry
, "icp.query_timeouts = %f/sec\n",
1085 stats
.icp_query_timeouts
);
1086 storeAppendPrintf(sentry
, "icp.kbytes_sent = %f/sec\n",
1087 stats
.icp_kbytes_sent
);
1088 storeAppendPrintf(sentry
, "icp.kbytes_recv = %f/sec\n",
1089 stats
.icp_kbytes_recv
);
1090 storeAppendPrintf(sentry
, "icp.q_kbytes_sent = %f/sec\n",
1091 stats
.icp_q_kbytes_sent
);
1092 storeAppendPrintf(sentry
, "icp.r_kbytes_sent = %f/sec\n",
1093 stats
.icp_r_kbytes_sent
);
1094 storeAppendPrintf(sentry
, "icp.q_kbytes_recv = %f/sec\n",
1095 stats
.icp_q_kbytes_recv
);
1096 storeAppendPrintf(sentry
, "icp.r_kbytes_recv = %f/sec\n",
1097 stats
.icp_r_kbytes_recv
);
1098 storeAppendPrintf(sentry
, "icp.query_median_svc_time = %f seconds\n",
1099 stats
.icp_query_median_svc_time
/ fct
);
1100 storeAppendPrintf(sentry
, "icp.reply_median_svc_time = %f seconds\n",
1101 stats
.icp_reply_median_svc_time
/ fct
);
1102 storeAppendPrintf(sentry
, "dns.median_svc_time = %f seconds\n",
1103 stats
.dns_median_svc_time
/ fct
);
1104 storeAppendPrintf(sentry
, "unlink.requests = %f/sec\n",
1105 stats
.unlink_requests
);
1106 storeAppendPrintf(sentry
, "page_faults = %f/sec\n",
1108 storeAppendPrintf(sentry
, "select_loops = %f/sec\n",
1109 stats
.select_loops
);
1110 storeAppendPrintf(sentry
, "select_fds = %f/sec\n",
1112 storeAppendPrintf(sentry
, "average_select_fd_period = %f/fd\n",
1113 stats
.average_select_fd_period
/ fct
);
1114 storeAppendPrintf(sentry
, "median_select_fds = %f\n",
1115 stats
.median_select_fds
/ fct
);
1116 storeAppendPrintf(sentry
, "swap.outs = %f/sec\n",
1118 storeAppendPrintf(sentry
, "swap.ins = %f/sec\n",
1120 storeAppendPrintf(sentry
, "swap.files_cleaned = %f/sec\n",
1121 stats
.swap_files_cleaned
);
1122 storeAppendPrintf(sentry
, "aborted_requests = %f/sec\n",
1123 stats
.aborted_requests
);
1125 storeAppendPrintf(sentry
, "hit_validation.attempts = %f/sec\n",
1126 stats
.hitValidationAttempts
);
1127 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_locking = %f/sec\n",
1128 stats
.hitValidationRefusalsDueToLocking
);
1129 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_zeroSize = %f/sec\n",
1130 stats
.hitValidationRefusalsDueToZeroSize
);
1131 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_timeLimit = %f/sec\n",
1132 stats
.hitValidationRefusalsDueToTimeLimit
);
1133 storeAppendPrintf(sentry
, "hit_validation.failures = %f/sec\n",
1134 stats
.hitValidationFailures
);
1137 storeAppendPrintf(sentry
, "syscalls.polls = %f/sec\n", stats
.syscalls_selects
);
1139 storeAppendPrintf(sentry
, "syscalls.selects = %f/sec\n", stats
.syscalls_selects
);
1142 storeAppendPrintf(sentry
, "syscalls.disk.opens = %f/sec\n", stats
.syscalls_disk_opens
);
1143 storeAppendPrintf(sentry
, "syscalls.disk.closes = %f/sec\n", stats
.syscalls_disk_closes
);
1144 storeAppendPrintf(sentry
, "syscalls.disk.reads = %f/sec\n", stats
.syscalls_disk_reads
);
1145 storeAppendPrintf(sentry
, "syscalls.disk.writes = %f/sec\n", stats
.syscalls_disk_writes
);
1146 storeAppendPrintf(sentry
, "syscalls.disk.seeks = %f/sec\n", stats
.syscalls_disk_seeks
);
1147 storeAppendPrintf(sentry
, "syscalls.disk.unlinks = %f/sec\n", stats
.syscalls_disk_unlinks
);
1148 storeAppendPrintf(sentry
, "syscalls.sock.accepts = %f/sec\n", stats
.syscalls_sock_accepts
);
1149 storeAppendPrintf(sentry
, "syscalls.sock.sockets = %f/sec\n", stats
.syscalls_sock_sockets
);
1150 storeAppendPrintf(sentry
, "syscalls.sock.connects = %f/sec\n", stats
.syscalls_sock_connects
);
1151 storeAppendPrintf(sentry
, "syscalls.sock.binds = %f/sec\n", stats
.syscalls_sock_binds
);
1152 storeAppendPrintf(sentry
, "syscalls.sock.closes = %f/sec\n", stats
.syscalls_sock_closes
);
1153 storeAppendPrintf(sentry
, "syscalls.sock.reads = %f/sec\n", stats
.syscalls_sock_reads
);
1154 storeAppendPrintf(sentry
, "syscalls.sock.writes = %f/sec\n", stats
.syscalls_sock_writes
);
1155 storeAppendPrintf(sentry
, "syscalls.sock.recvfroms = %f/sec\n", stats
.syscalls_sock_recvfroms
);
1156 storeAppendPrintf(sentry
, "syscalls.sock.sendtos = %f/sec\n", stats
.syscalls_sock_sendtos
);
1158 storeAppendPrintf(sentry
, "cpu_time = %f seconds\n", stats
.cpu_time
);
1159 storeAppendPrintf(sentry
, "wall_time = %f seconds\n", stats
.wall_time
);
1160 storeAppendPrintf(sentry
, "cpu_usage = %f%%\n", Math::doublePercent(stats
.cpu_time
, stats
.wall_time
));
1164 statRegisterWithCacheManager(void)
1166 Mgr::RegisterAction("info", "General Runtime Information",
1167 &Mgr::InfoAction::Create
, 0, 1);
1168 Mgr::RegisterAction("service_times", "Service Times (Percentiles)",
1169 &Mgr::ServiceTimesAction::Create
, 0, 1);
1170 Mgr::RegisterAction("filedescriptors", "Process Filedescriptor Allocation",
1171 fde::DumpStats
, 0, 1);
1172 Mgr::RegisterAction("objects", "All Cache Objects", stat_objects_get
, 0, 0);
1173 Mgr::RegisterAction("vm_objects", "In-Memory and In-Transit Objects",
1174 stat_vmobjects_get
, 0, 0);
1175 Mgr::RegisterAction("io", "Server-side network read() size histograms",
1176 &Mgr::IoAction::Create
, 0, 1);
1177 Mgr::RegisterAction("counters", "Traffic and Resource Counters",
1178 &Mgr::CountersAction::Create
, 0, 1);
1179 Mgr::RegisterAction("peer_select", "Peer Selection Algorithms",
1180 statPeerSelect
, 0, 1);
1181 Mgr::RegisterAction("digest_stats", "Cache Digest and ICP blob",
1182 statDigestBlob
, 0, 1);
1183 Mgr::RegisterAction("5min", "5 Minute Average of Counters",
1184 &Mgr::IntervalAction::Create5min
, 0, 1);
1185 Mgr::RegisterAction("60min", "60 Minute Average of Counters",
1186 &Mgr::IntervalAction::Create60min
, 0, 1);
1187 Mgr::RegisterAction("utilization", "Cache Utilization",
1188 statUtilization
, 0, 1);
1189 Mgr::RegisterAction("histograms", "Full Histogram Counts",
1190 statCountersHistograms
, 0, 1);
1191 Mgr::RegisterAction("active_requests",
1192 "Client-side Active Requests",
1193 statClientRequests
, 0, 1);
1195 Mgr::RegisterAction("username_cache",
1196 "Active Cached Usernames",
1197 Auth::User::CredentialsCacheStats
, 0, 1);
1199 Mgr::RegisterAction("openfd_objects", "Objects with Swapout files open",
1200 statOpenfdObj
, 0, 0);
1202 Mgr::RegisterAction("graph_variables", "Display cache metrics graphically",
1203 statGraphDump
, 0, 1);
1207 /* add special cases here as they arrive */
1209 statCountersInitSpecial(StatCounters
* C
)
1212 * HTTP svc_time hist is kept in milli-seconds; max of 3 hours.
1214 C
->client_http
.allSvcTime
.logInit(300, 0.0, 3600000.0 * 3.0);
1215 C
->client_http
.missSvcTime
.logInit(300, 0.0, 3600000.0 * 3.0);
1216 C
->client_http
.nearMissSvcTime
.logInit(300, 0.0, 3600000.0 * 3.0);
1217 C
->client_http
.nearHitSvcTime
.logInit(300, 0.0, 3600000.0 * 3.0);
1218 C
->client_http
.hitSvcTime
.logInit(300, 0.0, 3600000.0 * 3.0);
1220 * ICP svc_time hist is kept in micro-seconds; max of 1 minute.
1222 C
->icp
.querySvcTime
.logInit(300, 0.0, 1000000.0 * 60.0);
1223 C
->icp
.replySvcTime
.logInit(300, 0.0, 1000000.0 * 60.0);
1225 * DNS svc_time hist is kept in milli-seconds; max of 10 minutes.
1227 C
->dns
.svcTime
.logInit(300, 0.0, 60000.0 * 10.0);
1229 * Cache Digest Stuff
1231 C
->cd
.on_xition_count
.enumInit(CacheDigestHashFuncCount
);
1232 #if USE_POLL || USE_SELECT
1233 C
->comm_udp
.init(INCOMING_UDP_MAX
);
1234 C
->comm_dns
.init(INCOMING_DNS_MAX
);
1235 C
->comm_tcp
.init(INCOMING_TCP_MAX
);
1237 C
->select_fds_hist
.enumInit(256); /* was SQUID_MAXFD, but it is way too much. It is OK to crop this statistics */
1241 statCountersInit(StatCounters
* C
)
1244 *C
= StatCounters();
1245 statCountersInitSpecial(C
);
1252 debugs(18, 5, "statInit: Initializing...");
1254 for (i
= 0; i
< N_COUNT_HIST
; ++i
)
1255 statCountersInit(&CountHist
[i
]);
1257 for (i
= 0; i
< N_COUNT_HOUR_HIST
; ++i
)
1258 statCountersInit(&CountHourHist
[i
]);
1260 statCountersInit(&statCounter
);
1262 eventAdd("statAvgTick", statAvgTick
, nullptr, (double) COUNT_INTERVAL
, 1);
1264 ClientActiveRequests
.head
= nullptr;
1266 ClientActiveRequests
.tail
= nullptr;
1268 statRegisterWithCacheManager();
1274 struct rusage rusage
;
1275 eventAdd("statAvgTick", statAvgTick
, nullptr, (double) COUNT_INTERVAL
, 1);
1276 squid_getrusage(&rusage
);
1277 statCounter
.page_faults
= rusage_pagefaults(&rusage
);
1278 statCounter
.cputime
= rusage_cputime(&rusage
);
1279 statCounter
.timestamp
= current_time
;
1280 // shift all elements right and prepend statCounter
1281 for(int i
= N_COUNT_HIST
-1; i
> 0; --i
)
1282 CountHist
[i
] = CountHist
[i
-1];
1283 CountHist
[0] = statCounter
;
1286 if ((NCountHist
% COUNT_INTERVAL
) == 0) {
1287 /* we have an hours worth of readings. store previous hour */
1288 // shift all elements right and prepend final CountHist element
1289 for(int i
= N_COUNT_HOUR_HIST
-1; i
> 0; --i
)
1290 CountHourHist
[i
] = CountHourHist
[i
-1];
1291 CountHourHist
[0] = CountHist
[N_COUNT_HIST
- 1];
1295 if (Config
.warnings
.high_rptm
> 0) {
1296 int i
= (int) statPctileSvc(0.5, 20, PCTILE_HTTP
);
1298 if (Config
.warnings
.high_rptm
< i
)
1299 debugs(18, DBG_CRITICAL
, "WARNING: Median response time is " << i
<< " milliseconds");
1302 if (Config
.warnings
.high_pf
) {
1303 int i
= (CountHist
[0].page_faults
- CountHist
[1].page_faults
);
1304 double dt
= tvSubDsec(CountHist
[0].timestamp
, CountHist
[1].timestamp
);
1306 if (i
> 0 && dt
> 0.0) {
1309 if (Config
.warnings
.high_pf
< i
)
1310 debugs(18, DBG_CRITICAL
, "WARNING: Page faults occurring at " << i
<< "/sec");
1314 if (Config
.warnings
.high_memory
) {
1316 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
1317 struct mstats ms
= mstats();
1320 if (Config
.warnings
.high_memory
< i
)
1321 debugs(18, DBG_CRITICAL
, "WARNING: Memory usage at " << ((unsigned long int)(i
>> 20)) << " MB");
1326 statCountersHistograms(StoreEntry
* sentry
)
1328 storeAppendPrintf(sentry
, "client_http.allSvcTime histogram:\n");
1329 statCounter
.client_http
.allSvcTime
.dump(sentry
, nullptr);
1330 storeAppendPrintf(sentry
, "client_http.missSvcTime histogram:\n");
1331 statCounter
.client_http
.missSvcTime
.dump(sentry
, nullptr);
1332 storeAppendPrintf(sentry
, "client_http.nearMissSvcTime histogram:\n");
1333 statCounter
.client_http
.nearMissSvcTime
.dump(sentry
, nullptr);
1334 storeAppendPrintf(sentry
, "client_http.nearHitSvcTime histogram:\n");
1335 statCounter
.client_http
.nearHitSvcTime
.dump(sentry
, nullptr);
1336 storeAppendPrintf(sentry
, "client_http.hitSvcTime histogram:\n");
1337 statCounter
.client_http
.hitSvcTime
.dump(sentry
, nullptr);
1338 storeAppendPrintf(sentry
, "icp.querySvcTime histogram:\n");
1339 statCounter
.icp
.querySvcTime
.dump(sentry
, nullptr);
1340 storeAppendPrintf(sentry
, "icp.replySvcTime histogram:\n");
1341 statCounter
.icp
.replySvcTime
.dump(sentry
, nullptr);
1342 storeAppendPrintf(sentry
, "dns.svc_time histogram:\n");
1343 statCounter
.dns
.svcTime
.dump(sentry
, nullptr);
1344 storeAppendPrintf(sentry
, "select_fds_hist histogram:\n");
1345 statCounter
.select_fds_hist
.dump(sentry
, nullptr);
1349 statCountersDump(StoreEntry
* sentry
)
1351 Mgr::CountersActionData stats
;
1352 GetCountersStats(stats
);
1353 DumpCountersStats(stats
, sentry
);
1357 GetCountersStats(Mgr::CountersActionData
& stats
)
1359 StatCounters
*f
= &statCounter
;
1361 struct rusage rusage
;
1362 squid_getrusage(&rusage
);
1363 f
->page_faults
= rusage_pagefaults(&rusage
);
1364 f
->cputime
= rusage_cputime(&rusage
);
1366 stats
.sample_time
= f
->timestamp
;
1367 stats
.client_http_requests
= f
->client_http
.requests
;
1368 stats
.client_http_hits
= f
->client_http
.hits
;
1369 stats
.client_http_errors
= f
->client_http
.errors
;
1370 stats
.client_http_kbytes_in
= f
->client_http
.kbytes_in
.kb
;
1371 stats
.client_http_kbytes_out
= f
->client_http
.kbytes_out
.kb
;
1372 stats
.client_http_hit_kbytes_out
= f
->client_http
.hit_kbytes_out
.kb
;
1374 stats
.server_all_requests
= f
->server
.all
.requests
;
1375 stats
.server_all_errors
= f
->server
.all
.errors
;
1376 stats
.server_all_kbytes_in
= f
->server
.all
.kbytes_in
.kb
;
1377 stats
.server_all_kbytes_out
= f
->server
.all
.kbytes_out
.kb
;
1379 stats
.server_http_requests
= f
->server
.http
.requests
;
1380 stats
.server_http_errors
= f
->server
.http
.errors
;
1381 stats
.server_http_kbytes_in
= f
->server
.http
.kbytes_in
.kb
;
1382 stats
.server_http_kbytes_out
= f
->server
.http
.kbytes_out
.kb
;
1384 stats
.server_ftp_requests
= f
->server
.ftp
.requests
;
1385 stats
.server_ftp_errors
= f
->server
.ftp
.errors
;
1386 stats
.server_ftp_kbytes_in
= f
->server
.ftp
.kbytes_in
.kb
;
1387 stats
.server_ftp_kbytes_out
= f
->server
.ftp
.kbytes_out
.kb
;
1389 stats
.server_other_requests
= f
->server
.other
.requests
;
1390 stats
.server_other_errors
= f
->server
.other
.errors
;
1391 stats
.server_other_kbytes_in
= f
->server
.other
.kbytes_in
.kb
;
1392 stats
.server_other_kbytes_out
= f
->server
.other
.kbytes_out
.kb
;
1394 stats
.icp_pkts_sent
= f
->icp
.pkts_sent
;
1395 stats
.icp_pkts_recv
= f
->icp
.pkts_recv
;
1396 stats
.icp_queries_sent
= f
->icp
.queries_sent
;
1397 stats
.icp_replies_sent
= f
->icp
.replies_sent
;
1398 stats
.icp_queries_recv
= f
->icp
.queries_recv
;
1399 stats
.icp_replies_recv
= f
->icp
.replies_recv
;
1400 stats
.icp_query_timeouts
= f
->icp
.query_timeouts
;
1401 stats
.icp_replies_queued
= f
->icp
.replies_queued
;
1402 stats
.icp_kbytes_sent
= f
->icp
.kbytes_sent
.kb
;
1403 stats
.icp_kbytes_recv
= f
->icp
.kbytes_recv
.kb
;
1404 stats
.icp_q_kbytes_sent
= f
->icp
.q_kbytes_sent
.kb
;
1405 stats
.icp_r_kbytes_sent
= f
->icp
.r_kbytes_sent
.kb
;
1406 stats
.icp_q_kbytes_recv
= f
->icp
.q_kbytes_recv
.kb
;
1407 stats
.icp_r_kbytes_recv
= f
->icp
.r_kbytes_recv
.kb
;
1409 #if USE_CACHE_DIGESTS
1411 stats
.icp_times_used
= f
->icp
.times_used
;
1412 stats
.cd_times_used
= f
->cd
.times_used
;
1413 stats
.cd_msgs_sent
= f
->cd
.msgs_sent
;
1414 stats
.cd_msgs_recv
= f
->cd
.msgs_recv
;
1415 stats
.cd_memory
= f
->cd
.memory
.kb
;
1416 stats
.cd_local_memory
= store_digest
? store_digest
->mask_size
/ 1024 : 0;
1417 stats
.cd_kbytes_sent
= f
->cd
.kbytes_sent
.kb
;
1418 stats
.cd_kbytes_recv
= f
->cd
.kbytes_recv
.kb
;
1421 stats
.unlink_requests
= f
->unlink
.requests
;
1422 stats
.page_faults
= f
->page_faults
;
1423 stats
.select_loops
= f
->select_loops
;
1424 stats
.cpu_time
= f
->cputime
;
1425 stats
.wall_time
= tvSubDsec(f
->timestamp
, current_time
);
1426 stats
.swap_outs
= f
->swap
.outs
;
1427 stats
.swap_ins
= f
->swap
.ins
;
1428 stats
.swap_files_cleaned
= f
->swap
.files_cleaned
;
1429 stats
.aborted_requests
= f
->aborted_requests
;
1431 stats
.hitValidationAttempts
= f
->hitValidation
.attempts
;
1432 stats
.hitValidationRefusalsDueToLocking
= f
->hitValidation
.refusalsDueToLocking
;
1433 stats
.hitValidationRefusalsDueToZeroSize
= f
->hitValidation
.refusalsDueToZeroSize
;
1434 stats
.hitValidationRefusalsDueToTimeLimit
= f
->hitValidation
.refusalsDueToTimeLimit
;
1435 stats
.hitValidationFailures
= f
->hitValidation
.failures
;
1439 DumpCountersStats(Mgr::CountersActionData
& stats
, StoreEntry
* sentry
)
1441 storeAppendPrintf(sentry
, "sample_time = %d.%d (%s)\n",
1442 (int) stats
.sample_time
.tv_sec
,
1443 (int) stats
.sample_time
.tv_usec
,
1444 Time::FormatRfc1123(stats
.sample_time
.tv_sec
));
1445 storeAppendPrintf(sentry
, "client_http.requests = %.0f\n",
1446 stats
.client_http_requests
);
1447 storeAppendPrintf(sentry
, "client_http.hits = %.0f\n",
1448 stats
.client_http_hits
);
1449 storeAppendPrintf(sentry
, "client_http.errors = %.0f\n",
1450 stats
.client_http_errors
);
1451 storeAppendPrintf(sentry
, "client_http.kbytes_in = %.0f\n",
1452 stats
.client_http_kbytes_in
);
1453 storeAppendPrintf(sentry
, "client_http.kbytes_out = %.0f\n",
1454 stats
.client_http_kbytes_out
);
1455 storeAppendPrintf(sentry
, "client_http.hit_kbytes_out = %.0f\n",
1456 stats
.client_http_hit_kbytes_out
);
1458 storeAppendPrintf(sentry
, "server.all.requests = %.0f\n",
1459 stats
.server_all_requests
);
1460 storeAppendPrintf(sentry
, "server.all.errors = %.0f\n",
1461 stats
.server_all_errors
);
1462 storeAppendPrintf(sentry
, "server.all.kbytes_in = %.0f\n",
1463 stats
.server_all_kbytes_in
);
1464 storeAppendPrintf(sentry
, "server.all.kbytes_out = %.0f\n",
1465 stats
.server_all_kbytes_out
);
1467 storeAppendPrintf(sentry
, "server.http.requests = %.0f\n",
1468 stats
.server_http_requests
);
1469 storeAppendPrintf(sentry
, "server.http.errors = %.0f\n",
1470 stats
.server_http_errors
);
1471 storeAppendPrintf(sentry
, "server.http.kbytes_in = %.0f\n",
1472 stats
.server_http_kbytes_in
);
1473 storeAppendPrintf(sentry
, "server.http.kbytes_out = %.0f\n",
1474 stats
.server_http_kbytes_out
);
1476 storeAppendPrintf(sentry
, "server.ftp.requests = %.0f\n",
1477 stats
.server_ftp_requests
);
1478 storeAppendPrintf(sentry
, "server.ftp.errors = %.0f\n",
1479 stats
.server_ftp_errors
);
1480 storeAppendPrintf(sentry
, "server.ftp.kbytes_in = %.0f\n",
1481 stats
.server_ftp_kbytes_in
);
1482 storeAppendPrintf(sentry
, "server.ftp.kbytes_out = %.0f\n",
1483 stats
.server_ftp_kbytes_out
);
1485 storeAppendPrintf(sentry
, "server.other.requests = %.0f\n",
1486 stats
.server_other_requests
);
1487 storeAppendPrintf(sentry
, "server.other.errors = %.0f\n",
1488 stats
.server_other_errors
);
1489 storeAppendPrintf(sentry
, "server.other.kbytes_in = %.0f\n",
1490 stats
.server_other_kbytes_in
);
1491 storeAppendPrintf(sentry
, "server.other.kbytes_out = %.0f\n",
1492 stats
.server_other_kbytes_out
);
1494 storeAppendPrintf(sentry
, "icp.pkts_sent = %.0f\n",
1495 stats
.icp_pkts_sent
);
1496 storeAppendPrintf(sentry
, "icp.pkts_recv = %.0f\n",
1497 stats
.icp_pkts_recv
);
1498 storeAppendPrintf(sentry
, "icp.queries_sent = %.0f\n",
1499 stats
.icp_queries_sent
);
1500 storeAppendPrintf(sentry
, "icp.replies_sent = %.0f\n",
1501 stats
.icp_replies_sent
);
1502 storeAppendPrintf(sentry
, "icp.queries_recv = %.0f\n",
1503 stats
.icp_queries_recv
);
1504 storeAppendPrintf(sentry
, "icp.replies_recv = %.0f\n",
1505 stats
.icp_replies_recv
);
1506 storeAppendPrintf(sentry
, "icp.query_timeouts = %.0f\n",
1507 stats
.icp_query_timeouts
);
1508 storeAppendPrintf(sentry
, "icp.replies_queued = %.0f\n",
1509 stats
.icp_replies_queued
);
1510 storeAppendPrintf(sentry
, "icp.kbytes_sent = %.0f\n",
1511 stats
.icp_kbytes_sent
);
1512 storeAppendPrintf(sentry
, "icp.kbytes_recv = %.0f\n",
1513 stats
.icp_kbytes_recv
);
1514 storeAppendPrintf(sentry
, "icp.q_kbytes_sent = %.0f\n",
1515 stats
.icp_q_kbytes_sent
);
1516 storeAppendPrintf(sentry
, "icp.r_kbytes_sent = %.0f\n",
1517 stats
.icp_r_kbytes_sent
);
1518 storeAppendPrintf(sentry
, "icp.q_kbytes_recv = %.0f\n",
1519 stats
.icp_q_kbytes_recv
);
1520 storeAppendPrintf(sentry
, "icp.r_kbytes_recv = %.0f\n",
1521 stats
.icp_r_kbytes_recv
);
1523 #if USE_CACHE_DIGESTS
1525 storeAppendPrintf(sentry
, "icp.times_used = %.0f\n",
1526 stats
.icp_times_used
);
1527 storeAppendPrintf(sentry
, "cd.times_used = %.0f\n",
1528 stats
.cd_times_used
);
1529 storeAppendPrintf(sentry
, "cd.msgs_sent = %.0f\n",
1530 stats
.cd_msgs_sent
);
1531 storeAppendPrintf(sentry
, "cd.msgs_recv = %.0f\n",
1532 stats
.cd_msgs_recv
);
1533 storeAppendPrintf(sentry
, "cd.memory = %.0f\n",
1535 storeAppendPrintf(sentry
, "cd.local_memory = %.0f\n",
1536 stats
.cd_local_memory
);
1537 storeAppendPrintf(sentry
, "cd.kbytes_sent = %.0f\n",
1538 stats
.cd_kbytes_sent
);
1539 storeAppendPrintf(sentry
, "cd.kbytes_recv = %.0f\n",
1540 stats
.cd_kbytes_recv
);
1543 storeAppendPrintf(sentry
, "unlink.requests = %.0f\n",
1544 stats
.unlink_requests
);
1545 storeAppendPrintf(sentry
, "page_faults = %.0f\n",
1547 storeAppendPrintf(sentry
, "select_loops = %.0f\n",
1548 stats
.select_loops
);
1549 storeAppendPrintf(sentry
, "cpu_time = %f\n",
1551 storeAppendPrintf(sentry
, "wall_time = %f\n",
1553 storeAppendPrintf(sentry
, "swap.outs = %.0f\n",
1555 storeAppendPrintf(sentry
, "swap.ins = %.0f\n",
1557 storeAppendPrintf(sentry
, "swap.files_cleaned = %.0f\n",
1558 stats
.swap_files_cleaned
);
1559 storeAppendPrintf(sentry
, "aborted_requests = %.0f\n",
1560 stats
.aborted_requests
);
1562 storeAppendPrintf(sentry
, "hit_validation.attempts = %.0f\n",
1563 stats
.hitValidationAttempts
);
1564 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_locking = %.0f\n",
1565 stats
.hitValidationRefusalsDueToLocking
);
1566 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_zeroSize = %.0f\n",
1567 stats
.hitValidationRefusalsDueToZeroSize
);
1568 storeAppendPrintf(sentry
, "hit_validation.refusals.due_to_timeLimit = %.0f\n",
1569 stats
.hitValidationRefusalsDueToTimeLimit
);
1570 storeAppendPrintf(sentry
, "hit_validation.failures = %.0f\n",
1571 stats
.hitValidationFailures
);
1575 statPeerSelect(StoreEntry
* sentry
)
1577 #if USE_CACHE_DIGESTS
1578 StatCounters
*f
= &statCounter
;
1579 const int tot_used
= f
->cd
.times_used
+ f
->icp
.times_used
;
1582 static const SBuf
label("all peers");
1583 cacheDigestGuessStatsReport(&f
->cd
.guess
, sentry
, label
);
1585 storeAppendPrintf(sentry
, "\nPer-peer statistics:\n");
1587 for (const auto &peer
: CurrentCachePeers()) {
1589 peerDigestStatsReport(peer
->digest
, sentry
);
1591 storeAppendPrintf(sentry
, "\nNo peer digest from %s\n", peer
->host
);
1593 storeAppendPrintf(sentry
, "\n");
1596 storeAppendPrintf(sentry
, "\nAlgorithm usage:\n");
1597 storeAppendPrintf(sentry
, "Cache Digest: %7d (%3d%%)\n",
1598 f
->cd
.times_used
, xpercentInt(f
->cd
.times_used
, tot_used
));
1599 storeAppendPrintf(sentry
, "Icp: %7d (%3d%%)\n",
1600 f
->icp
.times_used
, xpercentInt(f
->icp
.times_used
, tot_used
));
1601 storeAppendPrintf(sentry
, "Total: %7d (%3d%%)\n",
1602 tot_used
, xpercentInt(tot_used
, tot_used
));
1605 storeAppendPrintf(sentry
, "peer digests are disabled; no stats is available.\n");
1610 statDigestBlob(StoreEntry
* sentry
)
1612 storeAppendPrintf(sentry
, "\nCounters:\n");
1613 statCountersDump(sentry
);
1614 storeAppendPrintf(sentry
, "\n5 Min Averages:\n");
1615 statAvgDump(sentry
, 5, 0);
1616 storeAppendPrintf(sentry
, "\nHistograms:\n");
1617 statCountersHistograms(sentry
);
1618 storeAppendPrintf(sentry
, "\nPeer Digests:\n");
1619 statPeerSelect(sentry
);
1620 storeAppendPrintf(sentry
, "\nLocal Digest:\n");
1621 storeDigestReport(sentry
);
1625 statPctileSvc(double pctile
, int interval
, int which
)
1630 assert(interval
> 0);
1632 if (interval
> N_COUNT_HIST
- 1)
1633 interval
= N_COUNT_HIST
- 1;
1637 l
= &CountHist
[interval
];
1646 x
= statHistDeltaPctile(l
->client_http
.allSvcTime
,f
->client_http
.allSvcTime
, pctile
);
1650 x
= statHistDeltaPctile(l
->client_http
.hitSvcTime
,f
->client_http
.hitSvcTime
, pctile
);
1654 x
= statHistDeltaPctile(l
->client_http
.missSvcTime
,f
->client_http
.missSvcTime
, pctile
);
1658 x
= statHistDeltaPctile(l
->client_http
.nearMissSvcTime
,f
->client_http
.nearMissSvcTime
, pctile
);
1662 x
= statHistDeltaPctile(l
->client_http
.nearHitSvcTime
,f
->client_http
.nearHitSvcTime
, pctile
);
1665 case PCTILE_ICP_QUERY
:
1666 x
= statHistDeltaPctile(l
->icp
.querySvcTime
,f
->icp
.querySvcTime
, pctile
);
1670 x
= statHistDeltaPctile(l
->dns
.svcTime
,f
->dns
.svcTime
, pctile
);
1674 debugs(49, 5, "statPctileSvc: unknown type.");
1682 snmpStatGet(int minutes
)
1684 return &CountHist
[minutes
];
1688 statSawRecentRequests()
1690 const auto recentMinutes
= 5;
1691 assert(N_COUNT_HIST
> recentMinutes
);
1693 // Math below computes the number of requests during the last 0-6 minutes.
1694 // CountHist is based on "minutes passed since Squid start" periods. It cannot
1695 // deliver precise info for "last N minutes", but we do not need to be precise.
1696 const auto oldRequests
= (NCountHist
> recentMinutes
) ? CountHist
[recentMinutes
].client_http
.requests
: 0;
1697 return statCounter
.client_http
.requests
- oldRequests
;
1701 statCPUUsage(int minutes
)
1703 assert(minutes
< N_COUNT_HIST
);
1704 return Math::doublePercent(CountHist
[0].cputime
- CountHist
[minutes
].cputime
,
1705 tvSubDsec(CountHist
[minutes
].timestamp
, CountHist
[0].timestamp
));
1709 statRequestHitRatio(int minutes
)
1711 assert(minutes
< N_COUNT_HIST
);
1712 return Math::doublePercent(CountHist
[0].client_http
.hits
-
1713 CountHist
[minutes
].client_http
.hits
,
1714 CountHist
[0].client_http
.requests
-
1715 CountHist
[minutes
].client_http
.requests
);
1719 statRequestHitMemoryRatio(int minutes
)
1721 assert(minutes
< N_COUNT_HIST
);
1722 return Math::doublePercent(CountHist
[0].client_http
.mem_hits
-
1723 CountHist
[minutes
].client_http
.mem_hits
,
1724 CountHist
[0].client_http
.hits
-
1725 CountHist
[minutes
].client_http
.hits
);
1729 statRequestHitDiskRatio(int minutes
)
1731 assert(minutes
< N_COUNT_HIST
);
1732 return Math::doublePercent(CountHist
[0].client_http
.disk_hits
-
1733 CountHist
[minutes
].client_http
.disk_hits
,
1734 CountHist
[0].client_http
.hits
-
1735 CountHist
[minutes
].client_http
.hits
);
1739 statByteHitRatio(int minutes
)
1743 #if USE_CACHE_DIGESTS
1747 /* size_t might be unsigned */
1748 assert(minutes
< N_COUNT_HIST
);
1749 c
= CountHist
[0].client_http
.kbytes_out
.kb
- CountHist
[minutes
].client_http
.kbytes_out
.kb
;
1750 s
= CountHist
[0].server
.all
.kbytes_in
.kb
- CountHist
[minutes
].server
.all
.kbytes_in
.kb
;
1751 #if USE_CACHE_DIGESTS
1753 * This ugly hack is here to prevent the user from seeing a
1754 * negative byte hit ratio. When we fetch a cache digest from
1755 * a neighbor, it gets treated like a cache miss because the
1756 * object is consumed internally. Thus, we subtract cache
1757 * digest bytes out before calculating the byte hit ratio.
1759 cd
= CountHist
[0].cd
.kbytes_recv
.kb
- CountHist
[minutes
].cd
.kbytes_recv
.kb
;
1762 debugs(18, DBG_IMPORTANT
, "STRANGE: srv_kbytes=" << s
<< ", cd_kbytes=" << cd
);
1769 return Math::doublePercent(c
- s
, c
);
1771 return (-1.0 * Math::doublePercent(s
- c
, c
));
1775 statClientRequests(StoreEntry
* s
)
1778 ClientHttpRequest
*http
;
1780 char buf
[MAX_IPSTRLEN
];
1782 for (i
= ClientActiveRequests
.head
; i
; i
= i
->next
) {
1783 const char *p
= nullptr;
1784 http
= static_cast<ClientHttpRequest
*>(i
->data
);
1786 ConnStateData
* conn
= http
->getConn();
1787 storeAppendPrintf(s
, "Connection: %p\n", conn
);
1789 if (conn
!= nullptr) {
1790 const int fd
= conn
->clientConnection
->fd
;
1791 storeAppendPrintf(s
, "\tFD %d, read %" PRId64
", wrote %" PRId64
"\n", fd
,
1792 fd_table
[fd
].bytes_read
, fd_table
[fd
].bytes_written
);
1793 storeAppendPrintf(s
, "\tFD desc: %s\n", fd_table
[fd
].desc
);
1794 storeAppendPrintf(s
, "\tin: buf %p, used %ld, free %ld\n",
1795 conn
->inBuf
.rawContent(), (long int) conn
->inBuf
.length(), (long int) conn
->inBuf
.spaceSize());
1796 storeAppendPrintf(s
, "\tremote: %s\n",
1797 conn
->clientConnection
->remote
.toUrl(buf
,MAX_IPSTRLEN
));
1798 storeAppendPrintf(s
, "\tlocal: %s\n",
1799 conn
->clientConnection
->local
.toUrl(buf
,MAX_IPSTRLEN
));
1800 storeAppendPrintf(s
, "\tnrequests: %u\n", conn
->pipeline
.nrequests
);
1803 storeAppendPrintf(s
, "uri %s\n", http
->uri
);
1804 storeAppendPrintf(s
, "logType %s\n", http
->loggingTags().c_str());
1805 storeAppendPrintf(s
, "out.offset %ld, out.size %lu\n",
1806 (long int) http
->out
.offset
, (unsigned long int) http
->out
.size
);
1807 storeAppendPrintf(s
, "req_sz %ld\n", (long int) http
->req_sz
);
1808 e
= http
->storeEntry();
1809 storeAppendPrintf(s
, "entry %p/%s\n", e
, e
? e
->getMD5Text() : "N/A");
1810 storeAppendPrintf(s
, "start %ld.%06d (%f seconds ago)\n",
1811 (long int) http
->al
->cache
.start_time
.tv_sec
,
1812 (int) http
->al
->cache
.start_time
.tv_usec
,
1813 tvSubDsec(http
->al
->cache
.start_time
, current_time
));
1815 if (http
->request
->auth_user_request
!= nullptr)
1816 p
= http
->request
->auth_user_request
->username();
1819 if (http
->request
->extacl_user
.size() > 0) {
1820 p
= http
->request
->extacl_user
.termedBuf();
1824 if (!p
&& conn
!= nullptr && Comm::IsConnOpen(conn
->clientConnection
))
1825 p
= sslGetUserEmail(fd_table
[conn
->clientConnection
->fd
].ssl
.get());
1831 storeAppendPrintf(s
, "username %s\n", p
);
1834 storeAppendPrintf(s
, "delay_pool %d\n", DelayId::DelayClient(http
).pool());
1837 storeAppendPrintf(s
, "\n");
1843 * urgh, i don't like these, but they do cut the amount of code down immensely
1846 #define GRAPH_PER_MIN(Y) \
1847 for (i=0;i<(N_COUNT_HIST-2);++i) { \
1848 dt = tvSubDsec(CountHist[i+1].timestamp, CountHist[i].timestamp); \
1851 storeAppendPrintf(e, "%lu,%0.2f:", \
1852 CountHist[i].timestamp.tv_sec, \
1853 ((CountHist[i].Y - CountHist[i+1].Y) / dt)); \
1856 #define GRAPH_PER_HOUR(Y) \
1857 for (i=0;i<(N_COUNT_HOUR_HIST-2);++i) { \
1858 dt = tvSubDsec(CountHourHist[i+1].timestamp, CountHourHist[i].timestamp); \
1861 storeAppendPrintf(e, "%lu,%0.2f:", \
1862 CountHourHist[i].timestamp.tv_sec, \
1863 ((CountHourHist[i].Y - CountHourHist[i+1].Y) / dt)); \
1866 #define GRAPH_TITLE(X,Y) storeAppendPrintf(e,"%s\t%s\t",X,Y);
1867 #define GRAPH_END storeAppendPrintf(e,"\n");
1869 #define GENGRAPH(X,Y,Z) \
1876 statGraphDump(StoreEntry
* e
)
1881 GENGRAPH(client_http
.requests
, "client_http.requests", "Client HTTP requests/sec");
1882 GENGRAPH(client_http
.hits
, "client_http.hits", "Client HTTP hits/sec");
1883 GENGRAPH(client_http
.errors
, "client_http.errors", "Client HTTP errors/sec");
1884 GENGRAPH(client_http
.kbytes_in
.kb
, "client_http.kbytes_in", "Client HTTP kbytes_in/sec");
1885 GENGRAPH(client_http
.kbytes_out
.kb
, "client_http.kbytes_out", "Client HTTP kbytes_out/sec");
1887 // TODO: http median service times
1889 GENGRAPH(server
.all
.requests
, "server.all.requests", "Server requests/sec");
1890 GENGRAPH(server
.all
.errors
, "server.all.errors", "Server errors/sec");
1891 GENGRAPH(server
.all
.kbytes_in
.kb
, "server.all.kbytes_in", "Server total kbytes_in/sec");
1892 GENGRAPH(server
.all
.kbytes_out
.kb
, "server.all.kbytes_out", "Server total kbytes_out/sec");
1894 GENGRAPH(server
.http
.requests
, "server.http.requests", "Server HTTP requests/sec");
1895 GENGRAPH(server
.http
.errors
, "server.http.errors", "Server HTTP errors/sec");
1896 GENGRAPH(server
.http
.kbytes_in
.kb
, "server.http.kbytes_in", "Server HTTP kbytes_in/sec");
1897 GENGRAPH(server
.http
.kbytes_out
.kb
, "server.http.kbytes_out", "Server HTTP kbytes_out/sec");
1899 GENGRAPH(server
.ftp
.requests
, "server.ftp.requests", "Server FTP requests/sec");
1900 GENGRAPH(server
.ftp
.errors
, "server.ftp.errors", "Server FTP errors/sec");
1901 GENGRAPH(server
.ftp
.kbytes_in
.kb
, "server.ftp.kbytes_in", "Server FTP kbytes_in/sec");
1902 GENGRAPH(server
.ftp
.kbytes_out
.kb
, "server.ftp.kbytes_out", "Server FTP kbytes_out/sec");
1904 GENGRAPH(server
.other
.requests
, "server.other.requests", "Server other requests/sec");
1905 GENGRAPH(server
.other
.errors
, "server.other.errors", "Server other errors/sec");
1906 GENGRAPH(server
.other
.kbytes_in
.kb
, "server.other.kbytes_in", "Server other kbytes_in/sec");
1907 GENGRAPH(server
.other
.kbytes_out
.kb
, "server.other.kbytes_out", "Server other kbytes_out/sec");
1909 GENGRAPH(icp
.pkts_sent
, "icp.pkts_sent", "ICP packets sent/sec");
1910 GENGRAPH(icp
.pkts_recv
, "icp.pkts_recv", "ICP packets received/sec");
1911 GENGRAPH(icp
.kbytes_sent
.kb
, "icp.kbytes_sent", "ICP kbytes_sent/sec");
1912 GENGRAPH(icp
.kbytes_recv
.kb
, "icp.kbytes_recv", "ICP kbytes_received/sec");
1914 // TODO: icp median service times
1915 // TODO: dns median service times
1917 GENGRAPH(unlink
.requests
, "unlink.requests", "Cache File unlink requests/sec");
1918 GENGRAPH(page_faults
, "page_faults", "System Page Faults/sec");
1919 GENGRAPH(select_loops
, "select_loops", "System Select Loop calls/sec");
1920 GENGRAPH(cputime
, "cputime", "CPU utilisation");
1923 #endif /* STAT_GRAPHS */