3 * $Id: stat.cc,v 1.352 2001/12/24 15:33:44 adrian Exp $
5 * DEBUG: section 18 Cache Manager Statistics
6 * AUTHOR: Harvest Derived
8 * SQUID Web Proxy Cache http://www.squid-cache.org/
9 * ----------------------------------------------------------
11 * Squid is the result of efforts by numerous individuals from
12 * the Internet community; see the CONTRIBUTORS file for full
13 * details. Many organizations have provided support for Squid's
14 * development; see the SPONSORS file for full details. Squid is
15 * Copyrighted (C) 2001 by the Regents of the University of
16 * California; see the COPYRIGHT file for full details. Squid
17 * incorporates software developed and/or copyrighted by other
18 * sources; see the CREDITS file for full details.
20 * This program is free software; you can redistribute it and/or modify
21 * it under the terms of the GNU General Public License as published by
22 * the Free Software Foundation; either version 2 of the License, or
23 * (at your option) any later version.
25 * This program is distributed in the hope that it will be useful,
26 * but WITHOUT ANY WARRANTY; without even the implied warranty of
27 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
28 * GNU General Public License for more details.
30 * You should have received a copy of the GNU General Public License
31 * along with this program; if not, write to the Free Software
32 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
39 #define DEBUG_OPENFD 1
41 typedef int STOBJFLT(const StoreEntry
*);
49 static const char *describeStatuses(const StoreEntry
*);
50 static const char *describeTimestamps(const StoreEntry
*);
51 static void statAvgTick(void *notused
);
52 static void statAvgDump(StoreEntry
*, int minutes
, int hours
);
54 static void statGraphDump(StoreEntry
*);
56 static void statCountersInit(StatCounters
*);
57 static void statCountersInitSpecial(StatCounters
*);
58 static void statCountersClean(StatCounters
*);
59 static void statCountersCopy(StatCounters
* dest
, const StatCounters
* orig
);
60 static double statMedianSvc(int, int);
61 static void statStoreEntry(StoreEntry
* s
, StoreEntry
* e
);
62 static double statCPUUsage(int minutes
);
63 static OBJH stat_io_get
;
64 static OBJH stat_objects_get
;
65 static OBJH stat_vmobjects_get
;
67 static OBJH statOpenfdObj
;
69 static EVH statObjects
;
71 static OBJH statFiledescriptors
;
72 static OBJH statCountersDump
;
73 static OBJH statPeerSelect
;
74 static OBJH statDigestBlob
;
75 static OBJH statAvg5min
;
76 static OBJH statAvg60min
;
77 static OBJH statUtilization
;
78 static OBJH statCountersHistograms
;
79 static OBJH statClientRequests
;
81 #ifdef XMALLOC_STATISTICS
82 static void info_get_mallstat(int, int, int, void *);
83 static double xm_time
;
84 static double xm_deltat
;
87 StatCounters CountHist
[N_COUNT_HIST
];
88 static int NCountHist
= 0;
89 static StatCounters CountHourHist
[N_COUNT_HOUR_HIST
];
90 static int NCountHourHist
= 0;
91 CBDATA_TYPE(StatObjectsState
);
93 extern unsigned int mem_pool_alloc_calls
;
94 extern unsigned int mem_pool_free_calls
;
97 statUtilization(StoreEntry
* e
)
99 storeAppendPrintf(e
, "Cache Utilisation:\n");
100 storeAppendPrintf(e
, "\n");
101 storeAppendPrintf(e
, "Last 5 minutes:\n");
103 statAvgDump(e
, 5, 0);
105 storeAppendPrintf(e
, "(no values recorded yet)\n");
106 storeAppendPrintf(e
, "\n");
107 storeAppendPrintf(e
, "Last 15 minutes:\n");
108 if (NCountHist
>= 15)
109 statAvgDump(e
, 15, 0);
111 storeAppendPrintf(e
, "(no values recorded yet)\n");
112 storeAppendPrintf(e
, "\n");
113 storeAppendPrintf(e
, "Last hour:\n");
114 if (NCountHist
>= 60)
115 statAvgDump(e
, 60, 0);
117 storeAppendPrintf(e
, "(no values recorded yet)\n");
118 storeAppendPrintf(e
, "\n");
119 storeAppendPrintf(e
, "Last 8 hours:\n");
120 if (NCountHourHist
>= 8)
121 statAvgDump(e
, 0, 8);
123 storeAppendPrintf(e
, "(no values recorded yet)\n");
124 storeAppendPrintf(e
, "\n");
125 storeAppendPrintf(e
, "Last day:\n");
126 if (NCountHourHist
>= 24)
127 statAvgDump(e
, 0, 24);
129 storeAppendPrintf(e
, "(no values recorded yet)\n");
130 storeAppendPrintf(e
, "\n");
131 storeAppendPrintf(e
, "Last 3 days:\n");
132 if (NCountHourHist
>= 72)
133 statAvgDump(e
, 0, 72);
135 storeAppendPrintf(e
, "(no values recorded yet)\n");
136 storeAppendPrintf(e
, "\n");
137 storeAppendPrintf(e
, "Totals since cache startup:\n");
142 stat_io_get(StoreEntry
* sentry
)
146 storeAppendPrintf(sentry
, "HTTP I/O\n");
147 storeAppendPrintf(sentry
, "number of reads: %d\n", IOStats
.Http
.reads
);
148 storeAppendPrintf(sentry
, "Read Histogram:\n");
149 for (i
= 0; i
< 16; i
++) {
150 storeAppendPrintf(sentry
, "%5d-%5d: %9d %2d%%\n",
151 i
? (1 << (i
- 1)) + 1 : 1,
153 IOStats
.Http
.read_hist
[i
],
154 percent(IOStats
.Http
.read_hist
[i
], IOStats
.Http
.reads
));
157 storeAppendPrintf(sentry
, "\n");
158 storeAppendPrintf(sentry
, "FTP I/O\n");
159 storeAppendPrintf(sentry
, "number of reads: %d\n", IOStats
.Ftp
.reads
);
160 storeAppendPrintf(sentry
, "Read Histogram:\n");
161 for (i
= 0; i
< 16; i
++) {
162 storeAppendPrintf(sentry
, "%5d-%5d: %9d %2d%%\n",
163 i
? (1 << (i
- 1)) + 1 : 1,
165 IOStats
.Ftp
.read_hist
[i
],
166 percent(IOStats
.Ftp
.read_hist
[i
], IOStats
.Ftp
.reads
));
169 storeAppendPrintf(sentry
, "\n");
170 storeAppendPrintf(sentry
, "Gopher I/O\n");
171 storeAppendPrintf(sentry
, "number of reads: %d\n", IOStats
.Gopher
.reads
);
172 storeAppendPrintf(sentry
, "Read Histogram:\n");
173 for (i
= 0; i
< 16; i
++) {
174 storeAppendPrintf(sentry
, "%5d-%5d: %9d %2d%%\n",
175 i
? (1 << (i
- 1)) + 1 : 1,
177 IOStats
.Gopher
.read_hist
[i
],
178 percent(IOStats
.Gopher
.read_hist
[i
], IOStats
.Gopher
.reads
));
181 storeAppendPrintf(sentry
, "\n");
182 storeAppendPrintf(sentry
, "WAIS I/O\n");
183 storeAppendPrintf(sentry
, "number of reads: %d\n", IOStats
.Wais
.reads
);
184 storeAppendPrintf(sentry
, "Read Histogram:\n");
185 for (i
= 0; i
< 16; i
++) {
186 storeAppendPrintf(sentry
, "%5d-%5d: %9d %2d%%\n",
187 i
? (1 << (i
- 1)) + 1 : 1,
189 IOStats
.Wais
.read_hist
[i
],
190 percent(IOStats
.Wais
.read_hist
[i
], IOStats
.Wais
.reads
));
195 describeStatuses(const StoreEntry
* entry
)
197 LOCAL_ARRAY(char, buf
, 256);
198 snprintf(buf
, 256, "%-13s %-13s %-12s %-12s",
199 storeStatusStr
[entry
->store_status
],
200 memStatusStr
[entry
->mem_status
],
201 swapStatusStr
[entry
->swap_status
],
202 pingStatusStr
[entry
->ping_status
]);
207 storeEntryFlags(const StoreEntry
* entry
)
209 LOCAL_ARRAY(char, buf
, 256);
210 int flags
= (int) entry
->flags
;
213 if (EBIT_TEST(flags
, ENTRY_SPECIAL
))
214 strcat(buf
, "SPECIAL,");
215 if (EBIT_TEST(flags
, ENTRY_REVALIDATE
))
216 strcat(buf
, "REVALIDATE,");
217 if (EBIT_TEST(flags
, DELAY_SENDING
))
218 strcat(buf
, "DELAY_SENDING,");
219 if (EBIT_TEST(flags
, RELEASE_REQUEST
))
220 strcat(buf
, "RELEASE_REQUEST,");
221 if (EBIT_TEST(flags
, REFRESH_REQUEST
))
222 strcat(buf
, "REFRESH_REQUEST,");
223 if (EBIT_TEST(flags
, ENTRY_CACHABLE
))
224 strcat(buf
, "CACHABLE,");
225 if (EBIT_TEST(flags
, ENTRY_DISPATCHED
))
226 strcat(buf
, "DISPATCHED,");
227 if (EBIT_TEST(flags
, KEY_PRIVATE
))
228 strcat(buf
, "PRIVATE,");
229 if (EBIT_TEST(flags
, ENTRY_FWD_HDR_WAIT
))
230 strcat(buf
, "FWD_HDR_WAIT,");
231 if (EBIT_TEST(flags
, ENTRY_NEGCACHED
))
232 strcat(buf
, "NEGCACHED,");
233 if (EBIT_TEST(flags
, ENTRY_VALIDATED
))
234 strcat(buf
, "VALIDATED,");
235 if (EBIT_TEST(flags
, ENTRY_BAD_LENGTH
))
236 strcat(buf
, "BAD_LENGTH,");
237 if (EBIT_TEST(flags
, ENTRY_ABORTED
))
238 strcat(buf
, "ABORTED,");
239 if ((t
= strrchr(buf
, ',')))
245 describeTimestamps(const StoreEntry
* entry
)
247 LOCAL_ARRAY(char, buf
, 256);
248 snprintf(buf
, 256, "LV:%-9d LU:%-9d LM:%-9d EX:%-9d",
249 (int) entry
->timestamp
,
250 (int) entry
->lastref
,
251 (int) entry
->lastmod
,
252 (int) entry
->expires
);
257 statStoreEntry(StoreEntry
* s
, StoreEntry
* e
)
259 MemObject
*mem
= e
->mem_obj
;
261 struct _store_client
*sc
;
263 storeAppendPrintf(s
, "KEY %s\n", storeKeyText(e
->hash
.key
));
265 storeAppendPrintf(s
, "\t%s %s\n",
266 RequestMethodStr
[mem
->method
], mem
->log_url
);
267 storeAppendPrintf(s
, "\t%s\n", describeStatuses(e
));
268 storeAppendPrintf(s
, "\t%s\n", storeEntryFlags(e
));
269 storeAppendPrintf(s
, "\t%s\n", describeTimestamps(e
));
270 storeAppendPrintf(s
, "\t%d locks, %d clients, %d refs\n",
272 storePendingNClients(e
),
274 storeAppendPrintf(s
, "\tSwap Dir %d, File %#08X\n",
275 e
->swap_dirn
, e
->swap_filen
);
277 storeAppendPrintf(s
, "\tinmem_lo: %d\n", (int) mem
->inmem_lo
);
278 storeAppendPrintf(s
, "\tinmem_hi: %d\n", (int) mem
->inmem_hi
);
279 storeAppendPrintf(s
, "\tswapout: %d bytes queued\n",
280 (int) mem
->swapout
.queue_offset
);
281 if (mem
->swapout
.sio
)
282 storeAppendPrintf(s
, "\tswapout: %d bytes written\n",
283 (int) storeOffset(mem
->swapout
.sio
));
284 for (i
= 0, node
= mem
->clients
.head
; node
; node
= node
->next
, i
++) {
285 sc
= (store_client
*) node
->data
;
286 if (sc
->callback_data
== NULL
)
288 storeAppendPrintf(s
, "\tClient #%d, %p\n", i
, sc
->callback_data
);
289 storeAppendPrintf(s
, "\t\tcopy_offset: %d\n",
290 (int) sc
->copy_offset
);
291 storeAppendPrintf(s
, "\t\tseen_offset: %d\n",
292 (int) sc
->seen_offset
);
293 storeAppendPrintf(s
, "\t\tcopy_size: %d\n",
294 (int) sc
->copy_size
);
295 storeAppendPrintf(s
, "\t\tflags:");
296 if (sc
->flags
.disk_io_pending
)
297 storeAppendPrintf(s
, " disk_io_pending");
298 if (sc
->flags
.store_copying
)
299 storeAppendPrintf(s
, " store_copying");
300 if (sc
->flags
.copy_event_pending
)
301 storeAppendPrintf(s
, " copy_event_pending");
302 storeAppendPrintf(s
, "\n");
305 storeAppendPrintf(s
, "\n");
308 /* process objects list */
310 statObjects(void *data
)
312 StatObjectsState
*state
= data
;
314 hash_link
*link_ptr
= NULL
;
315 hash_link
*link_next
= NULL
;
316 if (state
->bucket
>= store_hash_buckets
) {
317 storeComplete(state
->sentry
);
318 storeUnlockObject(state
->sentry
);
321 } else if (EBIT_TEST(state
->sentry
->flags
, ENTRY_ABORTED
)) {
322 storeUnlockObject(state
->sentry
);
325 } else if (fwdCheckDeferRead(-1, state
->sentry
)) {
326 eventAdd("statObjects", statObjects
, state
, 0.1, 1);
329 storeBuffer(state
->sentry
);
330 debug(49, 3) ("statObjects: Bucket #%d\n", state
->bucket
);
331 link_next
= hash_get_bucket(store_table
, state
->bucket
);
332 while (NULL
!= (link_ptr
= link_next
)) {
333 link_next
= link_ptr
->next
;
334 e
= (StoreEntry
*) link_ptr
;
335 if (state
->filter
&& 0 == state
->filter(e
))
337 statStoreEntry(state
->sentry
, e
);
340 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
341 storeBufferFlush(state
->sentry
);
345 statObjectsStart(StoreEntry
* sentry
, STOBJFLT
* filter
)
347 StatObjectsState
*state
;
348 state
= cbdataAlloc(StatObjectsState
);
349 state
->sentry
= sentry
;
350 state
->filter
= filter
;
351 storeLockObject(sentry
);
352 eventAdd("statObjects", statObjects
, state
, 0.0, 1);
356 stat_objects_get(StoreEntry
* sentry
)
358 statObjectsStart(sentry
, NULL
);
362 statObjectsVmFilter(const StoreEntry
* e
)
364 return e
->mem_obj
? 1 : 0;
368 stat_vmobjects_get(StoreEntry
* sentry
)
370 statObjectsStart(sentry
, statObjectsVmFilter
);
375 statObjectsOpenfdFilter(const StoreEntry
* e
)
377 if (e
->mem_obj
== NULL
)
379 if (e
->mem_obj
->swapout
.sio
== NULL
)
385 statOpenfdObj(StoreEntry
* sentry
)
387 statObjectsStart(sentry
, statObjectsOpenfdFilter
);
392 #ifdef XMALLOC_STATISTICS
394 info_get_mallstat(int size
, int number
, int oldnum
, void *data
)
396 StoreEntry
*sentry
= data
;
398 storeAppendPrintf(sentry
, "%d\t %d\t %d\t %.1f\n", size
, number
, number
- oldnum
, xdiv((number
- oldnum
), xm_deltat
));
403 fdRemoteAddr(const fde
* f
)
405 LOCAL_ARRAY(char, buf
, 32);
406 if (f
->type
!= FD_SOCKET
)
408 snprintf(buf
, 32, "%s.%d", f
->ipaddr
, (int) f
->remote_port
);
413 statFiledescriptors(StoreEntry
* sentry
)
417 storeAppendPrintf(sentry
, "Active file descriptors:\n");
418 storeAppendPrintf(sentry
, "%-4s %-6s %-4s %-7s* %-7s* %-21s %s\n",
426 storeAppendPrintf(sentry
, "---- ------ ---- -------- -------- --------------------- ------------------------------\n");
427 for (i
= 0; i
< Squid_MaxFD
; i
++) {
431 storeAppendPrintf(sentry
, "%4d %-6.6s %4d %7d%c %7d%c %-21s %s\n",
434 f
->timeout_handler
? (int) (f
->timeout
- squid_curtime
) / 60 : 0,
436 f
->read_handler
? '*' : ' ',
438 f
->write_handler
? '*' : ' ',
445 info_get(StoreEntry
* sentry
)
447 struct rusage rusage
;
450 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
452 #elif HAVE_MALLINFO && HAVE_STRUCT_MALLINFO
457 runtime
= tvSubDsec(squid_start
, current_time
);
460 storeAppendPrintf(sentry
, "Squid Object Cache: Version %s\n",
462 storeAppendPrintf(sentry
, "Start Time:\t%s\n",
463 mkrfc1123(squid_start
.tv_sec
));
464 storeAppendPrintf(sentry
, "Current Time:\t%s\n",
465 mkrfc1123(current_time
.tv_sec
));
466 storeAppendPrintf(sentry
, "Connection information for %s:\n",
468 storeAppendPrintf(sentry
, "\tNumber of clients accessing cache:\t%u\n",
469 statCounter
.client_http
.clients
);
470 storeAppendPrintf(sentry
, "\tNumber of HTTP requests received:\t%u\n",
471 statCounter
.client_http
.requests
);
472 storeAppendPrintf(sentry
, "\tNumber of ICP messages received:\t%u\n",
473 statCounter
.icp
.pkts_recv
);
474 storeAppendPrintf(sentry
, "\tNumber of ICP messages sent:\t%u\n",
475 statCounter
.icp
.pkts_sent
);
476 storeAppendPrintf(sentry
, "\tNumber of queued ICP replies:\t%u\n",
477 statCounter
.icp
.replies_queued
);
478 storeAppendPrintf(sentry
, "\tRequest failure ratio:\t%5.2f%%\n",
479 request_failure_ratio
);
481 storeAppendPrintf(sentry
, "\tHTTP requests per minute:\t%.1f\n",
482 statCounter
.client_http
.requests
/ (runtime
/ 60.0));
483 storeAppendPrintf(sentry
, "\tICP messages per minute:\t%.1f\n",
484 (statCounter
.icp
.pkts_sent
+ statCounter
.icp
.pkts_recv
) / (runtime
/ 60.0));
485 storeAppendPrintf(sentry
, "\tSelect loop called: %d times, %0.3f ms avg\n",
486 statCounter
.select_loops
, 1000.0 * runtime
/ statCounter
.select_loops
);
488 storeAppendPrintf(sentry
, "Cache information for %s:\n",
490 storeAppendPrintf(sentry
, "\tRequest Hit Ratios:\t5min: %3.1f%%, 60min: %3.1f%%\n",
491 statRequestHitRatio(5),
492 statRequestHitRatio(60));
493 storeAppendPrintf(sentry
, "\tByte Hit Ratios:\t5min: %3.1f%%, 60min: %3.1f%%\n",
495 statByteHitRatio(60));
496 storeAppendPrintf(sentry
, "\tRequest Memory Hit Ratios:\t5min: %3.1f%%, 60min: %3.1f%%\n",
497 statRequestHitMemoryRatio(5),
498 statRequestHitMemoryRatio(60));
499 storeAppendPrintf(sentry
, "\tRequest Disk Hit Ratios:\t5min: %3.1f%%, 60min: %3.1f%%\n",
500 statRequestHitDiskRatio(5),
501 statRequestHitDiskRatio(60));
502 storeAppendPrintf(sentry
, "\tStorage Swap size:\t%d KB\n",
504 storeAppendPrintf(sentry
, "\tStorage Mem size:\t%d KB\n",
505 (int) (store_mem_size
>> 10));
506 storeAppendPrintf(sentry
, "\tMean Object Size:\t%0.2f KB\n",
507 n_disk_objects
? (double) store_swap_size
/ n_disk_objects
: 0.0);
508 storeAppendPrintf(sentry
, "\tRequests given to unlinkd:\t%d\n",
509 statCounter
.unlink
.requests
);
511 storeAppendPrintf(sentry
, "Median Service Times (seconds) 5 min 60 min:\n");
512 storeAppendPrintf(sentry
, "\tHTTP Requests (All): %8.5f %8.5f\n",
513 statMedianSvc(5, MEDIAN_HTTP
) / 1000.0,
514 statMedianSvc(60, MEDIAN_HTTP
) / 1000.0);
515 storeAppendPrintf(sentry
, "\tCache Misses: %8.5f %8.5f\n",
516 statMedianSvc(5, MEDIAN_MISS
) / 1000.0,
517 statMedianSvc(60, MEDIAN_MISS
) / 1000.0);
518 storeAppendPrintf(sentry
, "\tCache Hits: %8.5f %8.5f\n",
519 statMedianSvc(5, MEDIAN_HIT
) / 1000.0,
520 statMedianSvc(60, MEDIAN_HIT
) / 1000.0);
521 storeAppendPrintf(sentry
, "\tNear Hits: %8.5f %8.5f\n",
522 statMedianSvc(5, MEDIAN_NH
) / 1000.0,
523 statMedianSvc(60, MEDIAN_NH
) / 1000.0);
524 storeAppendPrintf(sentry
, "\tNot-Modified Replies: %8.5f %8.5f\n",
525 statMedianSvc(5, MEDIAN_NM
) / 1000.0,
526 statMedianSvc(60, MEDIAN_NM
) / 1000.0);
527 storeAppendPrintf(sentry
, "\tDNS Lookups: %8.5f %8.5f\n",
528 statMedianSvc(5, MEDIAN_DNS
) / 1000.0,
529 statMedianSvc(60, MEDIAN_DNS
) / 1000.0);
530 storeAppendPrintf(sentry
, "\tICP Queries: %8.5f %8.5f\n",
531 statMedianSvc(5, MEDIAN_ICP_QUERY
) / 1000000.0,
532 statMedianSvc(60, MEDIAN_ICP_QUERY
) / 1000000.0);
534 squid_getrusage(&rusage
);
535 cputime
= rusage_cputime(&rusage
);
536 storeAppendPrintf(sentry
, "Resource usage for %s:\n", appname
);
537 storeAppendPrintf(sentry
, "\tUP Time:\t%.3f seconds\n", runtime
);
538 storeAppendPrintf(sentry
, "\tCPU Time:\t%.3f seconds\n", cputime
);
539 storeAppendPrintf(sentry
, "\tCPU Usage:\t%.2f%%\n",
540 dpercent(cputime
, runtime
));
541 storeAppendPrintf(sentry
, "\tCPU Usage, 5 minute avg:\t%.2f%%\n",
543 storeAppendPrintf(sentry
, "\tCPU Usage, 60 minute avg:\t%.2f%%\n",
545 storeAppendPrintf(sentry
, "\tMaximum Resident Size: %d KB\n",
546 rusage_maxrss(&rusage
));
547 storeAppendPrintf(sentry
, "\tPage faults with physical i/o: %d\n",
548 rusage_pagefaults(&rusage
));
550 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
552 storeAppendPrintf(sentry
, "Memory usage for %s via mstats():\n",
554 storeAppendPrintf(sentry
, "\tTotal space in arena: %6d KB\n",
555 ms
.bytes_total
>> 10);
556 storeAppendPrintf(sentry
, "\tTotal free: %6d KB %d%%\n",
557 ms
.bytes_free
>> 10, percent(ms
.bytes_free
, ms
.bytes_total
));
558 #elif HAVE_MALLINFO && HAVE_STRUCT_MALLINFO
560 storeAppendPrintf(sentry
, "Memory usage for %s via mallinfo():\n",
562 storeAppendPrintf(sentry
, "\tTotal space in arena: %6d KB\n",
564 storeAppendPrintf(sentry
, "\tOrdinary blocks: %6d KB %6d blks\n",
565 mp
.uordblks
>> 10, mp
.ordblks
);
566 storeAppendPrintf(sentry
, "\tSmall blocks: %6d KB %6d blks\n",
567 mp
.usmblks
>> 10, mp
.smblks
);
568 storeAppendPrintf(sentry
, "\tHolding blocks: %6d KB %6d blks\n",
569 mp
.hblkhd
>> 10, mp
.hblks
);
570 storeAppendPrintf(sentry
, "\tFree Small blocks: %6d KB\n",
572 storeAppendPrintf(sentry
, "\tFree Ordinary blocks: %6d KB\n",
574 t
= mp
.uordblks
+ mp
.usmblks
+ mp
.hblkhd
;
575 storeAppendPrintf(sentry
, "\tTotal in use: %6d KB %d%%\n",
576 t
>> 10, percent(t
, mp
.arena
));
577 t
= mp
.fsmblks
+ mp
.fordblks
;
578 storeAppendPrintf(sentry
, "\tTotal free: %6d KB %d%%\n",
579 t
>> 10, percent(t
, mp
.arena
));
580 #if HAVE_EXT_MALLINFO
581 storeAppendPrintf(sentry
, "\tmax size of small blocks:\t%d\n", mp
.mxfast
);
582 storeAppendPrintf(sentry
, "\tnumber of small blocks in a holding block:\t%d\n",
584 storeAppendPrintf(sentry
, "\tsmall block rounding factor:\t%d\n", mp
.grain
);
585 storeAppendPrintf(sentry
, "\tspace (including overhead) allocated in ord. blks:\t%d\n"
587 storeAppendPrintf(sentry
, "\tnumber of ordinary blocks allocated:\t%d\n",
589 storeAppendPrintf(sentry
, "\tbytes used in maintaining the free tree:\t%d\n",
591 #endif /* HAVE_EXT_MALLINFO */
592 #endif /* HAVE_MALLINFO */
593 storeAppendPrintf(sentry
, "Memory accounted for:\n");
594 storeAppendPrintf(sentry
, "\tTotal accounted: %6d KB\n",
595 statMemoryAccounted() >> 10);
596 storeAppendPrintf(sentry
, "\tmemPoolAlloc calls: %d\n",
597 mem_pool_alloc_calls
);
598 storeAppendPrintf(sentry
, "\tmemPoolFree calls: %d\n",
599 mem_pool_free_calls
);
601 storeAppendPrintf(sentry
, "File descriptor usage for %s:\n", appname
);
602 storeAppendPrintf(sentry
, "\tMaximum number of file descriptors: %4d\n",
604 storeAppendPrintf(sentry
, "\tLargest file desc currently in use: %4d\n",
606 storeAppendPrintf(sentry
, "\tNumber of file desc currently in use: %4d\n",
608 storeAppendPrintf(sentry
, "\tFiles queued for open: %4d\n",
610 storeAppendPrintf(sentry
, "\tAvailable number of file descriptors: %4d\n",
612 storeAppendPrintf(sentry
, "\tReserved number of file descriptors: %4d\n",
614 storeAppendPrintf(sentry
, "\tStore Disk files open: %4d\n",
617 storeAppendPrintf(sentry
, "Internal Data Structures:\n");
618 storeAppendPrintf(sentry
, "\t%6d StoreEntries\n",
619 memInUse(MEM_STOREENTRY
));
620 storeAppendPrintf(sentry
, "\t%6d StoreEntries with MemObjects\n",
621 memInUse(MEM_MEMOBJECT
));
622 storeAppendPrintf(sentry
, "\t%6d Hot Object Cache Items\n",
624 storeAppendPrintf(sentry
, "\t%6d on-disk objects\n",
627 #if XMALLOC_STATISTICS
628 xm_deltat
= current_dtime
- xm_time
;
629 xm_time
= current_dtime
;
630 storeAppendPrintf(sentry
, "\nMemory allocation statistics\n");
631 storeAppendPrintf(sentry
, "Allocation Size\t Alloc Count\t Alloc Delta\t Allocs/sec \n");
632 malloc_statistics(info_get_mallstat
, sentry
);
636 #define XAVG(X) (dt ? (double) (f->X - l->X) / dt : 0.0)
638 statAvgDump(StoreEntry
* sentry
, int minutes
, int hours
)
645 assert(N_COUNT_HIST
> 1);
646 assert(minutes
> 0 || hours
> 0);
649 if (minutes
> 0 && hours
== 0) {
650 /* checking minute readings ... */
651 if (minutes
> N_COUNT_HIST
- 1)
652 minutes
= N_COUNT_HIST
- 1;
653 l
= &CountHist
[minutes
];
654 } else if (minutes
== 0 && hours
> 0) {
655 /* checking hour readings ... */
656 if (hours
> N_COUNT_HOUR_HIST
- 1)
657 hours
= N_COUNT_HOUR_HIST
- 1;
658 l
= &CountHourHist
[hours
];
660 debug(18, 1) ("statAvgDump: Invalid args, minutes=%d, hours=%d\n",
664 dt
= tvSubDsec(l
->timestamp
, f
->timestamp
);
665 ct
= f
->cputime
- l
->cputime
;
667 storeAppendPrintf(sentry
, "sample_start_time = %d.%d (%s)\n",
668 (int) l
->timestamp
.tv_sec
,
669 (int) l
->timestamp
.tv_usec
,
670 mkrfc1123(l
->timestamp
.tv_sec
));
671 storeAppendPrintf(sentry
, "sample_end_time = %d.%d (%s)\n",
672 (int) f
->timestamp
.tv_sec
,
673 (int) f
->timestamp
.tv_usec
,
674 mkrfc1123(f
->timestamp
.tv_sec
));
676 storeAppendPrintf(sentry
, "client_http.requests = %f/sec\n",
677 XAVG(client_http
.requests
));
678 storeAppendPrintf(sentry
, "client_http.hits = %f/sec\n",
679 XAVG(client_http
.hits
));
680 storeAppendPrintf(sentry
, "client_http.errors = %f/sec\n",
681 XAVG(client_http
.errors
));
682 storeAppendPrintf(sentry
, "client_http.kbytes_in = %f/sec\n",
683 XAVG(client_http
.kbytes_in
.kb
));
684 storeAppendPrintf(sentry
, "client_http.kbytes_out = %f/sec\n",
685 XAVG(client_http
.kbytes_out
.kb
));
687 x
= statHistDeltaMedian(&l
->client_http
.all_svc_time
,
688 &f
->client_http
.all_svc_time
);
689 storeAppendPrintf(sentry
, "client_http.all_median_svc_time = %f seconds\n",
691 x
= statHistDeltaMedian(&l
->client_http
.miss_svc_time
,
692 &f
->client_http
.miss_svc_time
);
693 storeAppendPrintf(sentry
, "client_http.miss_median_svc_time = %f seconds\n",
695 x
= statHistDeltaMedian(&l
->client_http
.nm_svc_time
,
696 &f
->client_http
.nm_svc_time
);
697 storeAppendPrintf(sentry
, "client_http.nm_median_svc_time = %f seconds\n",
699 x
= statHistDeltaMedian(&l
->client_http
.nh_svc_time
,
700 &f
->client_http
.nh_svc_time
);
701 storeAppendPrintf(sentry
, "client_http.nh_median_svc_time = %f seconds\n",
703 x
= statHistDeltaMedian(&l
->client_http
.hit_svc_time
,
704 &f
->client_http
.hit_svc_time
);
705 storeAppendPrintf(sentry
, "client_http.hit_median_svc_time = %f seconds\n",
708 storeAppendPrintf(sentry
, "server.all.requests = %f/sec\n",
709 XAVG(server
.all
.requests
));
710 storeAppendPrintf(sentry
, "server.all.errors = %f/sec\n",
711 XAVG(server
.all
.errors
));
712 storeAppendPrintf(sentry
, "server.all.kbytes_in = %f/sec\n",
713 XAVG(server
.all
.kbytes_in
.kb
));
714 storeAppendPrintf(sentry
, "server.all.kbytes_out = %f/sec\n",
715 XAVG(server
.all
.kbytes_out
.kb
));
717 storeAppendPrintf(sentry
, "server.http.requests = %f/sec\n",
718 XAVG(server
.http
.requests
));
719 storeAppendPrintf(sentry
, "server.http.errors = %f/sec\n",
720 XAVG(server
.http
.errors
));
721 storeAppendPrintf(sentry
, "server.http.kbytes_in = %f/sec\n",
722 XAVG(server
.http
.kbytes_in
.kb
));
723 storeAppendPrintf(sentry
, "server.http.kbytes_out = %f/sec\n",
724 XAVG(server
.http
.kbytes_out
.kb
));
726 storeAppendPrintf(sentry
, "server.ftp.requests = %f/sec\n",
727 XAVG(server
.ftp
.requests
));
728 storeAppendPrintf(sentry
, "server.ftp.errors = %f/sec\n",
729 XAVG(server
.ftp
.errors
));
730 storeAppendPrintf(sentry
, "server.ftp.kbytes_in = %f/sec\n",
731 XAVG(server
.ftp
.kbytes_in
.kb
));
732 storeAppendPrintf(sentry
, "server.ftp.kbytes_out = %f/sec\n",
733 XAVG(server
.ftp
.kbytes_out
.kb
));
735 storeAppendPrintf(sentry
, "server.other.requests = %f/sec\n",
736 XAVG(server
.other
.requests
));
737 storeAppendPrintf(sentry
, "server.other.errors = %f/sec\n",
738 XAVG(server
.other
.errors
));
739 storeAppendPrintf(sentry
, "server.other.kbytes_in = %f/sec\n",
740 XAVG(server
.other
.kbytes_in
.kb
));
741 storeAppendPrintf(sentry
, "server.other.kbytes_out = %f/sec\n",
742 XAVG(server
.other
.kbytes_out
.kb
));
744 storeAppendPrintf(sentry
, "icp.pkts_sent = %f/sec\n",
745 XAVG(icp
.pkts_sent
));
746 storeAppendPrintf(sentry
, "icp.pkts_recv = %f/sec\n",
747 XAVG(icp
.pkts_recv
));
748 storeAppendPrintf(sentry
, "icp.queries_sent = %f/sec\n",
749 XAVG(icp
.queries_sent
));
750 storeAppendPrintf(sentry
, "icp.replies_sent = %f/sec\n",
751 XAVG(icp
.replies_sent
));
752 storeAppendPrintf(sentry
, "icp.queries_recv = %f/sec\n",
753 XAVG(icp
.queries_recv
));
754 storeAppendPrintf(sentry
, "icp.replies_recv = %f/sec\n",
755 XAVG(icp
.replies_recv
));
756 storeAppendPrintf(sentry
, "icp.replies_queued = %f/sec\n",
757 XAVG(icp
.replies_queued
));
758 storeAppendPrintf(sentry
, "icp.query_timeouts = %f/sec\n",
759 XAVG(icp
.query_timeouts
));
760 storeAppendPrintf(sentry
, "icp.kbytes_sent = %f/sec\n",
761 XAVG(icp
.kbytes_sent
.kb
));
762 storeAppendPrintf(sentry
, "icp.kbytes_recv = %f/sec\n",
763 XAVG(icp
.kbytes_recv
.kb
));
764 storeAppendPrintf(sentry
, "icp.q_kbytes_sent = %f/sec\n",
765 XAVG(icp
.q_kbytes_sent
.kb
));
766 storeAppendPrintf(sentry
, "icp.r_kbytes_sent = %f/sec\n",
767 XAVG(icp
.r_kbytes_sent
.kb
));
768 storeAppendPrintf(sentry
, "icp.q_kbytes_recv = %f/sec\n",
769 XAVG(icp
.q_kbytes_recv
.kb
));
770 storeAppendPrintf(sentry
, "icp.r_kbytes_recv = %f/sec\n",
771 XAVG(icp
.r_kbytes_recv
.kb
));
772 x
= statHistDeltaMedian(&l
->icp
.query_svc_time
, &f
->icp
.query_svc_time
);
773 storeAppendPrintf(sentry
, "icp.query_median_svc_time = %f seconds\n",
775 x
= statHistDeltaMedian(&l
->icp
.reply_svc_time
, &f
->icp
.reply_svc_time
);
776 storeAppendPrintf(sentry
, "icp.reply_median_svc_time = %f seconds\n",
778 x
= statHistDeltaMedian(&l
->dns
.svc_time
, &f
->dns
.svc_time
);
779 storeAppendPrintf(sentry
, "dns.median_svc_time = %f seconds\n",
781 storeAppendPrintf(sentry
, "unlink.requests = %f/sec\n",
782 XAVG(unlink
.requests
));
783 storeAppendPrintf(sentry
, "page_faults = %f/sec\n",
785 storeAppendPrintf(sentry
, "select_loops = %f/sec\n",
787 storeAppendPrintf(sentry
, "select_fds = %f/sec\n",
789 storeAppendPrintf(sentry
, "average_select_fd_period = %f/fd\n",
790 f
->select_fds
> l
->select_fds
?
791 (f
->select_time
- l
->select_time
) / (f
->select_fds
- l
->select_fds
)
793 x
= statHistDeltaMedian(&l
->select_fds_hist
, &f
->select_fds_hist
);
794 storeAppendPrintf(sentry
, "median_select_fds = %f\n", x
);
795 storeAppendPrintf(sentry
, "swap.outs = %f/sec\n",
797 storeAppendPrintf(sentry
, "swap.ins = %f/sec\n",
799 storeAppendPrintf(sentry
, "swap.files_cleaned = %f/sec\n",
800 XAVG(swap
.files_cleaned
));
801 storeAppendPrintf(sentry
, "aborted_requests = %f/sec\n",
802 XAVG(aborted_requests
));
805 storeAppendPrintf(sentry
, "syscalls.polls = %f/sec\n", XAVG(syscalls
.polls
));
808 storeAppendPrintf(sentry
, "syscalls.selects = %f/sec\n", XAVG(syscalls
.selects
));
810 storeAppendPrintf(sentry
, "syscalls.disk.opens = %f/sec\n", XAVG(syscalls
.disk
.opens
));
811 storeAppendPrintf(sentry
, "syscalls.disk.closes = %f/sec\n", XAVG(syscalls
.disk
.closes
));
812 storeAppendPrintf(sentry
, "syscalls.disk.reads = %f/sec\n", XAVG(syscalls
.disk
.reads
));
813 storeAppendPrintf(sentry
, "syscalls.disk.writes = %f/sec\n", XAVG(syscalls
.disk
.writes
));
814 storeAppendPrintf(sentry
, "syscalls.disk.seeks = %f/sec\n", XAVG(syscalls
.disk
.seeks
));
815 storeAppendPrintf(sentry
, "syscalls.disk.unlinks = %f/sec\n", XAVG(syscalls
.disk
.unlinks
));
816 storeAppendPrintf(sentry
, "syscalls.sock.accepts = %f/sec\n", XAVG(syscalls
.sock
.accepts
));
817 storeAppendPrintf(sentry
, "syscalls.sock.sockets = %f/sec\n", XAVG(syscalls
.sock
.sockets
));
818 storeAppendPrintf(sentry
, "syscalls.sock.connects = %f/sec\n", XAVG(syscalls
.sock
.connects
));
819 storeAppendPrintf(sentry
, "syscalls.sock.binds = %f/sec\n", XAVG(syscalls
.sock
.binds
));
820 storeAppendPrintf(sentry
, "syscalls.sock.closes = %f/sec\n", XAVG(syscalls
.sock
.closes
));
821 storeAppendPrintf(sentry
, "syscalls.sock.reads = %f/sec\n", XAVG(syscalls
.sock
.reads
));
822 storeAppendPrintf(sentry
, "syscalls.sock.writes = %f/sec\n", XAVG(syscalls
.sock
.writes
));
823 storeAppendPrintf(sentry
, "syscalls.sock.recvfroms = %f/sec\n", XAVG(syscalls
.sock
.recvfroms
));
824 storeAppendPrintf(sentry
, "syscalls.sock.sendtos = %f/sec\n", XAVG(syscalls
.sock
.sendtos
));
826 storeAppendPrintf(sentry
, "cpu_time = %f seconds\n", ct
);
827 storeAppendPrintf(sentry
, "wall_time = %f seconds\n", dt
);
828 storeAppendPrintf(sentry
, "cpu_usage = %f%%\n", dpercent(ct
, dt
));
836 debug(18, 5) ("statInit: Initializing...\n");
837 CBDATA_INIT_TYPE(StatObjectsState
);
838 for (i
= 0; i
< N_COUNT_HIST
; i
++)
839 statCountersInit(&CountHist
[i
]);
840 for (i
= 0; i
< N_COUNT_HOUR_HIST
; i
++)
841 statCountersInit(&CountHourHist
[i
]);
842 statCountersInit(&statCounter
);
843 eventAdd("statAvgTick", statAvgTick
, NULL
, (double) COUNT_INTERVAL
, 1);
844 cachemgrRegister("info",
845 "General Runtime Information",
847 cachemgrRegister("filedescriptors",
848 "Process Filedescriptor Allocation",
849 statFiledescriptors
, 0, 1);
850 cachemgrRegister("objects",
852 stat_objects_get
, 0, 0);
853 cachemgrRegister("vm_objects",
854 "In-Memory and In-Transit Objects",
855 stat_vmobjects_get
, 0, 0);
857 cachemgrRegister("openfd_objects",
858 "Objects with Swapout files open",
859 statOpenfdObj
, 0, 0);
861 cachemgrRegister("io",
862 "Server-side network read() size histograms",
864 cachemgrRegister("counters",
865 "Traffic and Resource Counters",
866 statCountersDump
, 0, 1);
867 cachemgrRegister("peer_select",
868 "Peer Selection Algorithms",
869 statPeerSelect
, 0, 1);
870 cachemgrRegister("digest_stats",
871 "Cache Digest and ICP blob",
872 statDigestBlob
, 0, 1);
873 cachemgrRegister("5min",
874 "5 Minute Average of Counters",
876 cachemgrRegister("60min",
877 "60 Minute Average of Counters",
879 cachemgrRegister("utilization",
881 statUtilization
, 0, 1);
883 cachemgrRegister("graph_variables",
884 "Display cache metrics graphically",
885 statGraphDump
, 0, 1);
887 cachemgrRegister("histograms",
888 "Full Histogram Counts",
889 statCountersHistograms
, 0, 1);
890 ClientActiveRequests
.head
= NULL
;
891 ClientActiveRequests
.tail
= NULL
;
892 cachemgrRegister("active_requests",
893 "Client-side Active Requests",
894 statClientRequests
, 0, 1);
898 statAvgTick(void *notused
)
900 StatCounters
*t
= &CountHist
[0];
901 StatCounters
*p
= &CountHist
[1];
902 StatCounters
*c
= &statCounter
;
903 struct rusage rusage
;
904 eventAdd("statAvgTick", statAvgTick
, NULL
, (double) COUNT_INTERVAL
, 1);
905 squid_getrusage(&rusage
);
906 c
->page_faults
= rusage_pagefaults(&rusage
);
907 c
->cputime
= rusage_cputime(&rusage
);
908 c
->timestamp
= current_time
;
909 /* even if NCountHist is small, we already Init()ed the tail */
910 statCountersClean(CountHist
+ N_COUNT_HIST
- 1);
911 xmemmove(p
, t
, (N_COUNT_HIST
- 1) * sizeof(StatCounters
));
912 statCountersCopy(t
, c
);
915 if ((NCountHist
% COUNT_INTERVAL
) == 0) {
916 /* we have an hours worth of readings. store previous hour */
917 StatCounters
*t
= &CountHourHist
[0];
918 StatCounters
*p
= &CountHourHist
[1];
919 StatCounters
*c
= &CountHist
[N_COUNT_HIST
- 1];
920 statCountersClean(CountHourHist
+ N_COUNT_HOUR_HIST
- 1);
921 xmemmove(p
, t
, (N_COUNT_HOUR_HIST
- 1) * sizeof(StatCounters
));
922 statCountersCopy(t
, c
);
925 if (Config
.warnings
.high_rptm
> 0) {
926 int i
= (int) statMedianSvc(20, MEDIAN_HTTP
);
927 if (Config
.warnings
.high_rptm
< i
)
928 debug(18, 0) ("WARNING: Median response time is %d milliseconds\n", i
);
930 if (Config
.warnings
.high_pf
) {
931 int i
= (CountHist
[0].page_faults
- CountHist
[1].page_faults
);
932 double dt
= tvSubDsec(CountHist
[0].timestamp
, CountHist
[1].timestamp
);
933 if (i
> 0 && dt
> 0.0) {
935 if (Config
.warnings
.high_pf
< i
)
936 debug(18, 0) ("WARNING: Page faults occuring at %d/sec\n", i
);
939 if (Config
.warnings
.high_memory
) {
941 #if HAVE_MSTATS && HAVE_GNUMALLOC_H
942 struct mstats ms
= mstats();
944 #elif HAVE_MALLINFO && HAVE_STRUCT_MALLINFO
945 struct mallinfo mp
= mallinfo();
948 if (Config
.warnings
.high_memory
< i
)
949 debug(18, 0) ("WARNING: Memory usage at %d MB\n", i
>> 20);
954 statCountersInit(StatCounters
* C
)
957 memset(C
, 0, sizeof(*C
));
958 C
->timestamp
= current_time
;
959 statCountersInitSpecial(C
);
962 /* add special cases here as they arrive */
964 statCountersInitSpecial(StatCounters
* C
)
967 * HTTP svc_time hist is kept in milli-seconds; max of 3 hours.
969 statHistLogInit(&C
->client_http
.all_svc_time
, 300, 0.0, 3600000.0 * 3.0);
970 statHistLogInit(&C
->client_http
.miss_svc_time
, 300, 0.0, 3600000.0 * 3.0);
971 statHistLogInit(&C
->client_http
.nm_svc_time
, 300, 0.0, 3600000.0 * 3.0);
972 statHistLogInit(&C
->client_http
.nh_svc_time
, 300, 0.0, 3600000.0 * 3.0);
973 statHistLogInit(&C
->client_http
.hit_svc_time
, 300, 0.0, 3600000.0 * 3.0);
975 * ICP svc_time hist is kept in micro-seconds; max of 1 minute.
977 statHistLogInit(&C
->icp
.query_svc_time
, 300, 0.0, 1000000.0 * 60.0);
978 statHistLogInit(&C
->icp
.reply_svc_time
, 300, 0.0, 1000000.0 * 60.0);
980 * DNS svc_time hist is kept in milli-seconds; max of 10 minutes.
982 statHistLogInit(&C
->dns
.svc_time
, 300, 0.0, 60000.0 * 10.0);
986 statHistEnumInit(&C
->cd
.on_xition_count
, CacheDigestHashFuncCount
);
987 statHistEnumInit(&C
->comm_icp_incoming
, INCOMING_ICP_MAX
);
988 statHistEnumInit(&C
->comm_dns_incoming
, INCOMING_DNS_MAX
);
989 statHistEnumInit(&C
->comm_http_incoming
, INCOMING_HTTP_MAX
);
990 statHistIntInit(&C
->select_fds_hist
, 256); /* was SQUID_MAXFD, but it is way too much. It is OK to crop this statistics */
993 /* add special cases here as they arrive */
995 statCountersClean(StatCounters
* C
)
998 statHistClean(&C
->client_http
.all_svc_time
);
999 statHistClean(&C
->client_http
.miss_svc_time
);
1000 statHistClean(&C
->client_http
.nm_svc_time
);
1001 statHistClean(&C
->client_http
.nh_svc_time
);
1002 statHistClean(&C
->client_http
.hit_svc_time
);
1003 statHistClean(&C
->icp
.query_svc_time
);
1004 statHistClean(&C
->icp
.reply_svc_time
);
1005 statHistClean(&C
->dns
.svc_time
);
1006 statHistClean(&C
->cd
.on_xition_count
);
1007 statHistClean(&C
->comm_icp_incoming
);
1008 statHistClean(&C
->comm_dns_incoming
);
1009 statHistClean(&C
->comm_http_incoming
);
1010 statHistClean(&C
->select_fds_hist
);
1013 /* add special cases here as they arrive */
1015 statCountersCopy(StatCounters
* dest
, const StatCounters
* orig
)
1017 assert(dest
&& orig
);
1018 /* this should take care of all the fields, but "special" ones */
1019 xmemcpy(dest
, orig
, sizeof(*dest
));
1020 /* prepare space where to copy special entries */
1021 statCountersInitSpecial(dest
);
1022 /* now handle special cases */
1023 /* note: we assert that histogram capacities do not change */
1024 statHistCopy(&dest
->client_http
.all_svc_time
, &orig
->client_http
.all_svc_time
);
1025 statHistCopy(&dest
->client_http
.miss_svc_time
, &orig
->client_http
.miss_svc_time
);
1026 statHistCopy(&dest
->client_http
.nm_svc_time
, &orig
->client_http
.nm_svc_time
);
1027 statHistCopy(&dest
->client_http
.nh_svc_time
, &orig
->client_http
.nh_svc_time
);
1028 statHistCopy(&dest
->client_http
.hit_svc_time
, &orig
->client_http
.hit_svc_time
);
1029 statHistCopy(&dest
->icp
.query_svc_time
, &orig
->icp
.query_svc_time
);
1030 statHistCopy(&dest
->icp
.reply_svc_time
, &orig
->icp
.reply_svc_time
);
1031 statHistCopy(&dest
->dns
.svc_time
, &orig
->dns
.svc_time
);
1032 statHistCopy(&dest
->cd
.on_xition_count
, &orig
->cd
.on_xition_count
);
1033 statHistCopy(&dest
->comm_icp_incoming
, &orig
->comm_icp_incoming
);
1034 statHistCopy(&dest
->comm_http_incoming
, &orig
->comm_http_incoming
);
1035 statHistCopy(&dest
->select_fds_hist
, &orig
->select_fds_hist
);
1039 statCountersHistograms(StoreEntry
* sentry
)
1041 StatCounters
*f
= &statCounter
;
1042 storeAppendPrintf(sentry
, "client_http.all_svc_time histogram:\n");
1043 statHistDump(&f
->client_http
.all_svc_time
, sentry
, NULL
);
1044 storeAppendPrintf(sentry
, "client_http.miss_svc_time histogram:\n");
1045 statHistDump(&f
->client_http
.miss_svc_time
, sentry
, NULL
);
1046 storeAppendPrintf(sentry
, "client_http.nm_svc_time histogram:\n");
1047 statHistDump(&f
->client_http
.nm_svc_time
, sentry
, NULL
);
1048 storeAppendPrintf(sentry
, "client_http.nh_svc_time histogram:\n");
1049 statHistDump(&f
->client_http
.nh_svc_time
, sentry
, NULL
);
1050 storeAppendPrintf(sentry
, "client_http.hit_svc_time histogram:\n");
1051 statHistDump(&f
->client_http
.hit_svc_time
, sentry
, NULL
);
1052 storeAppendPrintf(sentry
, "icp.query_svc_time histogram:\n");
1053 statHistDump(&f
->icp
.query_svc_time
, sentry
, NULL
);
1054 storeAppendPrintf(sentry
, "icp.reply_svc_time histogram:\n");
1055 statHistDump(&f
->icp
.reply_svc_time
, sentry
, NULL
);
1056 storeAppendPrintf(sentry
, "dns.svc_time histogram:\n");
1057 statHistDump(&f
->dns
.svc_time
, sentry
, NULL
);
1061 statCountersDump(StoreEntry
* sentry
)
1063 StatCounters
*f
= &statCounter
;
1064 struct rusage rusage
;
1065 squid_getrusage(&rusage
);
1066 f
->page_faults
= rusage_pagefaults(&rusage
);
1067 f
->cputime
= rusage_cputime(&rusage
);
1069 storeAppendPrintf(sentry
, "sample_time = %d.%d (%s)\n",
1070 (int) f
->timestamp
.tv_sec
,
1071 (int) f
->timestamp
.tv_usec
,
1072 mkrfc1123(f
->timestamp
.tv_sec
));
1073 storeAppendPrintf(sentry
, "client_http.requests = %d\n",
1074 f
->client_http
.requests
);
1075 storeAppendPrintf(sentry
, "client_http.hits = %d\n",
1076 f
->client_http
.hits
);
1077 storeAppendPrintf(sentry
, "client_http.errors = %d\n",
1078 f
->client_http
.errors
);
1079 storeAppendPrintf(sentry
, "client_http.kbytes_in = %d\n",
1080 (int) f
->client_http
.kbytes_in
.kb
);
1081 storeAppendPrintf(sentry
, "client_http.kbytes_out = %d\n",
1082 (int) f
->client_http
.kbytes_out
.kb
);
1083 storeAppendPrintf(sentry
, "client_http.hit_kbytes_out = %d\n",
1084 (int) f
->client_http
.hit_kbytes_out
.kb
);
1086 storeAppendPrintf(sentry
, "server.all.requests = %d\n",
1087 (int) f
->server
.all
.requests
);
1088 storeAppendPrintf(sentry
, "server.all.errors = %d\n",
1089 (int) f
->server
.all
.errors
);
1090 storeAppendPrintf(sentry
, "server.all.kbytes_in = %d\n",
1091 (int) f
->server
.all
.kbytes_in
.kb
);
1092 storeAppendPrintf(sentry
, "server.all.kbytes_out = %d\n",
1093 (int) f
->server
.all
.kbytes_out
.kb
);
1095 storeAppendPrintf(sentry
, "server.http.requests = %d\n",
1096 (int) f
->server
.http
.requests
);
1097 storeAppendPrintf(sentry
, "server.http.errors = %d\n",
1098 (int) f
->server
.http
.errors
);
1099 storeAppendPrintf(sentry
, "server.http.kbytes_in = %d\n",
1100 (int) f
->server
.http
.kbytes_in
.kb
);
1101 storeAppendPrintf(sentry
, "server.http.kbytes_out = %d\n",
1102 (int) f
->server
.http
.kbytes_out
.kb
);
1104 storeAppendPrintf(sentry
, "server.ftp.requests = %d\n",
1105 (int) f
->server
.ftp
.requests
);
1106 storeAppendPrintf(sentry
, "server.ftp.errors = %d\n",
1107 (int) f
->server
.ftp
.errors
);
1108 storeAppendPrintf(sentry
, "server.ftp.kbytes_in = %d\n",
1109 (int) f
->server
.ftp
.kbytes_in
.kb
);
1110 storeAppendPrintf(sentry
, "server.ftp.kbytes_out = %d\n",
1111 (int) f
->server
.ftp
.kbytes_out
.kb
);
1113 storeAppendPrintf(sentry
, "server.other.requests = %d\n",
1114 (int) f
->server
.other
.requests
);
1115 storeAppendPrintf(sentry
, "server.other.errors = %d\n",
1116 (int) f
->server
.other
.errors
);
1117 storeAppendPrintf(sentry
, "server.other.kbytes_in = %d\n",
1118 (int) f
->server
.other
.kbytes_in
.kb
);
1119 storeAppendPrintf(sentry
, "server.other.kbytes_out = %d\n",
1120 (int) f
->server
.other
.kbytes_out
.kb
);
1122 storeAppendPrintf(sentry
, "icp.pkts_sent = %d\n",
1124 storeAppendPrintf(sentry
, "icp.pkts_recv = %d\n",
1126 storeAppendPrintf(sentry
, "icp.queries_sent = %d\n",
1127 f
->icp
.queries_sent
);
1128 storeAppendPrintf(sentry
, "icp.replies_sent = %d\n",
1129 f
->icp
.replies_sent
);
1130 storeAppendPrintf(sentry
, "icp.queries_recv = %d\n",
1131 f
->icp
.queries_recv
);
1132 storeAppendPrintf(sentry
, "icp.replies_recv = %d\n",
1133 f
->icp
.replies_recv
);
1134 storeAppendPrintf(sentry
, "icp.query_timeouts = %d\n",
1135 f
->icp
.query_timeouts
);
1136 storeAppendPrintf(sentry
, "icp.replies_queued = %d\n",
1137 f
->icp
.replies_queued
);
1138 storeAppendPrintf(sentry
, "icp.kbytes_sent = %d\n",
1139 (int) f
->icp
.kbytes_sent
.kb
);
1140 storeAppendPrintf(sentry
, "icp.kbytes_recv = %d\n",
1141 (int) f
->icp
.kbytes_recv
.kb
);
1142 storeAppendPrintf(sentry
, "icp.q_kbytes_sent = %d\n",
1143 (int) f
->icp
.q_kbytes_sent
.kb
);
1144 storeAppendPrintf(sentry
, "icp.r_kbytes_sent = %d\n",
1145 (int) f
->icp
.r_kbytes_sent
.kb
);
1146 storeAppendPrintf(sentry
, "icp.q_kbytes_recv = %d\n",
1147 (int) f
->icp
.q_kbytes_recv
.kb
);
1148 storeAppendPrintf(sentry
, "icp.r_kbytes_recv = %d\n",
1149 (int) f
->icp
.r_kbytes_recv
.kb
);
1151 #if USE_CACHE_DIGESTS
1152 storeAppendPrintf(sentry
, "icp.times_used = %d\n",
1154 storeAppendPrintf(sentry
, "cd.times_used = %d\n",
1156 storeAppendPrintf(sentry
, "cd.msgs_sent = %d\n",
1158 storeAppendPrintf(sentry
, "cd.msgs_recv = %d\n",
1160 storeAppendPrintf(sentry
, "cd.memory = %d\n",
1161 (int) f
->cd
.memory
.kb
);
1162 storeAppendPrintf(sentry
, "cd.local_memory = %d\n",
1163 (int) (store_digest
? store_digest
->mask_size
/ 1024 : 0));
1164 storeAppendPrintf(sentry
, "cd.kbytes_sent = %d\n",
1165 (int) f
->cd
.kbytes_sent
.kb
);
1166 storeAppendPrintf(sentry
, "cd.kbytes_recv = %d\n",
1167 (int) f
->cd
.kbytes_recv
.kb
);
1170 storeAppendPrintf(sentry
, "unlink.requests = %d\n",
1171 f
->unlink
.requests
);
1172 storeAppendPrintf(sentry
, "page_faults = %d\n",
1174 storeAppendPrintf(sentry
, "select_loops = %d\n",
1176 storeAppendPrintf(sentry
, "cpu_time = %f\n",
1178 storeAppendPrintf(sentry
, "wall_time = %f\n",
1179 tvSubDsec(f
->timestamp
, current_time
));
1180 storeAppendPrintf(sentry
, "swap.outs = %d\n",
1182 storeAppendPrintf(sentry
, "swap.ins = %d\n",
1184 storeAppendPrintf(sentry
, "swap.files_cleaned = %d\n",
1185 f
->swap
.files_cleaned
);
1186 storeAppendPrintf(sentry
, "aborted_requests = %d\n",
1187 f
->aborted_requests
);
1191 statFreeMemory(void)
1194 for (i
= 0; i
< N_COUNT_HIST
; i
++)
1195 statCountersClean(&CountHist
[i
]);
1196 for (i
= 0; i
< N_COUNT_HOUR_HIST
; i
++)
1197 statCountersClean(&CountHourHist
[i
]);
1201 statPeerSelect(StoreEntry
* sentry
)
1203 #if USE_CACHE_DIGESTS
1204 StatCounters
*f
= &statCounter
;
1206 const int tot_used
= f
->cd
.times_used
+ f
->icp
.times_used
;
1209 cacheDigestGuessStatsReport(&f
->cd
.guess
, sentry
, "all peers");
1211 storeAppendPrintf(sentry
, "\nPer-peer statistics:\n");
1212 for (peer
= getFirstPeer(); peer
; peer
= getNextPeer(peer
)) {
1214 peerDigestStatsReport(peer
->digest
, sentry
);
1216 storeAppendPrintf(sentry
, "\nNo peer digest from %s\n", peer
->host
);
1217 storeAppendPrintf(sentry
, "\n");
1220 storeAppendPrintf(sentry
, "\nAlgorithm usage:\n");
1221 storeAppendPrintf(sentry
, "Cache Digest: %7d (%3d%%)\n",
1222 f
->cd
.times_used
, xpercentInt(f
->cd
.times_used
, tot_used
));
1223 storeAppendPrintf(sentry
, "Icp: %7d (%3d%%)\n",
1224 f
->icp
.times_used
, xpercentInt(f
->icp
.times_used
, tot_used
));
1225 storeAppendPrintf(sentry
, "Total: %7d (%3d%%)\n",
1226 tot_used
, xpercentInt(tot_used
, tot_used
));
1228 storeAppendPrintf(sentry
, "peer digests are disabled; no stats is available.\n");
1233 statDigestBlob(StoreEntry
* sentry
)
1235 storeAppendPrintf(sentry
, "\nCounters:\n");
1236 statCountersDump(sentry
);
1237 storeAppendPrintf(sentry
, "\n5 Min Averages:\n");
1238 statAvgDump(sentry
, 5, 0);
1239 storeAppendPrintf(sentry
, "\nHistograms:\n");
1240 statCountersHistograms(sentry
);
1241 storeAppendPrintf(sentry
, "\nPeer Digests:\n");
1242 statPeerSelect(sentry
);
1243 storeAppendPrintf(sentry
, "\nLocal Digest:\n");
1244 storeDigestReport(sentry
);
1248 statAvg5min(StoreEntry
* e
)
1250 statAvgDump(e
, 5, 0);
1254 statAvg60min(StoreEntry
* e
)
1256 statAvgDump(e
, 60, 0);
1260 statMedianSvc(int interval
, int which
)
1265 assert(interval
> 0);
1266 if (interval
> N_COUNT_HIST
- 1)
1267 interval
= N_COUNT_HIST
- 1;
1269 l
= &CountHist
[interval
];
1274 x
= statHistDeltaMedian(&l
->client_http
.all_svc_time
, &f
->client_http
.all_svc_time
);
1277 x
= statHistDeltaMedian(&l
->client_http
.hit_svc_time
, &f
->client_http
.hit_svc_time
);
1280 x
= statHistDeltaMedian(&l
->client_http
.miss_svc_time
, &f
->client_http
.miss_svc_time
);
1283 x
= statHistDeltaMedian(&l
->client_http
.nm_svc_time
, &f
->client_http
.nm_svc_time
);
1286 x
= statHistDeltaMedian(&l
->client_http
.nh_svc_time
, &f
->client_http
.nh_svc_time
);
1288 case MEDIAN_ICP_QUERY
:
1289 x
= statHistDeltaMedian(&l
->icp
.query_svc_time
, &f
->icp
.query_svc_time
);
1292 x
= statHistDeltaMedian(&l
->dns
.svc_time
, &f
->dns
.svc_time
);
1295 debug(49, 5) ("get_median_val: unknown type.\n");
1302 * SNMP wants ints, ick
1306 get_median_svc(int interval
, int which
)
1308 return (int) statMedianSvc(interval
, which
);
1314 snmpStatGet(int minutes
)
1316 return &CountHist
[minutes
];
1320 stat5minClientRequests(void)
1322 assert(N_COUNT_HIST
> 5);
1323 return statCounter
.client_http
.requests
- CountHist
[5].client_http
.requests
;
1327 statCPUUsage(int minutes
)
1329 assert(minutes
< N_COUNT_HIST
);
1330 return dpercent(CountHist
[0].cputime
- CountHist
[minutes
].cputime
,
1331 tvSubDsec(CountHist
[minutes
].timestamp
, CountHist
[0].timestamp
));
1335 statRequestHitRatio(int minutes
)
1337 assert(minutes
< N_COUNT_HIST
);
1338 return dpercent(CountHist
[0].client_http
.hits
-
1339 CountHist
[minutes
].client_http
.hits
,
1340 CountHist
[0].client_http
.requests
-
1341 CountHist
[minutes
].client_http
.requests
);
1345 statRequestHitMemoryRatio(int minutes
)
1347 assert(minutes
< N_COUNT_HIST
);
1348 return dpercent(CountHist
[0].client_http
.mem_hits
-
1349 CountHist
[minutes
].client_http
.mem_hits
,
1350 CountHist
[0].client_http
.hits
-
1351 CountHist
[minutes
].client_http
.hits
);
1355 statRequestHitDiskRatio(int minutes
)
1357 assert(minutes
< N_COUNT_HIST
);
1358 return dpercent(CountHist
[0].client_http
.disk_hits
-
1359 CountHist
[minutes
].client_http
.disk_hits
,
1360 CountHist
[0].client_http
.hits
-
1361 CountHist
[minutes
].client_http
.hits
);
1365 statByteHitRatio(int minutes
)
1369 #if USE_CACHE_DIGESTS
1372 /* size_t might be unsigned */
1373 assert(minutes
< N_COUNT_HIST
);
1374 c
= CountHist
[0].client_http
.kbytes_out
.kb
- CountHist
[minutes
].client_http
.kbytes_out
.kb
;
1375 s
= CountHist
[0].server
.all
.kbytes_in
.kb
- CountHist
[minutes
].server
.all
.kbytes_in
.kb
;
1376 #if USE_CACHE_DIGESTS
1378 * This ugly hack is here to prevent the user from seeing a
1379 * negative byte hit ratio. When we fetch a cache digest from
1380 * a neighbor, it gets treated like a cache miss because the
1381 * object is consumed internally. Thus, we subtract cache
1382 * digest bytes out before calculating the byte hit ratio.
1384 cd
= CountHist
[0].cd
.kbytes_recv
.kb
- CountHist
[minutes
].cd
.kbytes_recv
.kb
;
1386 debug(18, 1) ("STRANGE: srv_kbytes=%d, cd_kbytes=%d\n", s
, cd
);
1390 return dpercent(c
- s
, c
);
1392 return (-1.0 * dpercent(s
- c
, c
));
1396 statClientRequests(StoreEntry
* s
)
1399 clientHttpRequest
*http
;
1400 ConnStateData
*conn
;
1403 for (i
= ClientActiveRequests
.head
; i
; i
= i
->next
) {
1407 storeAppendPrintf(s
, "Connection: %p\n", conn
);
1410 storeAppendPrintf(s
, "\tFD %d, read %d, wrote %d\n", fd
,
1411 fd_table
[fd
].bytes_read
, fd_table
[fd
].bytes_written
);
1412 storeAppendPrintf(s
, "\tFD desc: %s\n", fd_table
[fd
].desc
);
1413 storeAppendPrintf(s
, "\tin: buf %p, offset %ld, size %ld\n",
1414 conn
->in
.buf
, (long int) conn
->in
.offset
, (long int) conn
->in
.size
);
1415 storeAppendPrintf(s
, "\tpeer: %s:%d\n",
1416 inet_ntoa(conn
->peer
.sin_addr
),
1417 ntohs(conn
->peer
.sin_port
));
1418 storeAppendPrintf(s
, "\tme: %s:%d\n",
1419 inet_ntoa(conn
->me
.sin_addr
),
1420 ntohs(conn
->me
.sin_port
));
1421 storeAppendPrintf(s
, "\tnrequests: %d\n",
1423 storeAppendPrintf(s
, "\tdefer: n %d, until %ld\n",
1424 conn
->defer
.n
, (long int) conn
->defer
.until
);
1426 storeAppendPrintf(s
, "uri %s\n", http
->uri
);
1427 storeAppendPrintf(s
, "log_type %s\n", log_tags
[http
->log_type
]);
1428 storeAppendPrintf(s
, "out.offset %ld, out.size %lu\n",
1429 (long int) http
->out
.offset
, (unsigned long int) http
->out
.size
);
1430 storeAppendPrintf(s
, "req_sz %ld\n", (long int) http
->req_sz
);
1432 storeAppendPrintf(s
, "entry %p/%s\n", e
, e
? storeKeyText(e
->hash
.key
) : "N/A");
1433 e
= http
->old_entry
;
1434 storeAppendPrintf(s
, "old_entry %p/%s\n", e
, e
? storeKeyText(e
->hash
.key
) : "N/A");
1435 storeAppendPrintf(s
, "start %ld.%06d (%f seconds ago)\n",
1436 (long int) http
->start
.tv_sec
,
1437 (int) http
->start
.tv_usec
,
1438 tvSubDsec(http
->start
, current_time
));
1439 storeAppendPrintf(s
, "\n");
1445 * urgh, i don't like these, but they do cut the amount of code down immensely
1448 #define GRAPH_PER_MIN(Y) \
1449 for (i=0;i<(N_COUNT_HIST-2);i++) { \
1450 dt = tvSubDsec(CountHist[i].timestamp, CountHist[i+1].timestamp); \
1453 storeAppendPrintf(e, "%lu,%0.2f:", \
1454 CountHist[i].timestamp.tv_sec, \
1455 ((CountHist[i].Y - CountHist[i+1].Y) / dt)); \
1458 #define GRAPH_PER_HOUR(Y) \
1459 for (i=0;i<(N_COUNT_HOUR_HIST-2);i++) { \
1460 dt = tvSubDsec(CountHourHist[i].timestamp, CountHourHist[i+1].timestamp); \
1463 storeAppendPrintf(e, "%lu,%0.2f:", \
1464 CountHourHist[i].timestamp.tv_sec, \
1465 ((CountHourHist[i].Y - CountHourHist[i+1].Y) / dt)); \
1468 #define GRAPH_TITLE(X,Y) storeAppendPrintf(e,"%s\t%s\t",X,Y);
1469 #define GRAPH_END storeAppendPrintf(e,"\n");
1471 #define GENGRAPH(X,Y,Z) \
1478 statGraphDump(StoreEntry
* e
)
1483 GENGRAPH(client_http
.requests
, "client_http.requests", "Client HTTP requests/sec");
1484 GENGRAPH(client_http
.hits
, "client_http.hits", "Client HTTP hits/sec");
1485 GENGRAPH(client_http
.errors
, "client_http.errors", "Client HTTP errors/sec");
1486 GENGRAPH(client_http
.kbytes_in
.kb
, "client_http.kbytes_in", "Client HTTP kbytes_in/sec");
1487 GENGRAPH(client_http
.kbytes_out
.kb
, "client_http.kbytes_out", "Client HTTP kbytes_out/sec");
1489 /* XXX todo: http median service times */
1491 GENGRAPH(server
.all
.requests
, "server.all.requests", "Server requests/sec");
1492 GENGRAPH(server
.all
.errors
, "server.all.errors", "Server errors/sec");
1493 GENGRAPH(server
.all
.kbytes_in
.kb
, "server.all.kbytes_in", "Server total kbytes_in/sec");
1494 GENGRAPH(server
.all
.kbytes_out
.kb
, "server.all.kbytes_out", "Server total kbytes_out/sec");
1496 GENGRAPH(server
.http
.requests
, "server.http.requests", "Server HTTP requests/sec");
1497 GENGRAPH(server
.http
.errors
, "server.http.errors", "Server HTTP errors/sec");
1498 GENGRAPH(server
.http
.kbytes_in
.kb
, "server.http.kbytes_in", "Server HTTP kbytes_in/sec");
1499 GENGRAPH(server
.http
.kbytes_out
.kb
, "server.http.kbytes_out", "Server HTTP kbytes_out/sec");
1501 GENGRAPH(server
.ftp
.requests
, "server.ftp.requests", "Server FTP requests/sec");
1502 GENGRAPH(server
.ftp
.errors
, "server.ftp.errors", "Server FTP errors/sec");
1503 GENGRAPH(server
.ftp
.kbytes_in
.kb
, "server.ftp.kbytes_in", "Server FTP kbytes_in/sec");
1504 GENGRAPH(server
.ftp
.kbytes_out
.kb
, "server.ftp.kbytes_out", "Server FTP kbytes_out/sec");
1506 GENGRAPH(server
.other
.requests
, "server.other.requests", "Server other requests/sec");
1507 GENGRAPH(server
.other
.errors
, "server.other.errors", "Server other errors/sec");
1508 GENGRAPH(server
.other
.kbytes_in
.kb
, "server.other.kbytes_in", "Server other kbytes_in/sec");
1509 GENGRAPH(server
.other
.kbytes_out
.kb
, "server.other.kbytes_out", "Server other kbytes_out/sec");
1511 GENGRAPH(icp
.pkts_sent
, "icp.pkts_sent", "ICP packets sent/sec");
1512 GENGRAPH(icp
.pkts_recv
, "icp.pkts_recv", "ICP packets received/sec");
1513 GENGRAPH(icp
.kbytes_sent
.kb
, "icp.kbytes_sent", "ICP kbytes_sent/sec");
1514 GENGRAPH(icp
.kbytes_recv
.kb
, "icp.kbytes_recv", "ICP kbytes_received/sec");
1516 /* XXX todo: icp median service times */
1517 /* XXX todo: dns median service times */
1519 GENGRAPH(unlink
.requests
, "unlink.requests", "Cache File unlink requests/sec");
1520 GENGRAPH(page_faults
, "page_faults", "System Page Faults/sec");
1521 GENGRAPH(select_loops
, "select_loops", "System Select Loop calls/sec");
1522 GENGRAPH(cputime
, "cputime", "CPU utilisation");
1526 statMemoryAccounted(void)
1528 memTotalAllocated();
1531 #endif /* STAT_GRAPHS */