2 * DEBUG: section 18 Cache Manager Statistics
3 * AUTHOR: Harvest Derived
5 * SQUID Web Proxy Cache http://www.squid-cache.org/
6 * ----------------------------------------------------------
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.
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.
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.
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.
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"
42 #include "format/Token.h"
44 #include "HttpRequest.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"
62 #include "StatCounters.h"
64 #include "store_digest.h"
65 #include "StoreClient.h"
68 #include "auth/UserRequest.h"
74 #include "ssl/support.h"
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
82 #include "StoreSearch.h"
84 #define DEBUG_OPENFD 1
86 typedef int STOBJFLT(const StoreEntry
*);
88 class StatObjectsState
94 StoreSearchPointer theSearch
;
97 CBDATA_CLASS2(StatObjectsState
);
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
);
106 static void statGraphDump(StoreEntry
*);
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
;
118 static OBJH statOpenfdObj
;
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
);
139 #if XMALLOC_STATISTICS
140 static void info_get_mallstat(int, int, int, void *);
141 static double xm_time
;
142 static double xm_deltat
;
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
);
151 extern unsigned int mem_pool_alloc_calls
;
152 extern unsigned int mem_pool_free_calls
;
155 statUtilization(StoreEntry
* e
)
157 storeAppendPrintf(e
, "Cache Utilisation:\n");
158 storeAppendPrintf(e
, "\n");
159 storeAppendPrintf(e
, "Last 5 minutes:\n");
162 statAvgDump(e
, 5, 0);
164 storeAppendPrintf(e
, "(no values recorded yet)\n");
166 storeAppendPrintf(e
, "\n");
168 storeAppendPrintf(e
, "Last 15 minutes:\n");
170 if (NCountHist
>= 15)
171 statAvgDump(e
, 15, 0);
173 storeAppendPrintf(e
, "(no values recorded yet)\n");
175 storeAppendPrintf(e
, "\n");
177 storeAppendPrintf(e
, "Last hour:\n");
179 if (NCountHist
>= 60)
180 statAvgDump(e
, 60, 0);
182 storeAppendPrintf(e
, "(no values recorded yet)\n");
184 storeAppendPrintf(e
, "\n");
186 storeAppendPrintf(e
, "Last 8 hours:\n");
188 if (NCountHourHist
>= 8)
189 statAvgDump(e
, 0, 8);
191 storeAppendPrintf(e
, "(no values recorded yet)\n");
193 storeAppendPrintf(e
, "\n");
195 storeAppendPrintf(e
, "Last day:\n");
197 if (NCountHourHist
>= 24)
198 statAvgDump(e
, 0, 24);
200 storeAppendPrintf(e
, "(no values recorded yet)\n");
202 storeAppendPrintf(e
, "\n");
204 storeAppendPrintf(e
, "Last 3 days:\n");
206 if (NCountHourHist
>= 72)
207 statAvgDump(e
, 0, 72);
209 storeAppendPrintf(e
, "(no values recorded yet)\n");
211 storeAppendPrintf(e
, "\n");
213 storeAppendPrintf(e
, "Totals since cache startup:\n");
219 GetIoStats(Mgr::IoActionData
& stats
)
223 stats
.http_reads
= IOStats
.Http
.reads
;
225 for (i
= 0; i
< IoStats::histSize
; ++i
) {
226 stats
.http_read_hist
[i
] = IOStats
.Http
.read_hist
[i
];
229 stats
.ftp_reads
= IOStats
.Ftp
.reads
;
231 for (i
= 0; i
< IoStats::histSize
; ++i
) {
232 stats
.ftp_read_hist
[i
] = IOStats
.Ftp
.read_hist
[i
];
235 stats
.gopher_reads
= IOStats
.Gopher
.reads
;
237 for (i
= 0; i
< IoStats::histSize
; ++i
) {
238 stats
.gopher_read_hist
[i
] = IOStats
.Gopher
.read_hist
[i
];
243 DumpIoStats(Mgr::IoActionData
& stats
, StoreEntry
* sentry
)
247 storeAppendPrintf(sentry
, "HTTP I/O\n");
248 storeAppendPrintf(sentry
, "number of reads: %.0f\n", stats
.http_reads
);
249 storeAppendPrintf(sentry
, "Read Histogram:\n");
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,
255 stats
.http_read_hist
[i
],
256 Math::doublePercent(stats
.http_read_hist
[i
], stats
.http_reads
));
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");
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,
268 stats
.ftp_read_hist
[i
],
269 Math::doublePercent(stats
.ftp_read_hist
[i
], stats
.ftp_reads
));
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");
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,
281 stats
.gopher_read_hist
[i
],
282 Math::doublePercent(stats
.gopher_read_hist
[i
], stats
.gopher_reads
));
285 storeAppendPrintf(sentry
, "\n");
289 describeStatuses(const StoreEntry
* entry
)
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
]);
301 storeEntryFlags(const StoreEntry
* entry
)
303 LOCAL_ARRAY(char, buf
, 256);
304 int flags
= (int) entry
->flags
;
308 if (EBIT_TEST(flags
, ENTRY_SPECIAL
))
309 strcat(buf
, "SPECIAL,");
311 if (EBIT_TEST(flags
, ENTRY_REVALIDATE
))
312 strcat(buf
, "REVALIDATE,");
314 if (EBIT_TEST(flags
, DELAY_SENDING
))
315 strcat(buf
, "DELAY_SENDING,");
317 if (EBIT_TEST(flags
, RELEASE_REQUEST
))
318 strcat(buf
, "RELEASE_REQUEST,");
320 if (EBIT_TEST(flags
, REFRESH_REQUEST
))
321 strcat(buf
, "REFRESH_REQUEST,");
323 if (EBIT_TEST(flags
, ENTRY_DISPATCHED
))
324 strcat(buf
, "DISPATCHED,");
326 if (EBIT_TEST(flags
, KEY_PRIVATE
))
327 strcat(buf
, "PRIVATE,");
329 if (EBIT_TEST(flags
, ENTRY_FWD_HDR_WAIT
))
330 strcat(buf
, "FWD_HDR_WAIT,");
332 if (EBIT_TEST(flags
, ENTRY_NEGCACHED
))
333 strcat(buf
, "NEGCACHED,");
335 if (EBIT_TEST(flags
, ENTRY_VALIDATED
))
336 strcat(buf
, "VALIDATED,");
338 if (EBIT_TEST(flags
, ENTRY_BAD_LENGTH
))
339 strcat(buf
, "BAD_LENGTH,");
341 if (EBIT_TEST(flags
, ENTRY_ABORTED
))
342 strcat(buf
, "ABORTED,");
344 if ((t
= strrchr(buf
, ',')))
351 describeTimestamps(const StoreEntry
* entry
)
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
);
363 statStoreEntry(MemBuf
* mb
, StoreEntry
* e
)
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",
372 storePendingNClients(e
),
374 mb
->Printf("\tSwap Dir %d, File %#08X\n",
375 e
->swap_dirn
, e
->swap_filen
);
383 /* process objects list */
385 statObjects(void *data
)
387 StatObjectsState
*state
= static_cast<StatObjectsState
*>(data
);
390 if (state
->theSearch
->isDone()) {
392 storeAppendPrintf(state
->sentry
, "} by kid%d\n\n", KidIdentifier
);
393 state
->sentry
->complete();
394 state
->sentry
->unlock("statObjects+isDone");
397 } else if (EBIT_TEST(state
->sentry
->flags
, ENTRY_ABORTED
)) {
398 state
->sentry
->unlock("statObjects+aborted");
401 } else if (state
->sentry
->checkDeferRead(-1)) {
402 state
->sentry
->flush();
403 eventAdd("statObjects", statObjects
, state
, 0.1, 1);
407 state
->sentry
->buffer();
408 size_t statCount
= 0;
412 while (statCount
++ < static_cast<size_t>(Config
.Store
.objectsPerBucket
) && state
->
414 e
= state
->theSearch
->currentItem();
416 if (state
->filter
&& 0 == state
->filter(e
))
419 statStoreEntry(&mb
, e
);
423 state
->sentry
->append(mb
.buf
, mb
.size
);
426 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
430 statObjectsStart(StoreEntry
* sentry
, STOBJFLT
* filter
)
432 StatObjectsState
*state
= new StatObjectsState
;
433 state
->sentry
= sentry
;
434 state
->filter
= filter
;
436 sentry
->lock("statObjects");
437 state
->theSearch
= Store::Root().search(NULL
, NULL
);
439 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
443 stat_objects_get(StoreEntry
* sentry
)
445 statObjectsStart(sentry
, NULL
);
449 statObjectsVmFilter(const StoreEntry
* e
)
451 return e
->mem_obj
? 1 : 0;
455 stat_vmobjects_get(StoreEntry
* sentry
)
457 statObjectsStart(sentry
, statObjectsVmFilter
);
462 statObjectsOpenfdFilter(const StoreEntry
* e
)
464 if (e
->mem_obj
== NULL
)
467 if (e
->mem_obj
->swapout
.sio
== NULL
)
474 statOpenfdObj(StoreEntry
* sentry
)
476 statObjectsStart(sentry
, statObjectsOpenfdFilter
);
481 #if XMALLOC_STATISTICS
483 info_get_mallstat(int size
, int number
, int oldnum
, void *data
)
485 StoreEntry
*sentry
= (StoreEntry
*)data
;
487 // format: "%12s %15s %6s %12s\n","Alloc Size","Count","Delta","Alloc/sec"
489 storeAppendPrintf(sentry
, "%12d %15d %6d %.1f\n", size
, number
, number
- oldnum
, xdiv((number
- oldnum
), xm_deltat
));
495 GetInfo(Mgr::InfoActionData
& stats
)
498 struct rusage rusage
;
501 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
505 runtime
= tvSubDsec(squid_start
, current_time
);
510 stats
.squid_start
= squid_start
;
512 stats
.current_time
= current_time
;
514 stats
.client_http_clients
= statCounter
.client_http
.clients
;
516 stats
.client_http_requests
= statCounter
.client_http
.requests
;
518 stats
.icp_pkts_recv
= statCounter
.icp
.pkts_recv
;
520 stats
.icp_pkts_sent
= statCounter
.icp
.pkts_sent
;
522 stats
.icp_replies_queued
= statCounter
.icp
.replies_queued
;
526 stats
.htcp_pkts_recv
= statCounter
.htcp
.pkts_recv
;
528 stats
.htcp_pkts_sent
= statCounter
.htcp
.pkts_sent
;
532 stats
.request_failure_ratio
= request_failure_ratio
;
534 stats
.avg_client_http_requests
= statCounter
.client_http
.requests
/ (runtime
/ 60.0);
536 stats
.avg_icp_messages
= (statCounter
.icp
.pkts_sent
+ statCounter
.icp
.pkts_recv
) / (runtime
/ 60.0);
538 stats
.select_loops
= statCounter
.select_loops
;
539 stats
.avg_loop_time
= 1000.0 * runtime
/ statCounter
.select_loops
;
541 stats
.request_hit_ratio5
= statRequestHitRatio(5);
542 stats
.request_hit_ratio60
= statRequestHitRatio(60);
544 stats
.byte_hit_ratio5
= statByteHitRatio(5);
545 stats
.byte_hit_ratio60
= statByteHitRatio(60);
547 stats
.request_hit_mem_ratio5
= statRequestHitMemoryRatio(5);
548 stats
.request_hit_mem_ratio60
= statRequestHitMemoryRatio(60);
550 stats
.request_hit_disk_ratio5
= statRequestHitDiskRatio(5);
551 stats
.request_hit_disk_ratio60
= statRequestHitDiskRatio(60);
553 Store::Root().getStats(stats
.store
);
555 stats
.unlink_requests
= statCounter
.unlink
.requests
;
557 stats
.http_requests5
= statPctileSvc(0.5, 5, PCTILE_HTTP
);
558 stats
.http_requests60
= statPctileSvc(0.5, 60, PCTILE_HTTP
);
560 stats
.cache_misses5
= statPctileSvc(0.5, 5, PCTILE_MISS
);
561 stats
.cache_misses60
= statPctileSvc(0.5, 60, PCTILE_MISS
);
563 stats
.cache_hits5
= statPctileSvc(0.5, 5, PCTILE_HIT
);
564 stats
.cache_hits60
= statPctileSvc(0.5, 60, PCTILE_HIT
);
566 stats
.near_hits5
= statPctileSvc(0.5, 5, PCTILE_NH
);
567 stats
.near_hits60
= statPctileSvc(0.5, 60, PCTILE_NH
);
569 stats
.not_modified_replies5
= statPctileSvc(0.5, 5, PCTILE_NM
);
570 stats
.not_modified_replies60
= statPctileSvc(0.5, 60, PCTILE_NM
);
572 stats
.dns_lookups5
= statPctileSvc(0.5, 5, PCTILE_DNS
);
573 stats
.dns_lookups60
= statPctileSvc(0.5, 60, PCTILE_DNS
);
575 stats
.icp_queries5
= statPctileSvc(0.5, 5, PCTILE_ICP_QUERY
);
576 stats
.icp_queries60
= statPctileSvc(0.5, 60, PCTILE_ICP_QUERY
);
578 squid_getrusage(&rusage
);
579 cputime
= rusage_cputime(&rusage
);
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);
587 stats
.maxrss
= rusage_maxrss(&rusage
);
589 stats
.page_faults
= rusage_pagefaults(&rusage
);
591 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
595 stats
.ms_bytes_total
= ms
.bytes_total
;
597 stats
.ms_bytes_free
= ms
.bytes_free
;
601 stats
.total_accounted
= statMemoryAccounted();
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
;
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
;
619 DumpInfo(Mgr::InfoActionData
& stats
, StoreEntry
* sentry
)
621 storeAppendPrintf(sentry
, "Squid Object Cache: Version %s\n",
624 storeAppendPrintf(sentry
, "Build Info: " SQUID_BUILD_INFO
"\n");
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
);
632 storeAppendPrintf(sentry
,"Running on %s\n",WIN32_OS_string
);
634 storeAppendPrintf(sentry
,"Service Name: %s\n", service_name
);
637 storeAppendPrintf(sentry
, "Start Time:\t%s\n",
638 mkrfc1123(stats
.squid_start
.tv_sec
));
640 storeAppendPrintf(sentry
, "Current Time:\t%s\n",
641 mkrfc1123(stats
.current_time
.tv_sec
));
643 storeAppendPrintf(sentry
, "Connection information for %s:\n",APP_SHORTNAME
);
645 storeAppendPrintf(sentry
, "\tNumber of clients accessing cache:\t%.0f\n",
646 stats
.client_http_clients
);
648 storeAppendPrintf(sentry
, "\tNumber of HTTP requests received:\t%.0f\n",
649 stats
.client_http_requests
);
651 storeAppendPrintf(sentry
, "\tNumber of ICP messages received:\t%.0f\n",
652 stats
.icp_pkts_recv
);
654 storeAppendPrintf(sentry
, "\tNumber of ICP messages sent:\t%.0f\n",
655 stats
.icp_pkts_sent
);
657 storeAppendPrintf(sentry
, "\tNumber of queued ICP replies:\t%.0f\n",
658 stats
.icp_replies_queued
);
662 storeAppendPrintf(sentry
, "\tNumber of HTCP messages received:\t%.0f\n",
663 stats
.htcp_pkts_recv
);
665 storeAppendPrintf(sentry
, "\tNumber of HTCP messages sent:\t%.0f\n",
666 stats
.htcp_pkts_sent
);
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
);
674 storeAppendPrintf(sentry
, "\tAverage HTTP requests per minute since start:\t%.1f\n",
675 stats
.avg_client_http_requests
);
677 storeAppendPrintf(sentry
, "\tAverage ICP messages per minute since start:\t%.1f\n",
678 stats
.avg_icp_messages
);
680 storeAppendPrintf(sentry
, "\tSelect loop called: %.0f times, %0.3f ms avg\n",
681 stats
.select_loops
, stats
.avg_loop_time
/ fct
);
683 storeAppendPrintf(sentry
, "Cache information for %s:\n",APP_SHORTNAME
);
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
);
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
);
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
);
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
);
701 storeAppendPrintf(sentry
, "\tStorage Swap size:\t%.0f KB\n",
702 stats
.store
.swap
.size
/ 1024);
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
));
708 storeAppendPrintf(sentry
, "\tStorage Mem size:\t%.0f KB\n",
709 stats
.store
.mem
.size
/ 1024);
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
));
715 storeAppendPrintf(sentry
, "\tMean Object Size:\t%0.2f KB\n",
716 stats
.store
.swap
.meanObjectSize() / 1024);
718 storeAppendPrintf(sentry
, "\tRequests given to unlinkd:\t%.0f\n",
719 stats
.unlink_requests
);
721 storeAppendPrintf(sentry
, "Median Service Times (seconds) 5 min 60 min:\n");
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
);
728 storeAppendPrintf(sentry
, "\tCache Misses: %8.5f %8.5f\n",
729 stats
.cache_misses5
/ fct
,
730 stats
.cache_misses60
/ fct
);
732 storeAppendPrintf(sentry
, "\tCache Hits: %8.5f %8.5f\n",
733 stats
.cache_hits5
/ fct
,
734 stats
.cache_hits60
/ fct
);
736 storeAppendPrintf(sentry
, "\tNear Hits: %8.5f %8.5f\n",
737 stats
.near_hits5
/ fct
,
738 stats
.near_hits60
/ fct
);
740 storeAppendPrintf(sentry
, "\tNot-Modified Replies: %8.5f %8.5f\n",
741 stats
.not_modified_replies5
/ fct
,
742 stats
.not_modified_replies60
/ fct
);
744 storeAppendPrintf(sentry
, "\tDNS Lookups: %8.5f %8.5f\n",
745 stats
.dns_lookups5
/ fct
,
746 stats
.dns_lookups60
/ fct
);
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
);
753 storeAppendPrintf(sentry
, "Resource usage for %s:\n", APP_SHORTNAME
);
755 storeAppendPrintf(sentry
, "\tUP Time:\t%.3f seconds\n", stats
.up_time
);
757 storeAppendPrintf(sentry
, "\tCPU Time:\t%.3f seconds\n", stats
.cpu_time
);
759 storeAppendPrintf(sentry
, "\tCPU Usage:\t%.2f%%\n",
762 storeAppendPrintf(sentry
, "\tCPU Usage, 5 minute avg:\t%.2f%%\n",
765 storeAppendPrintf(sentry
, "\tCPU Usage, 60 minute avg:\t%.2f%%\n",
768 storeAppendPrintf(sentry
, "\tMaximum Resident Size: %.0f KB\n",
771 storeAppendPrintf(sentry
, "\tPage faults with physical i/o: %.0f\n",
774 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
776 storeAppendPrintf(sentry
, "Memory usage for %s via mstats():\n",APP_SHORTNAME
);
778 storeAppendPrintf(sentry
, "\tTotal space in arena: %6.0f KB\n",
779 stats
.ms_bytes_total
/ 1024);
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
));
787 storeAppendPrintf(sentry
, "Memory accounted for:\n");
788 storeAppendPrintf(sentry
, "\tTotal accounted: %6.0f KB\n",
789 stats
.total_accounted
/ 1024);
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
);
799 storeAppendPrintf(sentry
, "File descriptor usage for %s:\n", APP_SHORTNAME
);
800 storeAppendPrintf(sentry
, "\tMaximum number of file descriptors: %4.0f\n",
802 storeAppendPrintf(sentry
, "\tLargest file desc currently in use: %4.0f\n",
804 storeAppendPrintf(sentry
, "\tNumber of file desc currently in use: %4.0f\n",
806 storeAppendPrintf(sentry
, "\tFiles queued for open: %4.0f\n",
808 storeAppendPrintf(sentry
, "\tAvailable number of file descriptors: %4.0f\n",
810 storeAppendPrintf(sentry
, "\tReserved number of file descriptors: %4.0f\n",
812 storeAppendPrintf(sentry
, "\tStore Disk files open: %4.0f\n",
813 stats
.store
.swap
.open_disk_fd
);
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
);
827 DumpMallocStatistics(StoreEntry
* sentry
)
829 #if XMALLOC_STATISTICS
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
);
840 GetServiceTimesStats(Mgr::ServiceTimesActionData
& stats
)
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
);
847 stats
.cache_misses5
[i
] = statPctileSvc(p
, 5, PCTILE_MISS
);
848 stats
.cache_misses60
[i
] = statPctileSvc(p
, 60, PCTILE_MISS
);
850 stats
.cache_hits5
[i
] = statPctileSvc(p
, 5, PCTILE_HIT
);
851 stats
.cache_hits60
[i
] = statPctileSvc(p
, 60, PCTILE_HIT
);
853 stats
.near_hits5
[i
] = statPctileSvc(p
, 5, PCTILE_NH
);
854 stats
.near_hits60
[i
] = statPctileSvc(p
, 60, PCTILE_NH
);
856 stats
.not_modified_replies5
[i
] = statPctileSvc(p
, 5, PCTILE_NM
);
857 stats
.not_modified_replies60
[i
] = statPctileSvc(p
, 60, PCTILE_NM
);
859 stats
.dns_lookups5
[i
] = statPctileSvc(p
, 5, PCTILE_DNS
);
860 stats
.dns_lookups60
[i
] = statPctileSvc(p
, 60, PCTILE_DNS
);
862 stats
.icp_queries5
[i
] = statPctileSvc(p
, 5, PCTILE_ICP_QUERY
);
863 stats
.icp_queries60
[i
] = statPctileSvc(p
, 60, PCTILE_ICP_QUERY
);
868 DumpServiceTimesStats(Mgr::ServiceTimesActionData
& stats
, StoreEntry
* sentry
)
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",
875 stats
.http_requests5
[i
] / fct
,
876 stats
.http_requests60
[i
] / fct
);
878 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
879 storeAppendPrintf(sentry
, "\tCache Misses: %2d%% %8.5f %8.5f\n",
881 stats
.cache_misses5
[i
] / fct
,
882 stats
.cache_misses60
[i
] / fct
);
884 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
885 storeAppendPrintf(sentry
, "\tCache Hits: %2d%% %8.5f %8.5f\n",
887 stats
.cache_hits5
[i
] / fct
,
888 stats
.cache_hits60
[i
] / fct
);
890 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
891 storeAppendPrintf(sentry
, "\tNear Hits: %2d%% %8.5f %8.5f\n",
893 stats
.near_hits5
[i
] / fct
,
894 stats
.near_hits60
[i
] / fct
);
896 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
897 storeAppendPrintf(sentry
, "\tNot-Modified Replies: %2d%% %8.5f %8.5f\n",
899 stats
.not_modified_replies5
[i
] / fct
,
900 stats
.not_modified_replies60
[i
] / fct
);
902 for (int i
= 0; i
< Mgr::ServiceTimesActionData::seriesSize
; ++i
) {
903 storeAppendPrintf(sentry
, "\tDNS Lookups: %2d%% %8.5f %8.5f\n",
905 stats
.dns_lookups5
[i
] / fct
,
906 stats
.dns_lookups60
[i
] / fct
);
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",
912 stats
.icp_queries5
[i
] / fct
,
913 stats
.icp_queries60
[i
] / fct
);
918 statAvgDump(StoreEntry
* sentry
, int minutes
, int hours
)
920 Mgr::IntervalActionData stats
;
921 GetAvgStat(stats
, minutes
, hours
);
922 DumpAvgStat(stats
, sentry
);
925 #define XAVG(X) (dt ? (double) (f->X - l->X) / dt : 0.0)
927 GetAvgStat(Mgr::IntervalActionData
& stats
, int minutes
, int hours
)
933 assert(N_COUNT_HIST
> 1);
934 assert(minutes
> 0 || hours
> 0);
938 if (minutes
> 0 && hours
== 0) {
939 /* checking minute readings ... */
941 if (minutes
> N_COUNT_HIST
- 1)
942 minutes
= N_COUNT_HIST
- 1;
944 l
= &CountHist
[minutes
];
945 } else if (minutes
== 0 && hours
> 0) {
946 /* checking hour readings ... */
948 if (hours
> N_COUNT_HOUR_HIST
- 1)
949 hours
= N_COUNT_HOUR_HIST
- 1;
951 l
= &CountHourHist
[hours
];
953 debugs(18, DBG_IMPORTANT
, "statAvgDump: Invalid args, minutes=" << minutes
<< ", hours=" << hours
);
957 dt
= tvSubDsec(l
->timestamp
, f
->timestamp
);
958 ct
= f
->cputime
- l
->cputime
;
960 stats
.sample_start_time
= l
->timestamp
;
961 stats
.sample_end_time
= f
->timestamp
;
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
);
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;
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
);
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
);
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
);
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
);
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
);
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;
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;
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
);
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
);
1052 stats
.cpu_time
= ct
;
1053 stats
.wall_time
= dt
;
1057 DumpAvgStat(Mgr::IntervalActionData
& stats
, StoreEntry
* sentry
)
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
));
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
);
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
);
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
);
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
);
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
);
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
);
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",
1165 storeAppendPrintf(sentry
, "select_loops = %f/sec\n",
1166 stats
.select_loops
);
1167 storeAppendPrintf(sentry
, "select_fds = %f/sec\n",
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",
1175 storeAppendPrintf(sentry
, "swap.ins = %f/sec\n",
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
);
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
);
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
);
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
));
1210 statRegisterWithCacheManager(void)
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);
1241 Mgr::RegisterAction("username_cache",
1242 "Active Cached Usernames",
1243 Auth::User::UsernameCacheStats
, 0, 1);
1246 Mgr::RegisterAction("openfd_objects", "Objects with Swapout files open",
1247 statOpenfdObj
, 0, 0);
1250 Mgr::RegisterAction("graph_variables", "Display cache metrics graphically",
1251 statGraphDump
, 0, 1);
1259 debugs(18, 5, "statInit: Initializing...");
1261 for (i
= 0; i
< N_COUNT_HIST
; ++i
)
1262 statCountersInit(&CountHist
[i
]);
1264 for (i
= 0; i
< N_COUNT_HOUR_HIST
; ++i
)
1265 statCountersInit(&CountHourHist
[i
]);
1267 statCountersInit(&statCounter
);
1269 eventAdd("statAvgTick", statAvgTick
, NULL
, (double) COUNT_INTERVAL
, 1);
1271 ClientActiveRequests
.head
= NULL
;
1273 ClientActiveRequests
.tail
= NULL
;
1275 statRegisterWithCacheManager();
1279 statAvgTick(void *notused
)
1281 StatCounters
*t
= &CountHist
[0];
1282 StatCounters
*p
= &CountHist
[1];
1283 StatCounters
*c
= &statCounter
;
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
);
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
);
1308 if (Config
.warnings
.high_rptm
> 0) {
1309 int i
= (int) statPctileSvc(0.5, 20, PCTILE_HTTP
);
1311 if (Config
.warnings
.high_rptm
< i
)
1312 debugs(18, DBG_CRITICAL
, "WARNING: Median response time is " << i
<< " milliseconds");
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
);
1319 if (i
> 0 && dt
> 0.0) {
1322 if (Config
.warnings
.high_pf
< i
)
1323 debugs(18, DBG_CRITICAL
, "WARNING: Page faults occuring at " << i
<< "/sec");
1327 if (Config
.warnings
.high_memory
) {
1329 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
1330 struct mstats ms
= mstats();
1333 if (Config
.warnings
.high_memory
< i
)
1334 debugs(18, DBG_CRITICAL
, "WARNING: Memory usage at " << ((unsigned long int)(i
>> 20)) << " MB");
1339 statCountersInit(StatCounters
* C
)
1342 memset(C
, 0, sizeof(*C
));
1343 C
->timestamp
= current_time
;
1344 statCountersInitSpecial(C
);
1347 /* add special cases here as they arrive */
1349 statCountersInitSpecial(StatCounters
* C
)
1352 * HTTP svc_time hist is kept in milli-seconds; max of 3 hours.
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);
1360 * ICP svc_time hist is kept in micro-seconds; max of 1 minute.
1362 C
->icp
.querySvcTime
.logInit(300, 0.0, 1000000.0 * 60.0);
1363 C
->icp
.replySvcTime
.logInit(300, 0.0, 1000000.0 * 60.0);
1365 * DNS svc_time hist is kept in milli-seconds; max of 10 minutes.
1367 C
->dns
.svcTime
.logInit(300, 0.0, 60000.0 * 10.0);
1369 * Cache Digest Stuff
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 */
1378 /* add special cases here as they arrive */
1380 statCountersClean(StatCounters
* 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();
1398 /* add special cases here as they arrive */
1400 statCountersCopy(StatCounters
* dest
, const StatCounters
* orig
)
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
;
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
;
1426 statCountersHistograms(StoreEntry
* sentry
)
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
);
1449 statCountersDump(StoreEntry
* sentry
)
1451 Mgr::CountersActionData stats
;
1452 GetCountersStats(stats
);
1453 DumpCountersStats(stats
, sentry
);
1457 GetCountersStats(Mgr::CountersActionData
& stats
)
1459 StatCounters
*f
= &statCounter
;
1461 struct rusage rusage
;
1462 squid_getrusage(&rusage
);
1463 f
->page_faults
= rusage_pagefaults(&rusage
);
1464 f
->cputime
= rusage_cputime(&rusage
);
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
;
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
;
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
;
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
;
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
;
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
;
1509 #if USE_CACHE_DIGESTS
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
;
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
;
1533 DumpCountersStats(Mgr::CountersActionData
& stats
, StoreEntry
* sentry
)
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
);
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
);
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
);
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
);
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
);
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
);
1617 #if USE_CACHE_DIGESTS
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",
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
);
1637 storeAppendPrintf(sentry
, "unlink.requests = %.0f\n",
1638 stats
.unlink_requests
);
1639 storeAppendPrintf(sentry
, "page_faults = %.0f\n",
1641 storeAppendPrintf(sentry
, "select_loops = %.0f\n",
1642 stats
.select_loops
);
1643 storeAppendPrintf(sentry
, "cpu_time = %f\n",
1645 storeAppendPrintf(sentry
, "wall_time = %f\n",
1647 storeAppendPrintf(sentry
, "swap.outs = %.0f\n",
1649 storeAppendPrintf(sentry
, "swap.ins = %.0f\n",
1651 storeAppendPrintf(sentry
, "swap.files_cleaned = %.0f\n",
1652 stats
.swap_files_cleaned
);
1653 storeAppendPrintf(sentry
, "aborted_requests = %.0f\n",
1654 stats
.aborted_requests
);
1658 statFreeMemory(void)
1662 for (i
= 0; i
< N_COUNT_HIST
; ++i
)
1663 statCountersClean(&CountHist
[i
]);
1665 for (i
= 0; i
< N_COUNT_HOUR_HIST
; ++i
)
1666 statCountersClean(&CountHourHist
[i
]);
1670 statPeerSelect(StoreEntry
* sentry
)
1672 #if USE_CACHE_DIGESTS
1673 StatCounters
*f
= &statCounter
;
1675 const int tot_used
= f
->cd
.times_used
+ f
->icp
.times_used
;
1678 cacheDigestGuessStatsReport(&f
->cd
.guess
, sentry
, "all peers");
1680 storeAppendPrintf(sentry
, "\nPer-peer statistics:\n");
1682 for (peer
= getFirstPeer(); peer
; peer
= getNextPeer(peer
)) {
1684 peerDigestStatsReport(peer
->digest
, sentry
);
1686 storeAppendPrintf(sentry
, "\nNo peer digest from %s\n", peer
->host
);
1688 storeAppendPrintf(sentry
, "\n");
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
));
1700 storeAppendPrintf(sentry
, "peer digests are disabled; no stats is available.\n");
1705 statDigestBlob(StoreEntry
* sentry
)
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
);
1720 statPctileSvc(double pctile
, int interval
, int which
)
1725 assert(interval
> 0);
1727 if (interval
> N_COUNT_HIST
- 1)
1728 interval
= N_COUNT_HIST
- 1;
1732 l
= &CountHist
[interval
];
1741 x
= statHistDeltaPctile(l
->client_http
.allSvcTime
,f
->client_http
.allSvcTime
, pctile
);
1745 x
= statHistDeltaPctile(l
->client_http
.hitSvcTime
,f
->client_http
.hitSvcTime
, pctile
);
1749 x
= statHistDeltaPctile(l
->client_http
.missSvcTime
,f
->client_http
.missSvcTime
, pctile
);
1753 x
= statHistDeltaPctile(l
->client_http
.nearMissSvcTime
,f
->client_http
.nearMissSvcTime
, pctile
);
1757 x
= statHistDeltaPctile(l
->client_http
.nearHitSvcTime
,f
->client_http
.nearHitSvcTime
, pctile
);
1760 case PCTILE_ICP_QUERY
:
1761 x
= statHistDeltaPctile(l
->icp
.querySvcTime
,f
->icp
.querySvcTime
, pctile
);
1765 x
= statHistDeltaPctile(l
->dns
.svcTime
,f
->dns
.svcTime
, pctile
);
1769 debugs(49, 5, "statPctileSvc: unknown type.");
1777 snmpStatGet(int minutes
)
1779 return &CountHist
[minutes
];
1783 stat5minClientRequests(void)
1785 assert(N_COUNT_HIST
> 5);
1786 return statCounter
.client_http
.requests
- CountHist
[5].client_http
.requests
;
1790 statCPUUsage(int minutes
)
1792 assert(minutes
< N_COUNT_HIST
);
1793 return Math::doublePercent(CountHist
[0].cputime
- CountHist
[minutes
].cputime
,
1794 tvSubDsec(CountHist
[minutes
].timestamp
, CountHist
[0].timestamp
));
1798 statRequestHitRatio(int minutes
)
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
);
1808 statRequestHitMemoryRatio(int minutes
)
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
);
1818 statRequestHitDiskRatio(int minutes
)
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
);
1828 statByteHitRatio(int minutes
)
1832 #if USE_CACHE_DIGESTS
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
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.
1848 cd
= CountHist
[0].cd
.kbytes_recv
.kb
- CountHist
[minutes
].cd
.kbytes_recv
.kb
;
1851 debugs(18, DBG_IMPORTANT
, "STRANGE: srv_kbytes=" << s
<< ", cd_kbytes=" << cd
);
1858 return Math::doublePercent(c
- s
, c
);
1860 return (-1.0 * Math::doublePercent(s
- c
, c
));
1864 statClientRequests(StoreEntry
* s
)
1867 ClientHttpRequest
*http
;
1869 char buf
[MAX_IPSTRLEN
];
1871 for (i
= ClientActiveRequests
.head
; i
; i
= i
->next
) {
1872 const char *p
= NULL
;
1873 http
= static_cast<ClientHttpRequest
*>(i
->data
);
1875 ConnStateData
* conn
= http
->getConn();
1876 storeAppendPrintf(s
, "Connection: %p\n", conn
);
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",
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
));
1905 if (http
->request
->auth_user_request
!= NULL
)
1906 p
= http
->request
->auth_user_request
->username();
1909 if (http
->request
->extacl_user
.size() > 0) {
1910 p
= http
->request
->extacl_user
.termedBuf();
1913 if (!p
&& conn
!= NULL
&& conn
->clientConnection
->rfc931
[0])
1914 p
= conn
->clientConnection
->rfc931
;
1918 if (!p
&& conn
!= NULL
&& Comm::IsConnOpen(conn
->clientConnection
))
1919 p
= sslGetUserEmail(fd_table
[conn
->clientConnection
->fd
].ssl
);
1926 storeAppendPrintf(s
, "username %s\n", p
);
1929 storeAppendPrintf(s
, "delay_pool %d\n", DelayId::DelayClient(http
).pool());
1932 storeAppendPrintf(s
, "\n");
1938 * urgh, i don't like these, but they do cut the amount of code down immensely
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); \
1946 storeAppendPrintf(e, "%lu,%0.2f:", \
1947 CountHist[i].timestamp.tv_sec, \
1948 ((CountHist[i].Y - CountHist[i+1].Y) / dt)); \
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); \
1956 storeAppendPrintf(e, "%lu,%0.2f:", \
1957 CountHourHist[i].timestamp.tv_sec, \
1958 ((CountHourHist[i].Y - CountHourHist[i+1].Y) / dt)); \
1961 #define GRAPH_TITLE(X,Y) storeAppendPrintf(e,"%s\t%s\t",X,Y);
1962 #define GRAPH_END storeAppendPrintf(e,"\n");
1964 #define GENGRAPH(X,Y,Z) \
1971 statGraphDump(StoreEntry
* e
)
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");
1982 /* XXX todo: http median service times */
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");
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");
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");
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");
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");
2009 /* XXX todo: icp median service times */
2010 /* XXX todo: dns median service times */
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");
2018 #endif /* STAT_GRAPHS */
2021 statMemoryAccounted(void)
2023 return memPoolsTotalAllocated();